niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #490
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestUploadMultipart_PartsInParallel18=== PAUSE TestUploadMultipart_PartsInParallel19=== RUN TestUploadMultipart_ReturnsAfterDroppedBody20=== PAUSE TestUploadMultipart_ReturnsAfterDroppedBody21=== RUN TestPartSizeForNAR22=== PAUSE TestPartSizeForNAR23=== RUN TestDumpPathCaseHackMatchesNix24--- PASS: TestDumpPathCaseHackMatchesNix (1.76s)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 TestGetStorePathHash115=== CONT TestStreamPushBatchesUnderLoad116=== CONT TestScriptTokenEmptyCommand117--- PASS: TestScriptTokenEmptyCommand (0.00s)118=== CONT TestScriptTokenScriptFails119=== RUN TestGetStorePathHash/valid_store_path120=== PAUSE TestGetStorePathHash/valid_store_path121=== RUN TestGetStorePathHash/basename_without_hyphen_should_error122=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error123=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error124=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error125=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error126=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error127=== CONT TestUploadMultipart_ReturnsAfterDroppedBody128=== CONT TestConvertHashToNix32129=== RUN TestConvertHashToNix32/SRI_format_to_Nix32130=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32131=== RUN TestConvertHashToNix32/already_Nix32_format132=== PAUSE TestConvertHashToNix32/already_Nix32_format133=== RUN TestConvertHashToNix32/invalid_format134=== PAUSE TestConvertHashToNix32/invalid_format135=== CONT TestShellSplit136--- PASS: TestShellSplit (0.00s)137=== CONT TestRetryTimeoutOutlastsMaxRetries138=== CONT TestEncodeNixBase32WithRealHash139--- PASS: TestEncodeNixBase32WithRealHash (0.00s)140=== CONT TestDoWithRetry_BodyReplayedViaGetBody141=== CONT TestDoWithRetry_FinalResponseBodyReadable142=== CONT TestEncodeNixBase32143=== RUN TestEncodeNixBase32/test_string_hash144=== PAUSE TestEncodeNixBase32/test_string_hash145=== RUN TestEncodeNixBase32/empty_input146=== PAUSE TestEncodeNixBase32/empty_input147=== CONT TestDumpPathWriterError148=== CONT TestResolveStorePath149=== CONT TestDumpPathSingleFile150=== CONT TestDumpPathMatchesNix151=== CONT TestPartSizeForNAR152=== CONT TestSetClientTLSErrors153=== CONT TestScriptTokenBadJSON154=== CONT TestScriptTokenEmptyToken155=== CONT TestScriptTokenCachesUntilRefresh156=== CONT TestScriptTokenNoExpiryRerunsEveryCall157=== CONT TestFileTokenEmpty158=== CONT TestFileTokenMissing159=== CONT TestFileTokenReadsAndCaches160=== CONT TestStaticToken161=== CONT TestRegisterUploadedObject_OutlivesPush162=== CONT TestStreamPushReportsEveryPath163=== CONT TestShellSplitErrors164=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false165--- PASS: TestResolveStorePath (1.14s)166--- PASS: TestScriptTokenScriptFails (1.66s)167=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun168=== CONT TestUploadMultipart_PartsInParallel169--- PASS: TestShellSplitErrors (0.00s)170=== CONT TestFilterOversizedClosures171=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false172=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true173=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true174=== RUN TestFilterOversizedClosures/no_limit_keeps_everything175=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything176=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped177=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped178=== RUN TestFilterOversizedClosures/all_closures_skipped179=== PAUSE TestFilterOversizedClosures/all_closures_skipped180=== CONT TestRegisterUploadedObjectReusesConnections181--- PASS: TestFileTokenEmpty (0.00s)182=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica183--- PASS: TestFileTokenReadsAndCaches (0.00s)184=== CONT TestPathInfoCACompatibility185=== RUN TestPathInfoCACompatibility/null_ca_field186=== PAUSE TestPathInfoCACompatibility/null_ca_field187=== RUN TestPathInfoCACompatibility/old_string_format_-_text188=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text189=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive190=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive191=== RUN TestPathInfoCACompatibility/new_structured_format_-_text192=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text193=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method194=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method195=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer196=== CONT TestCaseHackSuffix197--- PASS: TestStaticToken (0.00s)198=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess199=== RUN TestPartSizeForNAR/zero_stays_at_minimum200--- PASS: TestFileTokenMissing (0.01s)201=== CONT TestRateLimiterFeedback202=== RUN TestRateLimiterFeedback/429_enables_limiter2032026/11/11 23:36:29 WARN Rate limiter enabled after throttle name=server-test rate=5204=== RUN TestSetClientTLSErrors/missing_cert_file2052026/11/11 23:36:29 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:42871/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:42871/api/uploads/complete2062026/11/11 23:36:29 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"2072026/11/11 23:36:30 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:42871/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:42871/api/uploads/complete2082026/11/11 23:36:30 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"2092026/11/11 23:36:30 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:42871/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:42871/api/uploads/complete2102026/11/11 23:36:30 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"211--- PASS: TestStreamPushReportsEveryPath (1.87s)212=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry213--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.87s)214=== CONT TestStreamPushReportsSkippedPaths215=== PAUSE TestRateLimiterFeedback/429_enables_limiter216=== RUN TestRateLimiterFeedback/503_enables_limiter217=== PAUSE TestRateLimiterFeedback/503_enables_limiter218=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter219=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter220=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter221=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter222--- PASS: TestStreamPushReportsSkippedPaths (0.00s)223=== CONT TestSetClientTLSDoesNotMutateDefaultTransport224--- PASS: TestRegisterUploadedObject_OutlivesPush (1.87s)225=== CONT TestStreamPushStopsWhenCanceled2262026/11/11 23:36:30 WARN Rate limiter enabled after throttle name=server-test rate=52272026/11/11 23:36:30 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:43067228--- PASS: TestStreamPushStopsWhenCanceled (0.00s)229=== CONT TestClientSignaturesByStorePath230=== CONT TestSetClientTLS231=== PAUSE TestSetClientTLSErrors/missing_cert_file232=== RUN TestSetClientTLSErrors/missing_key_file233=== PAUSE TestSetClientTLSErrors/missing_key_file2342026/11/11 23:36:30 WARN Rate limiter enabled after throttle name=server-test rate=5235=== RUN TestSetClientTLSErrors/missing_ca_file236=== PAUSE TestSetClientTLSErrors/missing_ca_file2372026/11/11 23:36:30 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:45967238=== RUN TestSetClientTLSErrors/invalid_ca_file239=== PAUSE TestSetClientTLSErrors/invalid_ca_file2402026/11/11 23:36:30 WARN Rate limiter backed off name=server-test rate=5241=== CONT TestStreamPushReportsSignatures2422026/11/11 23:36:30 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:430672432026/11/11 23:36:30 INFO Garbage collection started2442026/11/11 23:36:30 WARN Rate limiter backed off name=server-test rate=5245=== CONT TestParsePathInfoJSON246=== RUN TestParsePathInfoJSON/Nix_format247=== CONT TestParsePathInfoJSONMultiplePaths248=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths249=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths250=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2512026/11/11 23:36:30 ERROR Upload failed error=boom count=1252=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths253=== PAUSE TestParsePathInfoJSON/Nix_format254=== CONT TestStreamPushGivesUpOnDeadServer255=== RUN TestParsePathInfoJSON/Lix_format2562026/11/11 23:36:30 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:34247257=== PAUSE TestParsePathInfoJSON/Lix_format2582026/11/11 23:36:30 ERROR Upload failed error="connection refused" count=20259=== RUN TestParsePathInfoJSON/empty_input2602026/11/11 23:36:30 ERROR Server seems unavailable, giving up on batch untried=17261=== PAUSE TestParsePathInfoJSON/empty_input262=== RUN TestParsePathInfoJSON/whitespace_only263=== PAUSE TestParsePathInfoJSON/whitespace_only264=== RUN TestParsePathInfoJSON/invalid_JSON265=== PAUSE TestParsePathInfoJSON/invalid_JSON266=== CONT TestStreamPushRequestLine267=== CONT TestPathInfoHashCompatibility268=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error269=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error270=== CONT TestGetStorePathHash/basename_without_hyphen_should_error271=== CONT TestConvertHashToNix32/invalid_format272=== CONT TestConvertHashToNix32/already_Nix32_format273=== CONT TestEncodeNixBase32/test_string_hash274=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false275=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)276=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)2772026/11/11 23:36:30 ERROR Upload failed error=boom count=1278=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon279=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon280=== CONT TestEncodeNixBase32/empty_input281=== CONT TestFilterOversizedClosures/no_limit_keeps_everything282=== CONT TestFilterOversizedClosures/all_closures_skipped2832026/11/11 23:36:30 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=50284=== CONT TestPathInfoCACompatibility/null_ca_field2852026/11/11 23:36:30 INFO Garbage collection started286=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method2872026/11/11 23:36:30 WARN Rate limiter enabled after throttle name=s3-test rate=52882026/11/11 23:36:30 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:32885289=== CONT TestPathInfoCACompatibility/new_structured_format_-_text290=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive291=== CONT TestPathInfoCACompatibility/old_string_format_-_text292=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true293=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2942026/11/11 23:36:30 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=2000295=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter296=== CONT TestConvertHashToNix32/SRI_format_to_Nix32297--- PASS: TestClientSignaturesByStorePath (0.00s)2982026/11/11 23:36:30 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:34247299--- PASS: TestDoServerRequestAttachesToken (3.54s)300=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI301=== CONT TestStreamPushIsolatesFailures302=== CONT TestGetStorePathHash/valid_store_path303=== CONT TestRateLimiterFeedback/429_enables_limiter304=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI305=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha5123062026/11/11 23:36:30 ERROR Upload failed error="bad path" count=3307=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512308=== CONT TestSetClientTLSErrors/missing_cert_file309=== CONT TestSetClientTLSErrors/missing_key_file310=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter311=== CONT TestParsePathInfoJSON/Nix_format312=== CONT TestRateLimiterFeedback/503_enables_limiter313=== CONT TestParsePathInfoJSON/invalid_JSON314=== CONT TestParsePathInfoJSON/whitespace_only315=== CONT TestParsePathInfoJSON/empty_input316=== CONT TestParsePathInfoJSON/Lix_format3172026/11/11 23:36:30 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=0318=== CONT TestSetClientTLSErrors/invalid_ca_file3192026/11/11 23:36:30 WARN Rate limiter enabled after throttle name=server-test rate=53202026/11/11 23:36:30 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:37901321=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)322=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512323=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon324=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI325=== CONT TestSetClientTLSErrors/missing_ca_file3262026/11/11 23:36:30 WARN Rate limiter enabled after throttle name=server-test rate=53272026/11/11 23:36:30 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:41989328=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths3292026/11/11 23:36:30 WARN Rate limiter backed off name=server-test rate=5330--- PASS: TestDoWithRetry_FinalResponseBodyReadable (3.54s)331--- PASS: TestStreamPushReportsSignatures (0.00s)332--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (3.54s)333--- PASS: TestUploadMultipart_ReturnsAfterDroppedBody (3.54s)334--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)335--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (1.88s)336=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum337=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths338=== RUN TestSetClientTLS/rejects_connection_without_client_cert339=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert340=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA341=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA342=== RUN TestSetClientTLS/preserves_debug_logging_transport343=== PAUSE TestSetClientTLS/preserves_debug_logging_transport344=== CONT TestSetClientTLS/rejects_connection_without_client_cert3452026/11/11 23:36:30 WARN Rate limiter backed off name=server-test rate=53462026/11/11 23:36:30 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:34247347=== RUN TestPartSizeForNAR/small_stays_at_minimum348=== PAUSE TestPartSizeForNAR/small_stays_at_minimum349=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum350=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum351--- PASS: TestEncodeNixBase32 (0.00s)352 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)353 --- PASS: TestEncodeNixBase32/empty_input (0.00s)354=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts355=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts356--- PASS: TestScriptTokenEmptyToken (1.87s)357=== RUN TestPartSizeForNAR/1_TiB358=== PAUSE TestPartSizeForNAR/1_TiB359=== RUN TestPartSizeForNAR/5_TiB_S3_max_object360=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object361=== RUN TestPartSizeForNAR/capped_at_5_GiB362=== PAUSE TestPartSizeForNAR/capped_at_5_GiB363=== CONT TestPartSizeForNAR/zero_stays_at_minimum364--- PASS: TestPathInfoCACompatibility (0.00s)365 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)366 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)367 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)368 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)369 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)370=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA371=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts372=== CONT TestPartSizeForNAR/capped_at_5_GiB373=== CONT TestPartSizeForNAR/5_TiB_S3_max_object374=== CONT TestPartSizeForNAR/1_TiB3752026/11/11 23:36:30 WARN Garbage collection finished on another replica. Its statistics are not available here3762026/11/11 23:36:30 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:34247377--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (1.88s)378=== CONT TestPartSizeForNAR/small_stays_at_minimum379--- PASS: TestFilterOversizedClosures (0.00s)380 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)381 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)382 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)383--- PASS: TestScriptTokenBadJSON (1.87s)384--- PASS: TestStreamPushIsolatesFailures (0.00s)385--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.01s)386--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)387=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum388--- PASS: TestPartSizeForNAR (1.87s)389 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)390 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)391 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)392 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)393 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)394 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)395 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)396=== CONT TestSetClientTLS/preserves_debug_logging_transport397--- PASS: TestConvertHashToNix32 (0.00s)398 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)399 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)400 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)401--- PASS: TestScriptTokenCachesUntilRefresh (1.87s)402--- PASS: TestStreamPushBatchesUnderLoad (1.66s)403 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)404 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)405--- PASS: TestGetStorePathHash (0.00s)406 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)407 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)408 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)409 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)410--- PASS: TestPathInfoHashCompatibility (0.00s)411 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)412 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)413 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)414 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)415--- PASS: TestParsePathInfoJSON (0.00s)416 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)417 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)418 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)419 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)420 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)421--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)422 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)423 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)424--- PASS: TestRateLimiterFeedback (1.87s)425 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)426 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)427 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)428 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)429--- PASS: TestSetClientTLSErrors (1.87s)430 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)431 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)432 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)433 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)4342026/11/11 23:36:30 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:34247435--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)4362026/11/11 23:36:30 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:342474372026/11/11 23:36:30 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:342474382026/11/11 23:36:32 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:34247439--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (3.52s)4402026/11/11 23:36:34 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:342474412026/11/11 23:36:34 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:34247442--- PASS: TestDumpPathSingleFile (4.94s)443--- PASS: TestCaseHackSuffix (4.93s)4442026/11/11 23:36:34 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:342474452026/11/11 23:36:34 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:34247446--- PASS: TestRegisterUploadedObjectReusesConnections (4.94s)4472026/11/11 23:36:34 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:342474482026/11/11 23:36:34 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:342474492026/11/11 23:36:34 http: TLS handshake error from 127.0.0.1:57966: remote error: tls: bad certificate450--- PASS: TestSetClientTLS (0.01s)451 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)452 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)453 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (3.06s)4542026/11/11 23:36:34 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:342474552026/11/11 23:36:34 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:34247456--- PASS: TestStreamPushRequestLine (3.07s)4572026/11/11 23:36:34 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:342474582026/11/11 23:36:34 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:342474592026/11/11 23:36:34 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:34247460--- PASS: TestRetryTimeoutOutlastsMaxRetries (6.61s)461--- PASS: TestDumpPathWriterError (6.62s)462--- PASS: TestUploadMultipart_PartsInParallel (5.53s)463--- PASS: TestDumpPathMatchesNix (6.02s)464PASS465Running server tests...466The files belonging to this database system will be owned by user "nixbld".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 /build/postgres284427648/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 /build/postgres284427648/data -l logfile start492493/build/postgres284427648:5432 - no response494/build/postgres284427648:5432 - no response495/build/postgres284427648:5432 - no response496/build/postgres284427648:5432 - no response4972026-11-11 23:36:40.214 UTC [131] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4982026-11-11 23:36:40.216 UTC [131] LOG: listening on Unix socket "/build/postgres284427648/.s.PGSQL.5432"4992026-11-11 23:36:40.226 UTC [141] LOG: database system was shut down at 2026-11-11 23:36:39 UTC5002026-11-11 23:36:40.231 UTC [131] LOG: database system is ready to accept connections5012026-11-11 23:36:40.232 UTC [143] FATAL: the database system is starting up502/build/postgres284427648:5432 - rejecting connections503/build/postgres284427648:5432 - accepting connections504{"timestamp":"2026-11-11T23:36:50.772667064Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"e6def6d4-d3e4-496b-b5af-740e27ed2cf7","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":16,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(206)"}505{"timestamp":"2026-11-11T23:36:50.885297939Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"628fca41-77da-4f05-908b-0a903fe3fde9","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(209)"}506{"timestamp":"2026-11-11T23:36:50.988980448Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"e60e2014-fb46-43da-b81b-39625919c502","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(200)"}507=== RUN TestAbortSucceeded508=== PAUSE TestAbortSucceeded509=== RUN TestService_AuthMiddleware510=== PAUSE TestService_AuthMiddleware511=== RUN TestService_AuthMiddleware_MTLSProxyHeader512=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader513=== RUN TestService_AuthMiddleware_MTLSBoundSubjects514=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects515=== RUN TestService_ReadAuthMiddleware516=== PAUSE TestService_ReadAuthMiddleware517=== RUN TestService_AuthMiddleware_OIDC518=== PAUSE TestService_AuthMiddleware_OIDC519=== RUN TestService_RequireScope_OIDC520=== PAUSE TestService_RequireScope_OIDC521=== RUN TestService_ReadScope_PublicByDefault522=== PAUSE TestService_ReadScope_PublicByDefault523=== RUN TestCacheConfigHandler524=== PAUSE TestCacheConfigHandler525=== RUN TestCacheStatsHandler526=== PAUSE TestCacheStatsHandler527=== RUN TestClientCADerivations528=== PAUSE TestClientCADerivations529=== RUN TestClientErrorHandling530=== PAUSE TestClientErrorHandling531=== RUN TestClientIntegration532=== PAUSE TestClientIntegration533=== RUN TestClientMultipleUploads534=== PAUSE TestClientMultipleUploads535=== RUN TestClientWithDependencies536=== PAUSE TestClientWithDependencies537=== RUN TestClientSharedPathCommittedMidPush538=== PAUSE TestClientSharedPathCommittedMidPush539=== RUN TestPinProtectsFromGC540=== PAUSE TestPinProtectsFromGC541=== RUN TestClientPushesUseOnePush542=== PAUSE TestClientPushesUseOnePush543=== RUN TestClientFallsBackToClosures544=== PAUSE TestClientFallsBackToClosures545=== RUN TestDeleteClosuresRacingPins546=== PAUSE TestDeleteClosuresRacingPins547=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock548=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock549=== RUN TestResolveDBConnectionString550=== PAUSE TestResolveDBConnectionString551=== RUN TestConnectWaitsForAPeerMigration552=== PAUSE TestConnectWaitsForAPeerMigration553=== RUN TestLeadElectsOneAndHandsOver554=== PAUSE TestLeadElectsOneAndHandsOver555=== RUN TestLeadIncumbentWinsAfterRestart5562026/11/11 23:36:53 INFO lead: acquired remote=192.0.2.1:1234 generation=15572026/11/11 23:36:53 INFO lead: released remote=192.0.2.1:1234 generation=15582026/11/11 23:36:53 INFO lead: acquired remote=192.0.2.1:1234 generation=25592026/11/11 23:36:54 INFO lead: released remote=192.0.2.1:1234 generation=2560--- PASS: TestLeadIncumbentWinsAfterRestart (3.70s)561=== RUN TestLeadUnannouncedStandbyYieldsToIncumbent562=== PAUSE TestLeadUnannouncedStandbyYieldsToIncumbent563=== RUN TestLeadIncumbentAnnouncesAtOnce564=== PAUSE TestLeadIncumbentAnnouncesAtOnce565=== RUN TestLeadGenerationGrowsWithEveryGrant566=== PAUSE TestLeadGenerationGrowsWithEveryGrant567=== RUN TestLeadEndsOnShutdown568=== PAUSE TestLeadEndsOnShutdown569=== RUN TestLeadEndsWhenItsConnectionHangs5702026/11/11 23:36:55 INFO lead: acquired remote=192.0.2.1:1234 generation=15712026-11-11 23:36:57.307 UTC [393] FATAL: terminating connection due to administrator command5722026/11/11 23:36:57 INFO lead: acquired remote=192.0.2.1:1234 generation=25732026/11/11 23:36:58 WARN lead: lock connection lost error="timeout: context deadline exceeded"5742026/11/11 23:36:58 INFO lead: released remote=192.0.2.1:1234 generation=15752026/11/11 23:36:58 INFO lead: released remote=192.0.2.1:1234 generation=2576--- PASS: TestLeadEndsWhenItsConnectionHangs (4.08s)577=== RUN TestGCAdvisoryLockBlocksConcurrentRun578=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun579=== RUN TestGCBugBareHashReferences580=== PAUSE TestGCBugBareHashReferences581=== RUN TestGCMetrics582=== PAUSE TestGCMetrics583=== RUN TestPushDedupSurvivesConcurrentGC584=== PAUSE TestPushDedupSurvivesConcurrentGC585=== RUN TestDeduplicatedObjectsRecordedAsPending586=== PAUSE TestDeduplicatedObjectsRecordedAsPending587=== RUN TestGCSweepSkipsPendingObjects588=== PAUSE TestGCSweepSkipsPendingObjects589=== RUN TestTombstonedObjectOfferedWithoutWaiting590=== PAUSE TestTombstonedObjectOfferedWithoutWaiting591=== RUN TestGCSweepDeliversEachKeyOnce592=== PAUSE TestGCSweepDeliversEachKeyOnce593=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection594=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection595=== RUN TestForceGCDuringPushOffersSweptObject596=== PAUSE TestForceGCDuringPushOffersSweptObject597=== RUN TestFailedS3DeleteKeepsTombstone598=== PAUSE TestFailedS3DeleteKeepsTombstone599=== RUN TestSweepSkipsRowsLockedByPush600=== PAUSE TestSweepSkipsRowsLockedByPush601=== RUN TestRegisterCompletedObjectNeedsPendingRow602=== PAUSE TestRegisterCompletedObjectNeedsPendingRow603=== RUN TestGetExistingObjectsLocksRows604=== PAUSE TestGetExistingObjectsLocksRows605=== RUN TestSweepRechecksPendingAfterLocking606=== PAUSE TestSweepRechecksPendingAfterLocking607=== RUN TestPushWaitsForSweepHoldingRow608=== PAUSE TestPushWaitsForSweepHoldingRow609=== RUN TestCommitRacingPendingCleanupKeepsObjects610=== PAUSE TestCommitRacingPendingCleanupKeepsObjects611=== RUN TestGCEndsOnShutdown612=== PAUSE TestGCEndsOnShutdown613=== RUN TestGCTaskStore_StartNew614=== PAUSE TestGCTaskStore_StartNew615=== RUN TestGCTaskStore_DeduplicateSameParams616=== PAUSE TestGCTaskStore_DeduplicateSameParams617=== RUN TestGCTaskStore_ConflictDifferentParams618=== PAUSE TestGCTaskStore_ConflictDifferentParams619=== RUN TestGCTaskStore_GetEmpty620=== PAUSE TestGCTaskStore_GetEmpty621=== RUN TestGCTaskStore_GetReturnsLatest622=== PAUSE TestGCTaskStore_GetReturnsLatest623=== RUN TestGCTaskStore_CompletedAllowsNewTask624=== PAUSE TestGCTaskStore_CompletedAllowsNewTask625=== RUN TestGCTaskStore_PhaseUpdates626=== PAUSE TestGCTaskStore_PhaseUpdates627=== RUN TestGCTaskStore_Fail628=== PAUSE TestGCTaskStore_Fail629=== RUN TestGracefulShutdownDrainsInflight630=== PAUSE TestGracefulShutdownDrainsInflight631=== RUN TestService_healthCheckHandler632=== PAUSE TestService_healthCheckHandler633=== RUN TestService_readinessHandler634=== PAUSE TestService_readinessHandler635=== RUN TestGenerateLandingPage636=== PAUSE TestGenerateLandingPage637=== RUN TestEnsureAbortUploadsRule638=== PAUSE TestEnsureAbortUploadsRule639=== RUN TestCacheConfigHandlerMaxNarSize640=== PAUSE TestCacheConfigHandlerMaxNarSize641=== RUN TestCreatePendingClosureRejectsOversizedNAR642=== PAUSE TestCreatePendingClosureRejectsOversizedNAR643=== RUN TestNARDeduplicationMetadataUploadBug644=== PAUSE TestNARDeduplicationMetadataUploadBug645=== RUN TestMetricsInventory646=== PAUSE TestMetricsInventory647=== RUN TestMetricsCommit648=== PAUSE TestMetricsCommit649=== RUN TestService_NativeMTLS650=== PAUSE TestService_NativeMTLS651=== RUN TestServerTLSConfig652=== PAUSE TestServerTLSConfig653=== RUN TestMultipartCleanup654=== PAUSE TestMultipartCleanup655=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded656=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded657=== RUN TestPendingCleanupUsesOneCutoff658=== PAUSE TestPendingCleanupUsesOneCutoff659=== RUN TestObjectStatsTrigger660=== PAUSE TestObjectStatsTrigger661=== RUN TestObjectStatsUpdatedOncePerCommit662=== PAUSE TestObjectStatsUpdatedOncePerCommit663=== RUN TestOrphanedObjectsGC664=== PAUSE TestOrphanedObjectsGC665=== RUN TestOrphanedObjectsGCStressTest666=== PAUSE TestOrphanedObjectsGCStressTest667=== RUN TestCreatePin_ReservedPins668=== PAUSE TestCreatePin_ReservedPins669=== RUN TestPresentReportsOnlyClosureRoots670=== PAUSE TestPresentReportsOnlyClosureRoots671=== RUN TestPresentRefreshesOnlyStaleClosures672=== PAUSE TestPresentRefreshesOnlyStaleClosures673=== RUN TestPresentNotReportedWhileGCDeletesClosure674=== PAUSE TestPresentNotReportedWhileGCDeletesClosure675=== RUN TestParseSingleRange676=== PAUSE TestParseSingleRange677=== RUN TestProxyHeadersOnlyTrustedOnSocket6782026/11/11 23:37:00 INFO Starting HTTP server address=127.0.0.1:377816792026/11/11 23:37:00 INFO Starting HTTP server address=proxy.sock6802026/11/11 23:37:00 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6812026/11/11 23:37:00 INFO Shutdown signal received, draining in-flight requests timeout=10s682--- PASS: TestProxyHeadersOnlyTrustedOnSocket (1.79s)683=== RUN TestIsValidCachePath684=== PAUSE TestIsValidCachePath685=== RUN TestReadProxyNarinfo686=== PAUSE TestReadProxyNarinfo687=== RUN TestReadProxyNarinfoAlreadyDecompressed688=== PAUSE TestReadProxyNarinfoAlreadyDecompressed689=== RUN TestReadProxyContentNegotiation690=== PAUSE TestReadProxyContentNegotiation691=== RUN TestReadProxyNarStreaming692=== PAUSE TestReadProxyNarStreaming693=== RUN TestReadProxy404694=== PAUSE TestReadProxy404695=== RUN TestReadProxyInvalidPath696=== PAUSE TestReadProxyInvalidPath697=== RUN TestReadProxyHead698=== PAUSE TestReadProxyHead699=== RUN TestReadProxyOutlastsServerWriteTimeout700=== PAUSE TestReadProxyOutlastsServerWriteTimeout701=== RUN TestReadProxyConditionalGet702=== PAUSE TestReadProxyConditionalGet703=== RUN TestReadProxyRootRedirectsToIndexHTML704=== PAUSE TestReadProxyRootRedirectsToIndexHTML705=== RUN TestReadProxyDisabled706=== PAUSE TestReadProxyDisabled707=== RUN TestReadRedirectNar708=== PAUSE TestReadRedirectNar709=== RUN TestReadRedirectKeepsNarinfoProxied710=== PAUSE TestReadRedirectKeepsNarinfoProxied711=== RUN TestReadProxyRangeRequest712=== PAUSE TestReadProxyRangeRequest713=== RUN TestReadRedirectUsesPublicS3URL714=== PAUSE TestReadRedirectUsesPublicS3URL715=== RUN TestPush_OverlappingRootsStoreOneRowPerKey716=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey717=== RUN TestPush_CompleteCommitsEveryRoot718=== PAUSE TestPush_CompleteCommitsEveryRoot719=== RUN TestPush_RepeatedRootCommitsOnce720=== PAUSE TestPush_RepeatedRootCommitsOnce721=== RUN TestPush_CompleteWaitsForCleanupOfThePush722=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush723=== RUN TestPush_RootsAreLockedInByteOrder724=== PAUSE TestPush_RootsAreLockedInByteOrder725=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit726=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit727=== RUN TestPush_RejectsBadRequests728=== PAUSE TestPush_RejectsBadRequests729=== RUN TestPush_SignsNarinfosOfItsPendingObjects730=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects731=== RUN TestSharedNarBothUploadsComplete732=== PAUSE TestSharedNarBothUploadsComplete733=== RUN TestCompleteMultipartUpload_ErrorButObjectExists734=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists735=== RUN TestCompletedNarNotReofferedAcrossClosures736=== PAUSE TestCompletedNarNotReofferedAcrossClosures737=== RUN TestPresignedUploadRegisteredBeforeCommit738=== PAUSE TestPresignedUploadRegisteredBeforeCommit739=== RUN TestService_Rustfstest740=== PAUSE TestService_Rustfstest741=== RUN TestParseSize742=== PAUSE TestParseSize743=== RUN TestSkippedUploadsHandler744=== PAUSE TestSkippedUploadsHandler745=== RUN TestSystemdListenerNotActivated746--- PASS: TestSystemdListenerNotActivated (0.00s)747=== RUN TestWatchdogBeatsWhenHealthy748--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)749=== RUN TestWatchdogSkipsWhenUnhealthy7502026/11/11 23:37:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7512026/11/11 23:37:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7522026/11/11 23:37:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7532026/11/11 23:37:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7542026/11/11 23:37:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7552026/11/11 23:37:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7562026/11/11 23:37:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7572026/11/11 23:37:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7582026/11/11 23:37:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7592026/11/11 23:37:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"760--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)761=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle762=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle763=== RUN TestProxyWriteTimeout764=== PAUSE TestProxyWriteTimeout765=== RUN TestPendingClosureWriteTimeout766=== PAUSE TestPendingClosureWriteTimeout767=== RUN TestIsValidUploadKey768=== PAUSE TestIsValidUploadKey769=== RUN TestUploadHandlersRejectInvalidKeys770=== PAUSE TestUploadHandlersRejectInvalidKeys771=== RUN TestUploadHandlersRejectOversizedBody772=== PAUSE TestUploadHandlersRejectOversizedBody773=== RUN TestService_cleanupPendingClosuresHandler774=== PAUSE TestService_cleanupPendingClosuresHandler775=== RUN TestService_createPendingClosureHandler776=== PAUSE TestService_createPendingClosureHandler777=== RUN TestService_verifyS3Integrity778=== PAUSE TestService_verifyS3Integrity779=== RUN TestService_verifyS3ReuploadsStaleNarinfo780=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo781=== RUN TestCompleteMultipartUnregistered782=== PAUSE TestCompleteMultipartUnregistered783=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT784=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT785=== CONT TestAbortSucceeded786--- PASS: TestAbortSucceeded (0.00s)787=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT788=== CONT TestCreatePendingClosureRejectsOversizedNAR789=== CONT TestGCMetrics790=== CONT TestClientSharedPathCommittedMidPush791=== CONT TestLeadElectsOneAndHandsOver792=== CONT TestGCEndsOnShutdown7932026/11/11 23:37:00 INFO Received uploads request method=POST path=/api/pending_closures794=== CONT TestDeleteClosuresRacingPins795=== RUN TestGCEndsOnShutdown/before_the_run796=== PAUSE TestGCEndsOnShutdown/before_the_run797=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete798=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete799=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark800=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark801=== CONT TestGCEndsOnShutdown/before_the_run802--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)803=== CONT TestCompleteMultipartUnregistered804=== CONT TestFailedS3DeleteKeepsTombstone805=== CONT TestResolveDBConnectionString806=== RUN TestResolveDBConnectionString/flag_wins807=== PAUSE TestResolveDBConnectionString/flag_wins808=== RUN TestResolveDBConnectionString/file_when_flag_empty809=== PAUSE TestResolveDBConnectionString/file_when_flag_empty810=== RUN TestResolveDBConnectionString/missing_file_is_an_error811=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error812=== RUN TestResolveDBConnectionString/PGHOST_allows_empty813=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty814=== RUN TestResolveDBConnectionString/nothing_configured815=== PAUSE TestResolveDBConnectionString/nothing_configured816=== CONT TestSweepRechecksPendingAfterLocking817=== CONT TestService_readinessHandler818=== CONT TestCommitRacingPendingCleanupKeepsObjects819=== CONT TestPushWaitsForSweepHoldingRow820=== CONT TestConnectWaitsForAPeerMigration821=== CONT TestCacheConfigHandler822=== CONT TestClientWithDependencies823=== RUN TestCacheConfigHandler/full_config,_no_issuer824=== PAUSE TestCacheConfigHandler/full_config,_no_issuer825=== RUN TestCacheConfigHandler/no_cache_url_configured826=== PAUSE TestCacheConfigHandler/no_cache_url_configured827=== RUN TestCacheConfigHandler/no_signing_keys828=== PAUSE TestCacheConfigHandler/no_signing_keys829=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator830=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator831=== CONT TestService_healthCheckHandler832=== CONT TestClientMultipleUploads833=== CONT TestClientIntegration834=== CONT TestClientErrorHandling835=== RUN TestClientErrorHandling/InvalidStorePath836=== CONT TestClientCADerivations837=== CONT TestCacheStatsHandler838=== CONT TestGCTaskStore_PhaseUpdates839--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)840=== CONT TestGracefulShutdownDrainsInflight841=== CONT TestCacheConfigHandlerMaxNarSize842--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)843=== CONT TestGCTaskStore_Fail844--- PASS: TestGCTaskStore_Fail (0.00s)845=== CONT TestTombstonedObjectOfferedWithoutWaiting8462026/11/11 23:37:01 INFO Starting HTTP server address=127.0.0.1:43971847=== CONT TestEnsureAbortUploadsRule848=== CONT TestGenerateLandingPage849=== PAUSE TestClientErrorHandling/InvalidStorePath850=== RUN TestClientErrorHandling/InvalidAuthToken851=== PAUSE TestClientErrorHandling/InvalidAuthToken852=== RUN TestClientErrorHandling/ServerNotAvailable853=== PAUSE TestClientErrorHandling/ServerNotAvailable854=== CONT TestForceGCDuringPushOffersSweptObject855=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows856=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows857=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check858=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check859=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection8602026/11/11 23:37:02 INFO Shutdown signal received, draining in-flight requests timeout=10s861--- PASS: TestGracefulShutdownDrainsInflight (1.22s)862=== CONT TestGCSweepDeliversEachKeyOnce863--- PASS: TestGenerateLandingPage (1.25s)864=== CONT TestRegisterCompletedObjectNeedsPendingRow8652026/11/11 23:37:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8662026/11/11 23:37:02 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst867--- PASS: TestCompleteMultipartUnregistered (1.80s)868=== CONT TestGetExistingObjectsLocksRows8692026/11/11 23:37:02 WARN readiness check failed error="closed pool"870--- PASS: TestService_readinessHandler (1.81s)871=== CONT TestReadRedirectNar8722026/11/11 23:37:02 INFO Installed lifecycle rule aborting incomplete NAR uploads bucket=bucket6 days=2873--- PASS: TestEnsureAbortUploadsRule (1.45s)874=== CONT TestService_verifyS3ReuploadsStaleNarinfo875=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed876=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed877=== RUN TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed878=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed879=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost880=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost881=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed882=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed883=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed884=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed885=== CONT TestService_verifyS3Integrity886=== CONT TestService_createPendingClosureHandler887--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.39s)888=== CONT TestService_cleanupPendingClosuresHandler8892026/11/11 23:37:03 INFO Received uploads request method=POST path=/api/pending_closures8902026/11/11 23:37:03 INFO Received uploads request method=POST path=/api/pending_closures8912026/11/11 23:37:03 INFO Aborted multipart uploads count=0 kept=0892--- PASS: TestService_healthCheckHandler (1.83s)893=== CONT TestUploadHandlersRejectOversizedBody894--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (1.92s)895=== CONT TestUploadHandlersRejectInvalidKeys896=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info897=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info898=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal899=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal900=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key901=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key902=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key903=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key904=== CONT TestIsValidUploadKey905=== RUN TestIsValidUploadKey/narinfo906=== PAUSE TestIsValidUploadKey/narinfo907=== RUN TestIsValidUploadKey/nar_zst908=== PAUSE TestIsValidUploadKey/nar_zst909=== RUN TestIsValidUploadKey/nar_xz910=== PAUSE TestIsValidUploadKey/nar_xz911=== RUN TestIsValidUploadKey/nar_plain912=== PAUSE TestIsValidUploadKey/nar_plain913=== RUN TestIsValidUploadKey/listing914=== PAUSE TestIsValidUploadKey/listing915=== RUN TestIsValidUploadKey/build_log916=== PAUSE TestIsValidUploadKey/build_log917=== RUN TestIsValidUploadKey/build_log_home-manager_file918=== PAUSE TestIsValidUploadKey/build_log_home-manager_file919=== RUN TestIsValidUploadKey/build_log_plus_in_name920=== PAUSE TestIsValidUploadKey/build_log_plus_in_name921=== RUN TestIsValidUploadKey/build_log_question_mark922=== PAUSE TestIsValidUploadKey/build_log_question_mark923=== RUN TestIsValidUploadKey/build_log_equals924=== PAUSE TestIsValidUploadKey/build_log_equals925=== RUN TestIsValidUploadKey/realisation926=== PAUSE TestIsValidUploadKey/realisation927=== RUN TestIsValidUploadKey/realisation_plus_in_output928=== PAUSE TestIsValidUploadKey/realisation_plus_in_output929=== RUN TestIsValidUploadKey/nix-cache-info930=== PAUSE TestIsValidUploadKey/nix-cache-info931=== RUN TestIsValidUploadKey/index.html932=== PAUSE TestIsValidUploadKey/index.html933=== RUN TestIsValidUploadKey/narinfo_key,_nar_type934=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type935=== RUN TestIsValidUploadKey/nar_key,_narinfo_type936=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type937=== RUN TestIsValidUploadKey/listing_key,_narinfo_type938=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type939=== RUN TestIsValidUploadKey/traversal940=== PAUSE TestIsValidUploadKey/traversal941=== RUN TestIsValidUploadKey/traversal_nar942=== PAUSE TestIsValidUploadKey/traversal_nar943=== RUN TestIsValidUploadKey/absolute944=== PAUSE TestIsValidUploadKey/absolute945=== RUN TestIsValidUploadKey/empty_key946=== PAUSE TestIsValidUploadKey/empty_key947=== RUN TestIsValidUploadKey/unknown_type948=== PAUSE TestIsValidUploadKey/unknown_type949=== CONT TestPendingClosureWriteTimeout950=== RUN TestPendingClosureWriteTimeout/empty951=== PAUSE TestPendingClosureWriteTimeout/empty952=== RUN TestPendingClosureWriteTimeout/400_objects953=== PAUSE TestPendingClosureWriteTimeout/400_objects954=== RUN TestPendingClosureWriteTimeout/670k_objects955=== PAUSE TestPendingClosureWriteTimeout/670k_objects956=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline957=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline958=== CONT TestProxyWriteTimeout959=== RUN TestProxyWriteTimeout/narinfo960=== PAUSE TestProxyWriteTimeout/narinfo961=== RUN TestProxyWriteTimeout/1_GiB_nar962=== PAUSE TestProxyWriteTimeout/1_GiB_nar963=== RUN TestProxyWriteTimeout/10_GiB_nar964=== PAUSE TestProxyWriteTimeout/10_GiB_nar965=== RUN TestProxyWriteTimeout/unknown_size966=== PAUSE TestProxyWriteTimeout/unknown_size967=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle9682026/11/11 23:37:03 INFO Received uploads request method=POST path=/api/pending_closures969--- PASS: TestTombstonedObjectOfferedWithoutWaiting (1.95s)970=== CONT TestSkippedUploadsHandler9712026/11/11 23:37:03 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000972--- PASS: TestSkippedUploadsHandler (0.01s)973=== CONT TestParseSize974--- PASS: TestParseSize (0.00s)975=== CONT TestService_Rustfstest9762026/11/11 23:37:03 INFO Aborted multipart uploads count=0 kept=09772026/11/11 23:37:03 INFO Received uploads request method=POST path=/api/pending_closures978=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure979=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure980=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart981=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart982=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts983=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts984=== CONT TestPresignedUploadRegisteredBeforeCommit985--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (2.53s)986=== CONT TestCompletedNarNotReofferedAcrossClosures9872026/11/11 23:37:03 INFO Received uploads request method=POST path=/api/pending_closures9882026/11/11 23:37:03 INFO Aborted multipart uploads count=0 kept=0989--- PASS: TestCacheStatsHandler (2.14s)990=== CONT TestCompleteMultipartUpload_ErrorButObjectExists991--- PASS: TestReadRedirectNar (0.82s)992=== CONT TestSharedNarBothUploadsComplete9932026/11/11 23:37:03 INFO lead: acquired remote=192.0.2.1:1234 generation=19942026/11/11 23:37:03 INFO Aborted multipart uploads count=0 kept=09952026/11/11 23:37:03 WARN Force mode enabled - objects will be deleted immediately without grace period9962026/11/11 23:37:03 WARN Force mode enabled - objects will be deleted immediately without grace period9972026/11/11 23:37:03 WARN Force mode enabled - objects will be deleted immediately without grace period9982026/11/11 23:37:03 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09992026/11/11 23:37:03 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010002026/11/11 23:37:03 INFO Vacuumed table table=pending_closures10012026/11/11 23:37:03 INFO Vacuumed table table=pending_closures10022026/11/11 23:37:03 INFO Vacuumed table table=pending_objects10032026/11/11 23:37:03 INFO Vacuumed table table=multipart_uploads10042026/11/11 23:37:03 INFO Vacuumed table table=pending_objects10052026/11/11 23:37:03 INFO Vacuumed table table=multipart_uploads10062026/11/11 23:37:03 INFO Vacuumed table table=closures10072026/11/11 23:37:03 INFO Vacuumed table table=objects10082026/11/11 23:37:03 INFO Vacuumed table table=closures10092026/11/11 23:37:03 INFO Vacuumed table table=objects1010--- PASS: TestGCMetrics (2.82s)1011=== CONT TestPush_SignsNarinfosOfItsPendingObjects1012=== NAME TestClientIntegration1013 client_integration_test.go:292: Created store path: /build/TestClientIntegration3512219487/002/store/i67khvbckq3n91xf9qgawqs35m5nrjfp-test-file.txt1014=== NAME TestClientMultipleUploads1015 client_integration_test.go:406: Created store path 0: /build/TestClientMultipleUploads4224180425/001/store/7qprh86ild94bgs26rrral3gwbjhlbdv-test-file-0.txt10162026/11/11 23:37:03 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=010172026/11/11 23:37:03 INFO Vacuumed table table=pending_closures10182026/11/11 23:37:03 INFO Received uploads request method=POST path=/api/pending_closures10192026/11/11 23:37:03 INFO Vacuumed table table=pending_objects10202026/11/11 23:37:03 INFO Vacuumed table table=multipart_uploads10212026/11/11 23:37:03 INFO Vacuumed table table=closures10222026/11/11 23:37:03 INFO Vacuumed table table=objects1023--- PASS: TestGCSweepDeliversEachKeyOnce (1.19s)1024=== CONT TestPush_RejectsBadRequests10252026/11/11 23:37:03 INFO Received uploads request method=POST path=/api/pending_closures10262026/11/11 23:37:03 INFO Received uploads request method=POST path=/api/pending_closures10272026/11/11 23:37:03 INFO Received uploads request method=POST path=/api/pending_closures10282026/11/11 23:37:03 INFO Received uploads request method=POST path=/api/pending_closures1029--- PASS: TestPushWaitsForSweepHoldingRow (2.68s)1030=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit10312026/11/11 23:37:04 INFO Received uploads request method=POST path=/api/pending_closures10322026/11/11 23:37:04 INFO Received cleanup request method=DELETE path=/api/pending_closures10332026/11/11 23:37:04 INFO Aborted multipart uploads count=0 kept=010342026/11/11 23:37:04 INFO Received uploads request method=POST path=/api/pending_closures1035=== NAME TestClientMultipleUploads1036 client_integration_test.go:406: Created store path 1: /build/TestClientMultipleUploads4224180425/001/store/rbg2hg7allqckf849v89wigbr87ky0mx-test-file-1.txt1037--- PASS: TestCommitRacingPendingCleanupKeepsObjects (3.09s)1038=== CONT TestPush_RootsAreLockedInByteOrder10392026/11/11 23:37:04 WARN Force mode enabled - objects will be deleted immediately without grace period10402026/11/11 23:37:04 INFO Received cleanup request method=DELETE path=/api/pending_closures10412026/11/11 23:37:04 INFO Aborted multipart uploads count=0 kept=010422026/11/11 23:37:04 INFO Aborted multipart uploads count=1 kept=010432026/11/11 23:37:04 WARN Force mode enabled - objects will be deleted immediately without grace period10442026/11/11 23:37:04 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."10452026/11/11 23:37:04 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."10462026/11/11 23:37:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10472026-11-11 23:37:04.410 UTC [506] ERROR: Closure does not exist: id=110482026-11-11 23:37:04.410 UTC [506] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE10492026-11-11 23:37:04.410 UTC [506] STATEMENT: -- name: CommitPendingClosure :one1050 SELECT commit_pending_closure($1::bigint)::bigint1051 1052--- PASS: TestService_cleanupPendingClosuresHandler (1.37s)1053=== CONT TestPush_CompleteWaitsForCleanupOfThePush1054--- PASS: TestFailedS3DeleteKeepsTombstone (3.48s)1055=== CONT TestPush_RepeatedRootCommitsOnce1056=== NAME TestClientWithDependencies1057 client_integration_test.go:661: Built derivation: /build/TestClientWithDependencies405523964/001/store/63v7n8x9bxkvp2rjbpld3f2v2x9wnky8-test-script1058--- PASS: TestService_Rustfstest (1.07s)1059=== CONT TestPush_CompleteCommitsEveryRoot10602026/11/11 23:37:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10612026/11/11 23:37:04 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=010622026/11/11 23:37:04 INFO Vacuumed table table=pending_closures1063=== NAME TestClientCADerivations1064 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations326494917/001/store/5z1ihdhifpbhvqk72p0469ipdyr3600f-ca-test10652026/11/11 23:37:04 INFO Vacuumed table table=pending_objects10662026/11/11 23:37:04 INFO Vacuumed table table=multipart_uploads10672026/11/11 23:37:04 INFO Vacuumed table table=closures10682026/11/11 23:37:04 INFO Vacuumed table table=objects1069--- PASS: TestSweepRechecksPendingAfterLocking (3.53s)1070=== CONT TestPush_OverlappingRootsStoreOneRowPerKey10712026/11/11 23:37:04 INFO Received push request method=POST path=/api/pushes10722026/11/11 23:37:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10732026/11/11 23:37:04 INFO Signed narinfos id=1 count=110742026/11/11 23:37:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10752026/11/11 23:37:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10762026/11/11 23:37:04 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"10772026/11/11 23:37:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10782026/11/11 23:37:04 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"10792026/11/11 23:37:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10802026/11/11 23:37:04 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=110812026/11/11 23:37:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10822026/11/11 23:37:04 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1083--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.77s)1084=== CONT TestReadRedirectUsesPublicS3URL10852026/11/11 23:37:04 INFO Received uploads request method=POST path=/api/pending_closures1086=== NAME TestClientCADerivations1087 client_ca_test.go:139: Found 1 dependencies (including self)1088=== NAME TestClientWithDependencies1089 client_integration_test.go:663: Found 1 dependencies (including self)1090=== NAME TestClientMultipleUploads1091 client_integration_test.go:406: Created store path 2: /build/TestClientMultipleUploads4224180425/001/store/0md08s326k0lx7rlg7y5jl7aa61f55jc-test-file-2.txt1092=== RUN TestPush_RejectsBadRequests/no_objects1093=== PAUSE TestPush_RejectsBadRequests/no_objects1094=== RUN TestPush_RejectsBadRequests/bad_root1095=== PAUSE TestPush_RejectsBadRequests/bad_root1096=== RUN TestPush_RejectsBadRequests/root_not_in_objects1097=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1098=== RUN TestPush_RejectsBadRequests/no_roots1099=== PAUSE TestPush_RejectsBadRequests/no_roots1100=== CONT TestReadProxyRangeRequest11012026/11/11 23:37:04 INFO Received push request method=POST path=/api/pushes11022026/11/11 23:37:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11032026/11/11 23:37:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11042026/11/11 23:37:04 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YjAzZDg0NTUtOTUwNS00MWJkLWI4MjAtZDE0MGZiOWQ1NThlLmYwYmE4MDgyLTg3YTEtNDRjOS05MGQ0LThiYzQxZmQxNDk1NHgxNzk0NDQwMjI0NTQyODMwNzYz11052026/11/11 23:37:04 INFO Received complete push request method=POST path=/api/pushes/1/complete11062026/11/11 23:37:04 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YjAzZDg0NTUtOTUwNS00MWJkLWI4MjAtZDE0MGZiOWQ1NThlLmYwYmE4MDgyLTg3YTEtNDRjOS05MGQ0LThiYzQxZmQxNDk1NHgxNzk0NDQwMjI0NTQyODMwNzYz parts=11107--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.15s)1108=== CONT TestReadRedirectKeepsNarinfoProxied11092026/11/11 23:37:04 INFO Received uploads request method=POST path=/api/pending_closures11102026/11/11 23:37:04 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YjAzZDg0NTUtOTUwNS00MWJkLWI4MjAtZDE0MGZiOWQ1NThlLjNhNDQ0MTE4LWIxZTgtNGI5Zi04MzYyLWMzMGViNTdkNmM2MngxNzk0NDQwMjIzODYzNzA1ODY1 parts=1011112026/11/11 23:37:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11122026/11/11 23:37:04 INFO Completed upload id=1 objects=2 duration=3.863357ms11132026/11/11 23:37:04 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000011142026/11/11 23:37:04 INFO Received uploads request method=POST path=/api/pending_closures11152026/11/11 23:37:04 INFO Starting cleanup of old closures method=DELETE path=/api/closures11162026/11/11 23:37:04 INFO Aborted multipart uploads count=0 kept=011172026/11/11 23:37:04 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11182026/11/11 23:37:04 INFO Received uploads request method=POST path=/api/pending_closures1119--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.29s)1120=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock11212026/11/11 23:37:04 INFO Received uploads request method=POST path=/api/pending_closures11222026/11/11 23:37:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11232026/11/11 23:37:04 INFO Received uploads request method=POST path=/api/pending_closures11242026/11/11 23:37:04 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YjAzZDg0NTUtOTUwNS00MWJkLWI4MjAtZDE0MGZiOWQ1NThlLjRlODFhNzI4LTgzY2YtNGI5ZC05Y2I2LTA0YjEzNDIxMzdjNHgxNzk0NDQwMjIzODAwOTMzOTY2 parts=1211252026/11/11 23:37:04 INFO Received uploads request method=POST path=/api/pending_closures1126--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.33s)1127=== CONT TestPresentRefreshesOnlyStaleClosures11282026/11/11 23:37:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1129--- PASS: TestGetExistingObjectsLocksRows (2.06s)1130=== CONT TestReadProxyDisabled11312026/11/11 23:37:04 INFO Received push request method=POST path=/api/pushes11322026/11/11 23:37:04 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YjAzZDg0NTUtOTUwNS00MWJkLWI4MjAtZDE0MGZiOWQ1NThlLmJlMjliMDNhLWY2N2UtNGNlZS05Y2I4LTRjNjA1MjU1ZGNlYngxNzk0NDQwMjI0MDMzNTI1NTY1 parts=1011332026/11/11 23:37:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11342026/11/11 23:37:04 INFO Completed upload id=1 objects=2 duration=11.019105ms11352026/11/11 23:37:04 INFO Received uploads request method=POST path=/api/pending_closures11362026/11/11 23:37:04 INFO lead: released remote=192.0.2.1:1234 generation=111372026/11/11 23:37:04 INFO Received uploads request method=POST path=/api/pending_closures11382026/11/11 23:37:04 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo11392026/11/11 23:37:04 WARN Found objects in DB but missing from S3, will re-upload count=11140--- PASS: TestService_verifyS3Integrity (2.03s)1141=== CONT TestReadProxyRootRedirectsToIndexHTML11422026/11/11 23:37:04 INFO lead: acquired remote=192.0.2.1:1234 generation=211432026/11/11 23:37:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11442026/11/11 23:37:05 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YjAzZDg0NTUtOTUwNS00MWJkLWI4MjAtZDE0MGZiOWQ1NThlLjUxZmYzM2RlLWJlZWItNDZiMS05ZjhmLTMzNmFjMDM1ZWM0YXgxNzk0NDQwMjI0NzQ3NTAyNTk2 parts=1211452026/11/11 23:37:05 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=011462026/11/11 23:37:05 INFO Vacuumed table table=pending_closures11472026/11/11 23:37:05 INFO Vacuumed table table=pending_objects11482026/11/11 23:37:05 INFO Vacuumed table table=multipart_uploads11492026/11/11 23:37:05 INFO Vacuumed table table=closures11502026/11/11 23:37:05 INFO Vacuumed table table=objects11512026/11/11 23:37:05 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001152--- PASS: TestService_createPendingClosureHandler (2.73s)1153=== CONT TestReadProxyConditionalGet1154--- PASS: TestPresentRefreshesOnlyStaleClosures (0.88s)1155=== CONT TestReadProxyOutlastsServerWriteTimeout11562026/11/11 23:37:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1157--- PASS: TestReadRedirectUsesPublicS3URL (1.20s)1158=== CONT TestReadProxyHead1159--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.84s)1160=== CONT TestReadProxyInvalidPath11612026/11/11 23:37:05 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YjAzZDg0NTUtOTUwNS00MWJkLWI4MjAtZDE0MGZiOWQ1NThlLjVmYmE0ZTQ4LTFhYjktNDYwMy1iYzhlLWJiZWExM2Q3ZDdjM3gxNzk0NDQwMjI0NzYxNTE4MjI5 parts=121162--- PASS: TestSharedNarBothUploadsComplete (2.16s)1163=== CONT TestReadProxy40411642026/11/11 23:37:05 INFO Received push request method=POST path=/api/pushes11652026/11/11 23:37:05 INFO Received complete push request method=POST path=/api/pushes/1/complete1166--- PASS: TestReadRedirectKeepsNarinfoProxied (1.11s)1167=== CONT TestReadProxyNarStreaming11682026/11/11 23:37:05 INFO Received push request method=POST path=/api/pushes11692026/11/11 23:37:05 INFO Received push request method=POST path=/api/pushes11702026/11/11 23:37:05 INFO Received complete push request method=POST path=/api/pushes/1/complete11712026/11/11 23:37:05 INFO Completed push id=1 objects=4 duration=9.543571ms1172--- PASS: TestPush_RepeatedRootCommitsOnce (1.44s)1173=== CONT TestReadProxyContentNegotiation1174--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (1.44s)1175=== CONT TestReadProxyNarinfoAlreadyDecompressed11762026/11/11 23:37:05 INFO Received push request method=POST path=/api/pushes11772026/11/11 23:37:06 INFO lead: released remote=192.0.2.1:1234 generation=21178--- PASS: TestLeadElectsOneAndHandsOver (5.10s)1179=== CONT TestReadProxyNarinfo11802026-11-11 23:37:06.303 UTC [937] ERROR: Push does not exist: id=111812026-11-11 23:37:06.303 UTC [937] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE11822026-11-11 23:37:06.303 UTC [937] STATEMENT: SELECT commit_push($1)11832026/11/11 23:37:06 INFO Completed push id=1 objects=4 duration=1.627673666s11842026/11/11 23:37:06 INFO Received push request method=POST path=/api/pushes1185--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.89s)1186=== CONT TestIsValidCachePath1187=== RUN TestIsValidCachePath/narinfo1188=== PAUSE TestIsValidCachePath/narinfo1189=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1190=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1191=== RUN TestIsValidCachePath/nar_zst1192=== PAUSE TestIsValidCachePath/nar_zst1193=== RUN TestIsValidCachePath/nar_xz1194=== PAUSE TestIsValidCachePath/nar_xz1195=== RUN TestIsValidCachePath/nar_bz21196=== PAUSE TestIsValidCachePath/nar_bz21197=== RUN TestIsValidCachePath/nar_uncompressed1198=== PAUSE TestIsValidCachePath/nar_uncompressed1199=== RUN TestIsValidCachePath/ls1200=== PAUSE TestIsValidCachePath/ls1201=== RUN TestIsValidCachePath/log1202=== PAUSE TestIsValidCachePath/log1203=== RUN TestIsValidCachePath/realisation1204=== PAUSE TestIsValidCachePath/realisation1205=== RUN TestIsValidCachePath/nix-cache-info1206=== PAUSE TestIsValidCachePath/nix-cache-info1207=== RUN TestIsValidCachePath/index.html1208=== PAUSE TestIsValidCachePath/index.html1209=== RUN TestIsValidCachePath/traversal_parent1210=== PAUSE TestIsValidCachePath/traversal_parent1211=== RUN TestIsValidCachePath/traversal_in_middle1212=== PAUSE TestIsValidCachePath/traversal_in_middle1213=== RUN TestIsValidCachePath/invalid_char_e1214=== PAUSE TestIsValidCachePath/invalid_char_e1215=== RUN TestIsValidCachePath/invalid_char_u1216=== PAUSE TestIsValidCachePath/invalid_char_u1217=== RUN TestIsValidCachePath/random_path1218=== PAUSE TestIsValidCachePath/random_path1219=== RUN TestIsValidCachePath/empty1220=== PAUSE TestIsValidCachePath/empty1221=== RUN TestIsValidCachePath/leading_slash1222=== PAUSE TestIsValidCachePath/leading_slash1223=== RUN TestIsValidCachePath/wrong_extension1224=== PAUSE TestIsValidCachePath/wrong_extension1225=== RUN TestIsValidCachePath/short_hash1226=== PAUSE TestIsValidCachePath/short_hash1227=== CONT TestParseSingleRange1228=== RUN TestParseSingleRange/none1229=== PAUSE TestParseSingleRange/none1230=== RUN TestParseSingleRange/unknown_unit1231=== PAUSE TestParseSingleRange/unknown_unit1232=== RUN TestParseSingleRange/multi-range_ignored1233=== PAUSE TestParseSingleRange/multi-range_ignored1234=== RUN TestParseSingleRange/malformed_no_dash1235=== PAUSE TestParseSingleRange/malformed_no_dash1236=== RUN TestParseSingleRange/malformed_both_empty1237=== PAUSE TestParseSingleRange/malformed_both_empty1238=== RUN TestParseSingleRange/malformed_end_before_start1239=== PAUSE TestParseSingleRange/malformed_end_before_start1240=== RUN TestParseSingleRange/closed1241=== PAUSE TestParseSingleRange/closed1242=== RUN TestParseSingleRange/open-ended1243=== PAUSE TestParseSingleRange/open-ended1244=== RUN TestParseSingleRange/end_clamped_to_size1245=== PAUSE TestParseSingleRange/end_clamped_to_size1246=== RUN TestParseSingleRange/suffix1247=== PAUSE TestParseSingleRange/suffix1248=== RUN TestParseSingleRange/suffix_exceeds_size1249=== PAUSE TestParseSingleRange/suffix_exceeds_size1250=== RUN TestParseSingleRange/single_byte1251=== PAUSE TestParseSingleRange/single_byte1252=== RUN TestParseSingleRange/start_past_EOF1253=== PAUSE TestParseSingleRange/start_past_EOF1254=== RUN TestParseSingleRange/start_far_past_EOF1255=== PAUSE TestParseSingleRange/start_far_past_EOF1256=== CONT TestPresentNotReportedWhileGCDeletesClosure1257=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1258=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1259=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1260=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1261=== CONT TestLeadEndsOnShutdown12622026/11/11 23:37:06 INFO Completed push id=1 objects=6 duration=539.116283ms1263--- PASS: TestPush_CompleteCommitsEveryRoot (1.88s)1264=== CONT TestGCBugBareHashReferences12652026-11-11 23:37:06.307 UTC [851] ERROR: could not obtain lock on row in relation "closures"12662026-11-11 23:37:06.307 UTC [851] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12672026-11-11 23:37:06.308 UTC [851] ERROR: could not obtain lock on row in relation "closures"12682026-11-11 23:37:06.308 UTC [851] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12692026-11-11 23:37:06.308 UTC [851] ERROR: could not obtain lock on row in relation "closures"12702026-11-11 23:37:06.308 UTC [851] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12712026-11-11 23:37:06.308 UTC [851] ERROR: could not obtain lock on row in relation "closures"12722026-11-11 23:37:06.308 UTC [851] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12732026-11-11 23:37:06.309 UTC [851] ERROR: could not obtain lock on row in relation "closures"12742026-11-11 23:37:06.309 UTC [851] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1275--- PASS: TestPush_RootsAreLockedInByteOrder (1.95s)1276=== CONT TestGCAdvisoryLockBlocksConcurrentRun1277--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.64s)1278=== CONT TestPendingCleanupUsesOneCutoff12792026/11/11 23:37:06 INFO Aborted multipart uploads count=0 kept=012802026/11/11 23:37:06 WARN Force mode enabled - objects will be deleted immediately without grace period1281--- PASS: TestReadProxy404 (1.16s)1282=== CONT TestPresentReportsOnlyClosureRoots1283--- PASS: TestReadProxyNarStreaming (1.13s)1284=== CONT TestCreatePin_ReservedPins1285--- PASS: TestReadProxyHead (1.31s)1286=== CONT TestOrphanedObjectsGCStressTest12872026/11/11 23:37:07 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46025/oidc1288--- PASS: TestReadProxyInvalidPath (1.48s)1289=== CONT TestOrphanedObjectsGC1290--- PASS: TestReadProxyDisabled (2.76s)1291=== CONT TestObjectStatsUpdatedOncePerCommit1292--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.73s)1293=== CONT TestObjectStatsTrigger1294--- PASS: TestReadProxyContentNegotiation (2.05s)1295=== CONT TestGCTaskStore_ConflictDifferentParams1296--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1297=== CONT TestGCTaskStore_CompletedAllowsNewTask1298--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1299=== CONT TestGCTaskStore_GetReturnsLatest1300--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1301=== CONT TestGCTaskStore_GetEmpty1302--- PASS: TestGCTaskStore_GetEmpty (0.00s)1303=== CONT TestSweepSkipsRowsLockedByPush13042026/11/11 23:37:08 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1305--- PASS: TestReadProxyNarinfo (2.06s)1306=== CONT TestDeduplicatedObjectsRecordedAsPending1307--- PASS: TestObjectStatsUpdatedOncePerCommit (0.71s)1308=== CONT TestGCSweepSkipsPendingObjects1309--- PASS: TestReadProxyRangeRequest (3.79s)1310=== CONT TestService_NativeMTLS13112026/11/11 23:37:08 INFO Aborted multipart uploads count=0 kept=013122026/11/11 23:37:08 WARN Force mode enabled - objects will be deleted immediately without grace period13132026/11/11 23:37:08 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=013142026/11/11 23:37:08 INFO Vacuumed table table=pending_closures13152026/11/11 23:37:08 INFO Vacuumed table table=pending_objects13162026/11/11 23:37:08 INFO Vacuumed table table=multipart_uploads13172026/11/11 23:37:08 INFO Vacuumed table table=closures13182026/11/11 23:37:08 INFO Vacuumed table table=objects13192026/11/11 23:37:08 INFO Aborted multipart uploads count=0 kept=013202026/11/11 23:37:08 WARN Force mode enabled - objects will be deleted immediately without grace period13212026/11/11 23:37:08 INFO Received push request method=POST path=/api/pushes1322--- PASS: TestConnectWaitsForAPeerMigration (7.19s)1323=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded13242026/11/11 23:37:08 INFO Received push request method=POST path=/api/pushes13252026/11/11 23:37:08 INFO Received push request method=POST path=/api/pushes1326--- PASS: TestReadProxyConditionalGet (2.89s)1327=== CONT TestMultipartCleanup13282026/11/11 23:37:08 INFO Received push request method=POST path=/api/pushes13292026/11/11 23:37:08 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13302026/11/11 23:37:08 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)13312026/11/11 23:37:08 INFO Uploading 63v7n8x9bxkvp2rjbpld3f2v2x9wnky8-test-script (136B)13322026/11/11 23:37:08 INFO Uploading 7qprh86ild94bgs26rrral3gwbjhlbdv-test-file-0.txt (160B)13332026/11/11 23:37:08 INFO Uploading rbg2hg7allqckf849v89wigbr87ky0mx-test-file-1.txt (160B)13342026/11/11 23:37:08 INFO Uploading 0md08s326k0lx7rlg7y5jl7aa61f55jc-test-file-2.txt (160B)13352026/11/11 23:37:08 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)13362026/11/11 23:37:08 INFO Uploading 8nj12928z8y64zwgnywfvd4idx9mjz1j-top (224B)13372026/11/11 23:37:08 INFO Uploading f6s6zpnkbwcpvl10mnf0z7d54fn1bgir-shared-dep (136B)13382026/11/11 23:37:08 INFO Received uploads request method=POST path=/api/pending_closures13392026/11/11 23:37:08 WARN Failed to register uploaded object key=log/ybcjbxva5v765kp49s3ddzgh348dvhm4-test-script.drv error="server returned 404: 404 page not found\n"13402026/11/11 23:37:08 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"13412026/11/11 23:37:08 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"13422026/11/11 23:37:08 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13432026/11/11 23:37:08 INFO Uploading i67khvbckq3n91xf9qgawqs35m5nrjfp-test-file.txt (152B)13442026/11/11 23:37:08 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=013452026/11/11 23:37:08 INFO Vacuumed table table=pending_closures13462026/11/11 23:37:08 INFO Vacuumed table table=pending_objects1347--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.54s)1348=== CONT TestServerTLSConfig1349=== RUN TestServerTLSConfig/no_client_CA1350=== PAUSE TestServerTLSConfig/no_client_CA1351=== RUN TestServerTLSConfig/missing_CA_file1352=== PAUSE TestServerTLSConfig/missing_CA_file1353=== RUN TestServerTLSConfig/not_a_PEM_file1354=== PAUSE TestServerTLSConfig/not_a_PEM_file1355=== CONT TestLeadIncumbentAnnouncesAtOnce13562026/11/11 23:37:08 INFO Vacuumed table table=multipart_uploads13572026/11/11 23:37:08 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"13582026/11/11 23:37:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13592026/11/11 23:37:08 WARN Failed to register uploaded object key=8nj12928z8y64zwgnywfvd4idx9mjz1j.ls error="server returned 404: 404 page not found\n"13602026/11/11 23:37:08 WARN Failed to register uploaded object key=63v7n8x9bxkvp2rjbpld3f2v2x9wnky8.ls error="server returned 404: 404 page not found\n"13612026/11/11 23:37:08 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"13622026/11/11 23:37:08 WARN Failed to register uploaded object key=7qprh86ild94bgs26rrral3gwbjhlbdv.ls error="server returned 404: 404 page not found\n"13632026/11/11 23:37:08 INFO Signed narinfos id=1 count=113642026/11/11 23:37:08 INFO Uploading 1 narinfos13652026/11/11 23:37:08 WARN Rate limiter enabled after throttle name=s3-test rate=513662026/11/11 23:37:08 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1367=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1368 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101369 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001370--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.46s)13712026/11/11 23:37:08 INFO Vacuumed table table=closures13722026/11/11 23:37:08 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13732026/11/11 23:37:08 WARN Failed to register uploaded object key=i67khvbckq3n91xf9qgawqs35m5nrjfp.ls error="server returned 404: 404 page not found\n"13742026/11/11 23:37:08 WARN Failed to register uploaded object key=rbg2hg7allqckf849v89wigbr87ky0mx.ls error="server returned 404: 404 page not found\n"13752026/11/11 23:37:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13762026/11/11 23:37:08 WARN Failed to register uploaded object key=0md08s326k0lx7rlg7y5jl7aa61f55jc.ls error="server returned 404: 404 page not found\n"1377=== CONT TestLeadGenerationGrowsWithEveryGrant13782026/11/11 23:37:08 INFO Signed narinfos id=1 count=313792026/11/11 23:37:08 INFO Uploading 3 narinfos13802026/11/11 23:37:08 WARN Failed to register uploaded object key=f6s6zpnkbwcpvl10mnf0z7d54fn1bgir.ls error="server returned 404: 404 page not found\n"13812026/11/11 23:37:08 WARN Failed to register uploaded object key=nar/0vdfkhmqjf3y3y2p0b0v4cw7gwlc4qicibprl78n5sa2hngc7sw0.nar.zst error="server returned 404: 404 page not found\n"13822026/11/11 23:37:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13832026/11/11 23:37:08 INFO Signed narinfos id=1 count=213842026/11/11 23:37:08 INFO Uploading 2 narinfos13852026/11/11 23:37:08 INFO Vacuumed table table=objects13862026/11/11 23:37:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13872026/11/11 23:37:08 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"13882026/11/11 23:37:08 INFO Signed narinfos id=1 count=113892026/11/11 23:37:08 INFO Uploading 1 narinfos13902026/11/11 23:37:08 INFO Received complete push request method=POST path=/api/pushes/2/complete13912026/11/11 23:37:08 WARN Failed to register uploaded object key=0md08s326k0lx7rlg7y5jl7aa61f55jc.narinfo error="server returned 404: 404 page not found\n"13922026/11/11 23:37:08 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=01393--- PASS: TestDeleteClosuresRacingPins (7.93s)1394=== CONT TestClientPushesUseOnePush13952026/11/11 23:37:08 WARN Failed to register uploaded object key=7qprh86ild94bgs26rrral3gwbjhlbdv.narinfo error="server returned 404: 404 page not found\n"13962026/11/11 23:37:08 INFO Received complete push request method=POST path=/api/pushes/1/complete13972026/11/11 23:37:08 WARN Failed to register uploaded object key=63v7n8x9bxkvp2rjbpld3f2v2x9wnky8.narinfo error="server returned 404: 404 page not found\n"13982026/11/11 23:37:08 INFO Vacuumed table table=pending_closures13992026/11/11 23:37:08 INFO Received complete push request method=POST path=/api/pushes/1/complete14002026/11/11 23:37:08 INFO Received complete push request method=POST path=/api/pushes/1/complete14012026/11/11 23:37:08 WARN Failed to register uploaded object key=rbg2hg7allqckf849v89wigbr87ky0mx.narinfo error="server returned 404: 404 page not found\n"14022026/11/11 23:37:08 WARN Failed to register uploaded object key=i67khvbckq3n91xf9qgawqs35m5nrjfp.narinfo error="server returned 404: 404 page not found\n"14032026/11/11 23:37:08 WARN Failed to register uploaded object key=8nj12928z8y64zwgnywfvd4idx9mjz1j.narinfo error="server returned 404: 404 page not found\n"14042026/11/11 23:37:08 INFO Completed push id=2 objects=4 duration=30.893794ms1405--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (4.90s)1406=== CONT TestClientFallsBackToClosures14072026/11/11 23:37:08 INFO Received complete push request method=POST path=/api/pushes/1/complete14082026/11/11 23:37:08 WARN Failed to register uploaded object key=f6s6zpnkbwcpvl10mnf0z7d54fn1bgir.narinfo error="server returned 404: 404 page not found\n"14092026/11/11 23:37:08 INFO Vacuumed table table=pending_objects14102026/11/11 23:37:08 INFO Vacuumed table table=multipart_uploads14112026/11/11 23:37:08 INFO Vacuumed table table=closures14122026/11/11 23:37:08 INFO Completed push id=1 objects=3 duration=51.891455ms14132026/11/11 23:37:08 INFO Completed push id=1 objects=6 duration=42.011601ms14142026/11/11 23:37:08 INFO Completed push id=1 objects=9 duration=52.234918ms14152026/11/11 23:37:08 INFO Upload complete. (4.534s)14162026/11/11 23:37:08 INFO Upload complete. (2.603s)1417=== NAME TestClientMultipleUploads1418 client_integration_test.go:417: Uploaded 3 paths in 4.363334904s14192026/11/11 23:37:08 INFO Upload complete. (4.385s)1420=== NAME TestClientSharedPathCommittedMidPush1421 client_integration_test.go:728: Retrieved narinfo from S3:1422 StorePath: /build/TestClientSharedPathCommittedMidPush3162382709/001/store/f6s6zpnkbwcpvl10mnf0z7d54fn1bgir-shared-dep1423 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1424 Compression: zstd1425 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821426 NarSize: 1361427 References: 1428 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n14292026/11/11 23:37:08 INFO Completed push id=1 objects=4 duration=68.365852ms14302026/11/11 23:37:08 INFO Upload complete. (2.619s)1431 client_integration_test.go:728: Retrieved narinfo from S3:1432 StorePath: /build/TestClientSharedPathCommittedMidPush3162382709/001/store/8nj12928z8y64zwgnywfvd4idx9mjz1j-top1433 URL: nar/0vdfkhmqjf3y3y2p0b0v4cw7gwlc4qicibprl78n5sa2hngc7sw0.nar.zst1434 Compression: zstd1435 NarHash: sha256:0vdfkhmqjf3y3y2p0b0v4cw7gwlc4qicibprl78n5sa2hngc7sw01436 NarSize: 2241437 References: /build/TestClientSharedPathCommittedMidPush3162382709/001/store/f6s6zpnkbwcpvl10mnf0z7d54fn1bgir-shared-dep1438 CA: text:sha256:18zx3crx943pbxpn1jh2nhq7h79bh46c8pnyn53nm72sm93w32f814392026/11/11 23:37:08 INFO Vacuumed table table=objects1440--- PASS: TestSweepSkipsRowsLockedByPush (1.05s)1441=== CONT TestLeadUnannouncedStandbyYieldsToIncumbent1442=== NAME TestClientWithDependencies1443 client_integration_test.go:665: Skipping nix copy test - isolated store (/build/TestClientWithDependencies405523964/001/store) requires matching store prefix1444--- PASS: TestClientSharedPathCommittedMidPush (8.05s)1445=== CONT TestMetricsInventory1446--- PASS: TestClientWithDependencies (7.59s)1447=== CONT TestMetricsCommit1448--- PASS: TestClientMultipleUploads (7.59s)1449=== CONT TestPushDedupSurvivesConcurrentGC14502026/11/11 23:37:09 INFO All 1 paths already cached1451=== NAME TestClientIntegration1452 client_integration_test.go:318: Retrieved narinfo from S3:1453 StorePath: /build/TestClientIntegration3512219487/002/store/i67khvbckq3n91xf9qgawqs35m5nrjfp-test-file.txt1454 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1455 Compression: zstd1456 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11457 NarSize: 1521458 References: 1459 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11460 client_integration_test.go:319: Retrieved .ls file from S3 (compressed size: 77 bytes)1461 client_integration_test.go:319: Decompressed .ls content (64 bytes):1462 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1463--- PASS: TestObjectStatsTrigger (2.43s)1464=== CONT TestPinProtectsFromGC14652026/11/11 23:37:10 INFO Received push request method=POST path=/api/pushes14662026/11/11 23:37:10 INFO Received push request method=POST path=/api/pushes14672026/11/11 23:37:10 INFO Object in database but missing from S3 key=i67khvbckq3n91xf9qgawqs35m5nrjfp.ls14682026/11/11 23:37:10 WARN Found objects in DB but missing from S3, will re-upload count=114692026/11/11 23:37:10 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)14702026/11/11 23:37:10 INFO Received complete push request method=POST path=/api/pushes/2/complete14712026/11/11 23:37:10 WARN Failed to register uploaded object key=i67khvbckq3n91xf9qgawqs35m5nrjfp.ls error="server returned 404: 404 page not found\n"14722026/11/11 23:37:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14732026/11/11 23:37:10 INFO Uploading 5z1ihdhifpbhvqk72p0469ipdyr3600f-ca-test (144B)14742026/11/11 23:37:10 INFO Completed push id=2 objects=3 duration=3.406952ms14752026/11/11 23:37:10 INFO Upload complete. (98ms)1476=== NAME TestClientIntegration1477 client_integration_test.go:336: Retrieved .ls file from S3 (compressed size: 62 bytes)1478 client_integration_test.go:336: Decompressed .ls content (49 bytes):1479 {"version":1,"root":{"type":"regular","size":39}}14802026/11/11 23:37:10 WARN Failed to register uploaded object key=5z1ihdhifpbhvqk72p0469ipdyr3600f.ls error="server returned 404: 404 page not found\n"14812026/11/11 23:37:10 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"14822026/11/11 23:37:10 WARN Failed to register uploaded object key=log/14adb131sx3fn54c4vi236pamz66ip74-ca-test.drv error="server returned 404: 404 page not found\n"14832026/11/11 23:37:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14842026/11/11 23:37:10 INFO Signed narinfos id=1 count=114852026/11/11 23:37:10 INFO Uploading 1 narinfos14862026/11/11 23:37:10 INFO Received complete push request method=POST path=/api/pushes/1/complete14872026/11/11 23:37:10 WARN Failed to register uploaded object key=5z1ihdhifpbhvqk72p0469ipdyr3600f.narinfo error="server returned 404: 404 page not found\n"14882026/11/11 23:37:10 INFO Completed push id=1 objects=4 duration=10.4832ms14892026/11/11 23:37:10 INFO Upload complete. (3.84s)1490=== NAME TestClientCADerivations1491 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations326494917/001/store/5z1ihdhifpbhvqk72p0469ipdyr3600f-ca-test1492 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1493 Compression: zstd1494 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1495 NarSize: 1441496 References: 1497 Deriver: /build/TestClientCADerivations326494917/001/store/14adb131sx3fn54c4vi236pamz66ip74-ca-test.drv1498 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1499 client_ca_test.go:185: Checking for realisation files in S3...15002026/11/11 23:37:10 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=nixbld database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1501--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (3.85s)1502=== CONT TestService_ReadAuthMiddleware1503=== NAME TestClientCADerivations1504 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1505 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache15062026/11/11 23:37:10 INFO Received uploads request method=POST path=/api/pending_closures15072026/11/11 23:37:10 INFO Received uploads request method=POST path=/api/pending_closures15082026/11/11 23:37:10 INFO Received cleanup request method=DELETE path=/api/pending_closures15092026/11/11 23:37:10 INFO lead: acquired remote=192.0.2.1:1234 generation=11510--- PASS: TestPresentReportsOnlyClosureRoots (3.41s)1511=== CONT TestService_ReadScope_PublicByDefault15122026/11/11 23:37:10 INFO lead: acquired remote=192.0.2.1:1234 generation=115132026/11/11 23:37:10 INFO lead: released remote=192.0.2.1:1234 generation=11514--- PASS: TestLeadIncumbentAnnouncesAtOnce (1.69s)1515=== CONT TestService_RequireScope_OIDC15162026/11/11 23:37:10 INFO Received uploads request method=POST path=/api/pending_closures15172026/11/11 23:37:10 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15182026/11/11 23:37:10 WARN Refused reserved pin name=worker-x86_64-linux15192026/11/11 23:37:10 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15202026/11/11 23:37:10 INFO Received create pin request method=POST path=/api/pins/my-app15212026/11/11 23:37:10 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1522--- PASS: TestCreatePin_ReservedPins (3.46s)1523=== CONT TestService_AuthMiddleware_OIDC1524--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (1.88s)1525=== CONT TestGCTaskStore_StartNew1526--- PASS: TestGCTaskStore_StartNew (0.00s)1527=== CONT TestGCTaskStore_DeduplicateSameParams1528--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1529=== CONT TestService_AuthMiddleware_MTLSProxyHeader15302026/11/11 23:37:10 INFO Received push request method=POST path=/api/pushes15312026/11/11 23:37:10 INFO Received complete push request method=POST path=/api/pushes/1/complete15322026/11/11 23:37:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37839/oidc15332026/11/11 23:37:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45655/oidc15342026/11/11 23:37:10 INFO Received uploads request method=POST path=/api/pending_closures15352026/11/11 23:37:10 INFO lead: acquired remote=192.0.2.1:1234 generation=115362026/11/11 23:37:10 INFO lead: acquired remote=192.0.2.1:1234 generation=115372026/11/11 23:37:10 WARN mTLS auth: subject not in bound subjects subject="CN=reader"15382026/11/11 23:37:10 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1539--- PASS: TestService_NativeMTLS (2.22s)1540=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15412026/11/11 23:37:10 INFO Aborted multipart uploads count=0 kept=015422026/11/11 23:37:10 INFO Received uploads request method=POST path=/api/pending_closures15432026/11/11 23:37:10 INFO Aborted multipart uploads count=0 kept=01544--- PASS: TestReadProxyOutlastsServerWriteTimeout (5.31s)1545=== CONT TestService_AuthMiddleware15462026/11/11 23:37:11 INFO lead: released remote=192.0.2.1:1234 generation=11547--- PASS: TestLeadEndsOnShutdown (5.06s)1548=== CONT TestNARDeduplicationMetadataUploadBug15492026/11/11 23:37:11 INFO lead: released remote=192.0.2.1:1234 generation=115502026/11/11 23:37:11 INFO lead: acquired remote=192.0.2.1:1234 generation=215512026/11/11 23:37:11 INFO lead: released remote=192.0.2.1:1234 generation=11552--- PASS: TestGCBugBareHashReferences (5.40s)1553=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark15542026/11/11 23:37:11 INFO lead: acquired remote=192.0.2.1:1234 generation=215552026/11/11 23:37:11 WARN Force mode enabled - objects will be deleted immediately without grace period15562026/11/11 23:37:11 INFO lead: given back to the incumbent remote=192.0.2.1:1234 generation=215572026/11/11 23:37:11 INFO Completed push id=1 objects=4 duration=1.278170293s15582026/11/11 23:37:11 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=015592026/11/11 23:37:11 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=015602026/11/11 23:37:11 INFO Vacuumed table table=pending_closures15612026/11/11 23:37:11 INFO lead: acquired remote=192.0.2.1:1234 generation=315622026/11/11 23:37:11 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15632026/11/11 23:37:11 INFO Vacuumed table table=pending_closures15642026/11/11 23:37:11 INFO Vacuumed table table=pending_objects15652026/11/11 23:37:11 INFO Vacuumed table table=multipart_uploads15662026/11/11 23:37:11 INFO Completed upload id=2 objects=2 duration=6.661243ms15672026/11/11 23:37:11 INFO Vacuumed table table=pending_objects15682026/11/11 23:37:11 INFO Vacuumed table table=multipart_uploads15692026/11/11 23:37:11 INFO Vacuumed table table=closures1570--- PASS: TestMetricsCommit (2.77s)1571=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete15722026/11/11 23:37:11 INFO Vacuumed table table=closures15732026/11/11 23:37:11 INFO Vacuumed table table=objects15742026/11/11 23:37:11 INFO Vacuumed table table=objects1575--- PASS: TestGCSweepSkipsPendingObjects (3.50s)1576=== CONT TestResolveDBConnectionString/flag_wins1577=== CONT TestResolveDBConnectionString/missing_file_is_an_error1578=== CONT TestResolveDBConnectionString/nothing_configured1579=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1580=== CONT TestResolveDBConnectionString/file_when_flag_empty1581=== CONT TestCacheConfigHandler/full_config,_no_issuer1582--- PASS: TestResolveDBConnectionString (0.00s)1583 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1584 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1585 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1586 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1587 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1588=== CONT TestCacheConfigHandler/no_signing_keys1589=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator15902026/11/11 23:37:11 INFO Aborted multipart uploads count=0 kept=01591=== CONT TestCacheConfigHandler/no_cache_url_configured1592--- PASS: TestCacheConfigHandler (0.00s)1593 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1594 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1595 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1596 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1597=== CONT TestClientErrorHandling/InvalidStorePath15982026/11/11 23:37:11 WARN Force mode enabled - objects will be deleted immediately without grace period15992026/11/11 23:37:11 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=016002026/11/11 23:37:11 INFO Vacuumed table table=pending_closures16012026/11/11 23:37:11 INFO Vacuumed table table=pending_objects16022026/11/11 23:37:11 INFO Vacuumed table table=multipart_uploads16032026/11/11 23:37:11 INFO Vacuumed table table=closures16042026/11/11 23:37:11 INFO Vacuumed table table=objects1605--- PASS: TestPushDedupSurvivesConcurrentGC (2.82s)1606=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows16072026/11/11 23:37:11 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1608--- PASS: TestService_AuthMiddleware (0.91s)1609=== CONT TestClientErrorHandling/ServerNotAvailable1610=== NAME TestOrphanedObjectsGC1611 orphaned_objects_gc_test.go:287: GC Test Summary:1612 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1613 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1614 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1615 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1616 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1617--- PASS: TestOrphanedObjectsGC (4.69s)1618=== CONT TestClientErrorHandling/InvalidAuthToken1619=== RUN TestService_RequireScope_OIDC/builder_may_write1620=== PAUSE TestService_RequireScope_OIDC/builder_may_write1621=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1622=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1623=== RUN TestService_RequireScope_OIDC/ops_may_admin1624=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1625=== RUN TestService_RequireScope_OIDC/ops_may_not_write1626=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1627=== RUN TestService_RequireScope_OIDC/reader_may_not_write1628=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1629=== RUN TestService_RequireScope_OIDC/static_token_may_admin1630=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1631=== RUN TestService_RequireScope_OIDC/static_token_may_write1632=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1633=== RUN TestService_RequireScope_OIDC/reader_may_read1634=== PAUSE TestService_RequireScope_OIDC/reader_may_read1635=== RUN TestService_RequireScope_OIDC/writer_implies_read1636=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1637=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1638=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1639=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1640=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1641=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1642=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1643=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1644=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1645=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1646=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1647=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1648--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.57s)1649=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed16502026/11/11 23:37:11 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16512026/11/11 23:37:11 WARN mTLS auth: bound subjects configured but subject DN unavailable16522026/11/11 23:37:11 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1653--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.41s)1654=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed1655--- PASS: TestService_ReadAuthMiddleware (1.85s)1656=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed1657--- PASS: TestService_ReadScope_PublicByDefault (1.77s)1658=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost1659--- PASS: TestMetricsInventory (3.26s)1660=== CONT TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed1661=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1662=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1663=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1664=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1665=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1666=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1667=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1668=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1669=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16702026/11/11 23:37:12 INFO Received uploads request method=POST path=/1671=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16722026/11/11 23:37:12 INFO Received complete multipart upload request method=POST path=/1673=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16742026/11/11 23:37:12 INFO Received request for more parts method=POST path=/1675=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16762026/11/11 23:37:12 INFO Received uploads request method=POST path=/1677--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1678 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1679 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1680 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1681 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1682=== CONT TestIsValidUploadKey/narinfo1683=== CONT TestPendingClosureWriteTimeout/empty1684=== CONT TestIsValidUploadKey/unknown_type1685=== CONT TestIsValidUploadKey/empty_key1686=== CONT TestIsValidUploadKey/absolute1687=== CONT TestIsValidUploadKey/traversal_nar1688=== CONT TestIsValidUploadKey/traversal1689=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1690=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1691=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1692=== CONT TestIsValidUploadKey/index.html1693=== CONT TestIsValidUploadKey/nix-cache-info1694=== CONT TestIsValidUploadKey/realisation_plus_in_output1695=== CONT TestIsValidUploadKey/realisation1696=== CONT TestIsValidUploadKey/build_log_equals1697=== CONT TestIsValidUploadKey/build_log_question_mark1698=== CONT TestIsValidUploadKey/build_log_plus_in_name1699=== CONT TestIsValidUploadKey/build_log_home-manager_file1700=== CONT TestIsValidUploadKey/build_log1701=== CONT TestIsValidUploadKey/listing1702=== CONT TestIsValidUploadKey/nar_plain1703=== CONT TestIsValidUploadKey/nar_xz1704=== CONT TestIsValidUploadKey/nar_zst1705--- PASS: TestIsValidUploadKey (0.00s)1706 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1707 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1708 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1709 --- PASS: TestIsValidUploadKey/absolute (0.00s)1710 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1711 --- PASS: TestIsValidUploadKey/traversal (0.00s)1712 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1713 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1714 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1715 --- PASS: TestIsValidUploadKey/index.html (0.00s)1716 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1717 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1718 --- PASS: TestIsValidUploadKey/realisation (0.00s)1719 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1720 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1721 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1722 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1723 --- PASS: TestIsValidUploadKey/build_log (0.00s)1724 --- PASS: TestIsValidUploadKey/listing (0.00s)1725 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1726 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1727 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1728=== CONT TestProxyWriteTimeout/narinfo1729=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline17302026/11/11 23:37:12 INFO Received uploads request method=POST path=/api/pending_closures17312026/11/11 23:37:12 INFO Received cleanup request method=DELETE path=/api/pending_closures17322026/11/11 23:37:12 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket94/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""17332026/11/11 23:37:12 INFO Aborted multipart uploads count=0 kept=117342026/11/11 23:37:12 INFO Received cleanup request method=DELETE path=/api/pending_closures17352026/11/11 23:37:12 INFO Aborted multipart uploads count=1 kept=01736--- PASS: TestMultipartCleanup (3.98s)1737=== CONT TestPendingClosureWriteTimeout/670k_objects1738=== CONT TestPendingClosureWriteTimeout/400_objects1739=== CONT TestProxyWriteTimeout/10_GiB_nar1740=== CONT TestProxyWriteTimeout/unknown_size1741=== CONT TestProxyWriteTimeout/1_GiB_nar1742--- PASS: TestProxyWriteTimeout (0.00s)1743 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1744 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1745 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1746 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1747=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17482026/11/11 23:37:12 INFO Received uploads request method=POST path=/1749=== NAME TestOrphanedObjectsGCStressTest1750 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains17512026/11/11 23:37:12 INFO lead: released remote=192.0.2.1:1234 generation=217522026/11/11 23:37:13 INFO lead: acquired remote=192.0.2.1:1234 generation=317532026/11/11 23:37:13 INFO lead: released remote=192.0.2.1:1234 generation=31754--- PASS: TestLeadGenerationGrowsWithEveryGrant (4.39s)1755=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17562026/11/11 23:37:13 INFO Received request for more parts method=POST path=/1757=== NAME TestOrphanedObjectsGCStressTest1758 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion1759=== NAME TestNARDeduplicationMetadataUploadBug1760 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3047426480/001/store/jzgl5lrwqyrmy35673lzkgjc45gnx9vd-file1.txt1761=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17622026/11/11 23:37:13 INFO Received complete multipart upload request method=POST path=/1763=== CONT TestPush_RejectsBadRequests/no_objects17642026/11/11 23:37:13 INFO Received push request method=POST path=/api/pushes1765=== CONT TestPush_RejectsBadRequests/bad_root17662026/11/11 23:37:13 INFO Received push request method=POST path=/api/pushes1767=== CONT TestPush_RejectsBadRequests/no_roots17682026/11/11 23:37:13 INFO Received push request method=POST path=/api/pushes1769=== CONT TestPush_RejectsBadRequests/root_not_in_objects17702026/11/11 23:37:13 INFO Received push request method=POST path=/api/pushes1771=== CONT TestIsValidCachePath/narinfo1772=== CONT TestIsValidCachePath/index.html1773=== CONT TestIsValidCachePath/short_hash1774=== CONT TestIsValidCachePath/wrong_extension1775=== CONT TestIsValidCachePath/leading_slash1776=== CONT TestIsValidCachePath/empty1777=== CONT TestIsValidCachePath/random_path1778=== CONT TestIsValidCachePath/invalid_char_u1779=== CONT TestIsValidCachePath/invalid_char_e1780=== CONT TestIsValidCachePath/traversal_in_middle1781=== CONT TestIsValidCachePath/traversal_parent1782=== CONT TestIsValidCachePath/nar_uncompressed1783=== CONT TestIsValidCachePath/nix-cache-info1784--- PASS: TestPush_RejectsBadRequests (0.78s)1785 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1786 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1787 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1788 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1789=== CONT TestIsValidCachePath/realisation1790=== CONT TestIsValidCachePath/log1791=== CONT TestIsValidCachePath/ls1792=== CONT TestIsValidCachePath/nar_xz1793=== CONT TestIsValidCachePath/nar_bz21794=== CONT TestIsValidCachePath/nar_zst1795=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1796=== CONT TestParseSingleRange/none1797=== CONT TestParseSingleRange/open-ended1798=== CONT TestParseSingleRange/start_far_past_EOF1799=== CONT TestParseSingleRange/start_past_EOF1800--- PASS: TestIsValidCachePath (0.00s)1801 --- PASS: TestIsValidCachePath/narinfo (0.00s)1802 --- PASS: TestIsValidCachePath/index.html (0.00s)1803 --- PASS: TestIsValidCachePath/short_hash (0.00s)1804 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1805 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1806 --- PASS: TestIsValidCachePath/empty (0.00s)1807 --- PASS: TestIsValidCachePath/random_path (0.00s)1808 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1809 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1810 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1811 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1812 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1813 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1814 --- PASS: TestIsValidCachePath/realisation (0.00s)1815 --- PASS: TestIsValidCachePath/log (0.00s)1816 --- PASS: TestIsValidCachePath/ls (0.00s)1817 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1818 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1819 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1820 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1821=== CONT TestParseSingleRange/single_byte1822=== CONT TestParseSingleRange/suffix_exceeds_size1823=== CONT TestParseSingleRange/suffix1824=== CONT TestParseSingleRange/end_clamped_to_size1825=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1826=== NAME TestPinProtectsFromGC1827 client_integration_test.go:779: Pinned store path: /build/TestPinProtectsFromGC2725197344/001/store/8qa0f2cdnghwdz9miprm1pdzbkm9kfll-pinned-file.txt1828 client_integration_test.go:780: Unpinned store path: /build/TestPinProtectsFromGC2725197344/001/store/klg9lybp8q2yvayphv1kxdhvggx7z3yq-unpinned-file.txt18292026/11/11 23:37:13 INFO Received uploads request method=POST path=/api/pending_closures18302026/11/11 23:37:13 INFO Aborted multipart uploads count=0 kept=018312026/11/11 23:37:13 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18322026/11/11 23:37:13 INFO Received uploads request method=POST path=/api/pending_closures18332026/11/11 23:37:13 INFO Received push request method=POST path=/api/pushes18342026/11/11 23:37:13 WARN Force mode enabled - objects will be deleted immediately without grace period18352026/11/11 23:37:13 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)18362026/11/11 23:37: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=018372026/11/11 23:37:13 INFO Vacuumed table table=pending_closures18382026/11/11 23:37:13 INFO Received complete push request method=POST path=/api/pushes/3/complete18392026/11/11 23:37:13 INFO Vacuumed table table=pending_objects18402026/11/11 23:37:13 INFO Vacuumed table table=multipart_uploads18412026/11/11 23:37:13 WARN Failed to register uploaded object key=i67khvbckq3n91xf9qgawqs35m5nrjfp.ls error="server returned 404: 404 page not found\n"18422026/11/11 23:37:13 INFO Vacuumed table table=closures18432026/11/11 23:37:13 INFO Vacuumed table table=objects18442026/11/11 23:37:13 INFO Completed push id=3 objects=3 duration=3.344931ms18452026/11/11 23:37:13 INFO Upload complete. (222ms)1846=== NAME TestClientIntegration1847 client_integration_test.go:353: Retrieved .ls file from S3 (compressed size: 62 bytes)1848 client_integration_test.go:353: Decompressed .ls content (49 bytes):1849 {"version":1,"root":{"type":"regular","size":39}}1850 client_integration_test.go:364: Testing garbage collection...18512026/11/11 23:37:13 INFO Received uploads request method=POST path=/api/pending_closures1852=== CONT TestParseSingleRange/closed1853=== CONT TestParseSingleRange/malformed_end_before_start1854=== CONT TestParseSingleRange/malformed_both_empty1855=== CONT TestParseSingleRange/malformed_no_dash1856=== CONT TestParseSingleRange/multi-range_ignored1857=== CONT TestParseSingleRange/unknown_unit1858--- PASS: TestParseSingleRange (0.00s)1859 --- PASS: TestParseSingleRange/none (0.00s)1860 --- PASS: TestParseSingleRange/open-ended (0.00s)1861 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1862 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1863 --- PASS: TestParseSingleRange/single_byte (0.00s)1864 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1865 --- PASS: TestParseSingleRange/suffix (0.00s)1866 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1867 --- PASS: TestParseSingleRange/closed (0.00s)1868 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1869 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1870 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1871 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1872 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1873=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh18742026/11/11 23:37:13 INFO Received uploads request method=POST path=/api/pending_closures18752026/11/11 23:37:13 INFO Received uploads request method=POST path=/api/pending_closures18762026/11/11 23:37:13 WARN Request failed, retrying attempt=2 backoff=197.890963ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18772026/11/11 23:37:13 INFO Received uploads request method=POST path=/api/pending_closures18782026/11/11 23:37:13 INFO Aborted multipart uploads count=0 kept=018792026/11/11 23:37:13 INFO Aborted multipart uploads count=0 kept=018802026/11/11 23:37:13 INFO Received uploads request method=POST path=/api/pending_closures18812026/11/11 23:37:13 INFO Received uploads request method=POST path=/api/pending_closures18822026/11/11 23:37:13 WARN Request failed, retrying attempt=3 backoff=362.937708ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18832026/11/11 23:37:13 INFO Aborted multipart uploads count=0 kept=01884--- PASS: TestUploadHandlersRejectOversizedBody (0.21s)1885 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)1886 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.04s)1887 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.24s)1888=== CONT TestServerTLSConfig/no_client_CA1889=== CONT TestServerTLSConfig/not_a_PEM_file1890=== CONT TestServerTLSConfig/missing_CA_file1891=== CONT TestService_RequireScope_OIDC/builder_may_write1892--- PASS: TestServerTLSConfig (0.00s)1893 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1894 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1895 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1896=== CONT TestService_RequireScope_OIDC/reader_may_read1897=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1898=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18992026/11/11 23:37:13 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]1900=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1901=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1902=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1903=== CONT TestService_RequireScope_OIDC/writer_implies_read1904=== CONT TestService_RequireScope_OIDC/reader_may_not_write1905=== CONT TestService_RequireScope_OIDC/static_token_may_write1906=== CONT TestService_RequireScope_OIDC/static_token_may_admin1907=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1908=== CONT TestService_RequireScope_OIDC/ops_may_not_write1909=== CONT TestService_RequireScope_OIDC/ops_may_admin1910=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1911--- PASS: TestService_RequireScope_OIDC (1.61s)1912 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1913 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1914 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1915 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1916 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1917 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1918 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1919 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1920 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1921 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1922 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1923 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1924 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1925 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1926=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19272026/11/11 23:37:13 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]1928=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1929=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19302026/11/11 23:37:13 WARN Authentication failed token_preview=eyJhbGciOi...lDbZdq_4Hw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1931--- PASS: TestService_AuthMiddleware_OIDC (1.93s)1932 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)1933 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1934 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1935 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)19362026/11/11 23:37:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19372026/11/11 23:37:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19382026/11/11 23:37:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19392026/11/11 23:37:13 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst upload_id=YjAzZDg0NTUtOTUwNS00MWJkLWI4MjAtZDE0MGZiOWQ1NThlLmFjMmM0OGFmLWUzMzMtNGU5OS1hZGQ4LTY2YzQ2Y2M2MmM2N3gxNzk0NDQwMjMzNDI1NDg0MDc4 parts=1019402026/11/11 23:37:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19412026/11/11 23:37:13 WARN Force mode enabled - objects will be deleted immediately without grace period19422026/11/11 23:37:13 WARN Force mode enabled - objects will be deleted immediately without grace period19432026/11/11 23:37:13 INFO Completed upload id=1 objects=3 duration=10.640922ms19442026/11/11 23:37:13 INFO Received uploads request method=POST path=/api/pending_closures19452026/11/11 23:37:13 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst upload_id=YjAzZDg0NTUtOTUwNS00MWJkLWI4MjAtZDE0MGZiOWQ1NThlLmY3NGY2NGY4LTRlYmEtNGM1My05ZmVlLTY1YzZiMDVmZjQyN3gxNzk0NDQwMjMzNDgwNjYzNzA1 parts=1019462026/11/11 23:37:13 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000200000000000000000000.nar.zst upload_id=YjAzZDg0NTUtOTUwNS00MWJkLWI4MjAtZDE0MGZiOWQ1NThlLjAzNzQ0OThlLThkZmQtNDE1OS1hOThmLTc0OTUxY2MxODdmOXgxNzk0NDQwMjMzNDYwMzE3NTMx parts=1019472026/11/11 23:37:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19482026/11/11 23:37:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19492026/11/11 23:37:13 INFO Completed upload id=1 objects=3 duration=4.756765ms19502026/11/11 23:37:13 INFO Completed upload id=1 objects=3 duration=5.663414ms19512026/11/11 23:37:13 INFO Received uploads request method=POST path=/api/pending_closures19522026/11/11 23:37:13 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=019532026/11/11 23:37:13 INFO Vacuumed table table=pending_closures19542026/11/11 23:37:13 INFO Vacuumed table table=pending_objects19552026/11/11 23:37:13 INFO Vacuumed table table=multipart_uploads19562026/11/11 23:37:13 INFO Vacuumed table table=closures19572026/11/11 23:37:13 INFO Vacuumed table table=objects19582026/11/11 23:37:13 INFO Received uploads request method=POST path=/api/pending_closures19592026/11/11 23:37:13 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst19602026/11/11 23:37:13 WARN Found objects in DB but missing from S3, will re-upload count=11961--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1962 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (1.49s)1963 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (2.13s)19642026/11/11 23:37:13 INFO lead: released remote=192.0.2.1:1234 generation=31965--- PASS: TestLeadUnannouncedStandbyYieldsToIncumbent (5.01s)19662026/11/11 23:37:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19672026/11/11 23:37:14 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst upload_id=YjAzZDg0NTUtOTUwNS00MWJkLWI4MjAtZDE0MGZiOWQ1NThlLjFjYjVlM2I3LTIwZDUtNGMxZC1hYTgxLWEyNDMzNzFkZGU1ZHgxNzk0NDQwMjMzNjI2NDk5MDk2 parts=1019682026/11/11 23:37:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19692026/11/11 23:37:14 INFO Completed upload id=1 objects=3 duration=24.360812ms19702026/11/11 23:37:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19712026/11/11 23:37:14 WARN Request failed, retrying attempt=4 backoff=775.881608ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19722026/11/11 23:37:14 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst upload_id=YjAzZDg0NTUtOTUwNS00MWJkLWI4MjAtZDE0MGZiOWQ1NThlLmI0OWYzOThiLTEwODItNDFlNy1hZGU0LTAzYzMwNjdhYzg0NngxNzk0NDQwMjMzNjUyNDU3NTQz parts=1019732026/11/11 23:37:14 INFO Received uploads request method=POST path=/api/pending_closures19742026/11/11 23:37:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19752026/11/11 23:37:14 INFO Completed upload id=1 objects=3 duration=3.602934ms19762026/11/11 23:37:14 INFO Received uploads request method=POST path=/api/pending_closures19772026/11/11 23:37:14 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst19782026/11/11 23:37:14 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0001.narinfo1979--- PASS: TestPendingClosureWriteTimeout (0.00s)1980 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1981 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1982 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1983 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.90s)19842026/11/11 23:37:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19852026/11/11 23:37:14 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100300000000000000000000.nar.zst upload_id=YjAzZDg0NTUtOTUwNS00MWJkLWI4MjAtZDE0MGZiOWQ1NThlLjExYjIzOGI4LTVhNzEtNGM1ZS1hOTIyLTQ5ODUyMjNhOWUzNHgxNzk0NDQwMjMzODkyMjMzODEx parts=1019862026/11/11 23:37:14 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete19872026/11/11 23:37:14 INFO Completed upload id=2 objects=3 duration=929.909µs1988=== NAME TestOrphanedObjectsGCStressTest1989 orphaned_objects_gc_test.go:503: Stress test completed successfully:1990 orphaned_objects_gc_test.go:504: - Active objects preserved: 201991 orphaned_objects_gc_test.go:505: - Objects deleted: 2101992 orphaned_objects_gc_test.go:506: - Total GC'd: 2101993--- PASS: TestOrphanedObjectsGCStressTest (7.33s)19942026/11/11 23:37:14 INFO Received uploads request method=POST path=/api/pending_closures19952026/11/11 23:37:14 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst19962026/11/11 23:37:14 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0003.narinfo1997--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)1998 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.95s)1999 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (1.04s)20002026/11/11 23:37:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20012026/11/11 23:37:14 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100400000000000000000000.nar.zst upload_id=YjAzZDg0NTUtOTUwNS00MWJkLWI4MjAtZDE0MGZiOWQ1NThlLjdiNGI3NzA3LWY0OWYtNGFjNy05YzJjLTAxNDk2Mjc2MzU0ZXgxNzk0NDQwMjM0MDkxOTc5NzE2 parts=1020022026/11/11 23:37:14 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete20032026/11/11 23:37:14 INFO Completed upload id=2 objects=3 duration=1.05675ms20042026/11/11 23:37:14 INFO Received uploads request method=POST path=/api/pending_closures20052026/11/11 23:37:14 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst20062026/11/11 23:37:14 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0004.narinfo2007--- PASS: TestService_verifyS3ReuploadsStaleNarinfo (0.00s)2008 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed (1.68s)2009 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed (1.92s)2010 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed (2.14s)2011 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost (2.30s)2012 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed (2.54s)20132026/11/11 23:37:14 WARN Request failed, retrying attempt=5 backoff=1.562335474s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20142026/11/11 23:37:14 WARN Force mode enabled - objects will be deleted immediately without grace period20152026/11/11 23:37:14 INFO Received push request method=POST path=/api/pushes20162026/11/11 23:37:14 INFO Starting cleanup of old closures method=DELETE path=/api/closures20172026/11/11 23:37:14 INFO Garbage collection started20182026/11/11 23:37:14 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20192026/11/11 23:37:14 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:43729/bucket106/?delete=\": context canceled"20202026/11/11 23:37:14 INFO Uploading jzgl5lrwqyrmy35673lzkgjc45gnx9vd-file1.txt (160B)2021--- PASS: TestGCEndsOnShutdown (0.00s)2022 --- PASS: TestGCEndsOnShutdown/before_the_run (1.95s)2023 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (2.19s)2024 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (3.15s)20252026/11/11 23:37:14 WARN Failed to register uploaded object key=jzgl5lrwqyrmy35673lzkgjc45gnx9vd.ls error="server returned 404: 404 page not found\n"20262026/11/11 23:37:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20272026/11/11 23:37:14 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"20282026/11/11 23:37:14 INFO Signed narinfos id=1 count=120292026/11/11 23:37:14 INFO Uploading 1 narinfos20302026/11/11 23:37:14 INFO Aborted multipart uploads count=0 kept=020312026/11/11 23:37:14 INFO Received complete push request method=POST path=/api/pushes/1/complete20322026/11/11 23:37:14 WARN Failed to register uploaded object key=jzgl5lrwqyrmy35673lzkgjc45gnx9vd.narinfo error="server returned 404: 404 page not found\n"20332026/11/11 23:37:14 INFO Completed push id=1 objects=3 duration=6.790565ms20342026/11/11 23:37:14 INFO Upload complete. (1.541s)2035=== NAME TestNARDeduplicationMetadataUploadBug2036 metadata_upload_test.go:54: Retrieved narinfo from S3:2037 StorePath: /build/TestNARDeduplicationMetadataUploadBug3047426480/001/store/jzgl5lrwqyrmy35673lzkgjc45gnx9vd-file1.txt2038 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2039 Compression: zstd2040 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2041 NarSize: 1602042 References: 2043 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2044 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2045 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2046 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}20472026/11/11 23:37:16 INFO Aborted multipart uploads count=1 kept=020482026/11/11 23:37:16 INFO Received cleanup request method=DELETE path=/api/pending_closures20492026/11/11 23:37:16 INFO Aborted multipart uploads count=1 kept=02050--- PASS: TestPendingCleanupUsesOneCutoff (9.91s)2051=== NAME TestNARDeduplicationMetadataUploadBug2052 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3047426480/001/store/1hbhqjy9017agk6yi8yn1lkqwyisfq89-file2.txt20532026/11/11 23:37:16 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20542026/11/11 23:37:16 INFO Received push request method=POST path=/api/pushes20552026/11/11 23:37:16 INFO Received uploads request method=POST path=/api/pending_closures20562026/11/11 23:37:16 WARN Force mode enabled - objects will be deleted immediately without grace period20572026/11/11 23:37:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20582026/11/11 23:37:16 INFO Uploading 8qa0f2cdnghwdz9miprm1pdzbkm9kfll-pinned-file.txt (128B)20592026/11/11 23:37:16 INFO Received push request method=POST path=/api/pushes20602026/11/11 23:37:16 INFO Received uploads request method=POST path=/api/pending_closures20612026/11/11 23:37:16 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)20622026/11/11 23:37:16 INFO Uploading vll67wwim2yszg3zsnnx9yd3hn0dsyrr-shared-dep (136B)20632026/11/11 23:37:16 INFO Uploading sxl85lp026v99z2ax03s91k25fk324rg-b (216B)20642026/11/11 23:37:16 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)20652026/11/11 23:37:16 INFO Uploading mfyayfcqiaqb97xarxdipmk1acw036wi-shared-dep (136B)20662026/11/11 23:37:16 INFO Uploading lza8rgpc22bb9i19pnsgzgbbc57awn1d-b (216B)20672026/11/11 23:37:16 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"20682026/11/11 23:37:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20692026/11/11 23:37:16 WARN Failed to register uploaded object key=8qa0f2cdnghwdz9miprm1pdzbkm9kfll.ls error="server returned 404: 404 page not found\n"20702026/11/11 23:37:16 INFO Signed narinfos id=1 count=120712026/11/11 23:37:16 INFO Uploading 1 narinfos20722026/11/11 23:37:16 WARN Failed to register uploaded object key=sxl85lp026v99z2ax03s91k25fk324rg.ls error="server returned 404: 404 page not found\n"20732026/11/11 23:37:16 WARN Failed to register uploaded object key=nar/1jlxambc34rj5nsy7df80j7g7k1cfvmfv3in6fca24f464d7hlpx.nar.zst error="server returned 404: 404 page not found\n"20742026/11/11 23:37:16 WARN Failed to register uploaded object key=vll67wwim2yszg3zsnnx9yd3hn0dsyrr.ls error="server returned 404: 404 page not found\n"20752026/11/11 23:37:16 WARN Failed to register uploaded object key=5bifnrw7dsji11lxg7cfszcw33287hmk.ls error="server returned 404: 404 page not found\n"20762026/11/11 23:37:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20772026/11/11 23:37:16 WARN Failed to register uploaded object key=lza8rgpc22bb9i19pnsgzgbbc57awn1d.ls error="server returned 404: 404 page not found\n"20782026/11/11 23:37:16 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"20792026/11/11 23:37:16 WARN Failed to register uploaded object key=lw4gfzr590jqywzwnzjn35giz2h9jwpn.ls error="server returned 404: 404 page not found\n"20802026/11/11 23:37:16 INFO Received complete push request method=POST path=/api/pushes/1/complete20812026/11/11 23:37:16 WARN Failed to register uploaded object key=mfyayfcqiaqb97xarxdipmk1acw036wi.ls error="server returned 404: 404 page not found\n"20822026/11/11 23:37:16 WARN Failed to register uploaded object key=8qa0f2cdnghwdz9miprm1pdzbkm9kfll.narinfo error="server returned 404: 404 page not found\n"20832026/11/11 23:37:16 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"20842026/11/11 23:37:16 INFO Signed narinfos id=1 count=220852026/11/11 23:37:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign20862026/11/11 23:37:16 INFO Signed narinfos id=2 count=220872026/11/11 23:37:16 INFO Uploading 4 narinfos20882026/11/11 23:37:16 WARN Failed to register uploaded object key=nar/1xl0g1nb7vhsswhg9mmla6ix5hs0r683k7b1x600msda1v59mzd7.nar.zst error="server returned 404: 404 page not found\n"20892026/11/11 23:37:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20902026/11/11 23:37:16 INFO Signed narinfos id=1 count=320912026/11/11 23:37:16 INFO Uploading 3 narinfos20922026/11/11 23:37:16 WARN Failed to register uploaded object key=vll67wwim2yszg3zsnnx9yd3hn0dsyrr.narinfo error="server returned 404: 404 page not found\n"20932026/11/11 23:37:16 WARN Failed to register uploaded object key=sxl85lp026v99z2ax03s91k25fk324rg.narinfo error="server returned 404: 404 page not found\n"20942026/11/11 23:37:16 WARN Failed to register uploaded object key=lza8rgpc22bb9i19pnsgzgbbc57awn1d.narinfo error="server returned 404: 404 page not found\n"20952026/11/11 23:37:16 WARN Failed to register uploaded object key=5bifnrw7dsji11lxg7cfszcw33287hmk.narinfo error="server returned 404: 404 page not found\n"20962026/11/11 23:37:16 WARN Failed to register uploaded object key=mfyayfcqiaqb97xarxdipmk1acw036wi.narinfo error="server returned 404: 404 page not found\n"20972026/11/11 23:37:16 INFO Received complete push request method=POST path=/api/pushes/1/complete20982026/11/11 23:37:16 WARN Failed to register uploaded object key=lw4gfzr590jqywzwnzjn35giz2h9jwpn.narinfo error="server returned 404: 404 page not found\n"20992026/11/11 23:37:16 INFO Completed push id=1 objects=3 duration=12.56572ms21002026/11/11 23:37:16 INFO Upload complete. (1.911s)21012026/11/11 23:37:16 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21022026/11/11 23:37:16 WARN Failed to register uploaded object key=vll67wwim2yszg3zsnnx9yd3hn0dsyrr.narinfo error="server returned 404: 404 page not found\n"21032026/11/11 23:37:16 INFO Completed push id=1 objects=8 duration=8.616942ms21042026/11/11 23:37:16 INFO Upload complete. (2.948s)21052026/11/11 23:37: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=02106=== NAME TestClientPushesUseOnePush2107 client_pushes_test.go:97: Retrieved narinfo from S3:2108 StorePath: /build/TestClientPushesUseOnePush1007185541/001/store/mfyayfcqiaqb97xarxdipmk1acw036wi-shared-dep2109 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2110 Compression: zstd2111 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822112 NarSize: 1362113 References: 2114 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n21152026/11/11 23:37:16 INFO Completed upload id=2 objects=6 duration=9.43199ms21162026/11/11 23:37:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete2117 client_pushes_test.go:97: Retrieved narinfo from S3:2118 StorePath: /build/TestClientPushesUseOnePush1007185541/001/store/lw4gfzr590jqywzwnzjn35giz2h9jwpn-a2119 URL: nar/1xl0g1nb7vhsswhg9mmla6ix5hs0r683k7b1x600msda1v59mzd7.nar.zst2120 Compression: zstd2121 NarHash: sha256:1xl0g1nb7vhsswhg9mmla6ix5hs0r683k7b1x600msda1v59mzd72122 NarSize: 2162123 References: /build/TestClientPushesUseOnePush1007185541/001/store/mfyayfcqiaqb97xarxdipmk1acw036wi-shared-dep2124 CA: text:sha256:1swq96alxw9687a8hgjpvm37cs2nf2sgq1x99cypyg14i9xp7vd221252026/11/11 23:37:16 INFO Completed upload id=1 objects=6 duration=1.743757ms21262026/11/11 23:37:16 INFO Upload complete. (2.949s)2127=== NAME TestClientFallsBackToClosures2128 client_pushes_test.go:112: Retrieved narinfo from S3:2129 StorePath: /build/TestClientFallsBackToClosures1023861771/001/store/vll67wwim2yszg3zsnnx9yd3hn0dsyrr-shared-dep2130 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2131 Compression: zstd2132 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822133 NarSize: 1362134 References: 2135 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2136=== NAME TestClientPushesUseOnePush2137 client_pushes_test.go:97: Retrieved narinfo from S3:2138 StorePath: /build/TestClientPushesUseOnePush1007185541/001/store/lza8rgpc22bb9i19pnsgzgbbc57awn1d-b2139 URL: nar/1xl0g1nb7vhsswhg9mmla6ix5hs0r683k7b1x600msda1v59mzd7.nar.zst2140 Compression: zstd2141 NarHash: sha256:1xl0g1nb7vhsswhg9mmla6ix5hs0r683k7b1x600msda1v59mzd72142 NarSize: 2162143 References: /build/TestClientPushesUseOnePush1007185541/001/store/mfyayfcqiaqb97xarxdipmk1acw036wi-shared-dep2144 CA: text:sha256:1swq96alxw9687a8hgjpvm37cs2nf2sgq1x99cypyg14i9xp7vd221452026/11/11 23:37:16 INFO Vacuumed table table=pending_closures2146=== NAME TestClientFallsBackToClosures2147 client_pushes_test.go:112: Retrieved narinfo from S3:2148 StorePath: /build/TestClientFallsBackToClosures1023861771/001/store/5bifnrw7dsji11lxg7cfszcw33287hmk-a2149 URL: nar/1jlxambc34rj5nsy7df80j7g7k1cfvmfv3in6fca24f464d7hlpx.nar.zst2150 Compression: zstd2151 NarHash: sha256:1jlxambc34rj5nsy7df80j7g7k1cfvmfv3in6fca24f464d7hlpx2152 NarSize: 2162153 References: /build/TestClientFallsBackToClosures1023861771/001/store/vll67wwim2yszg3zsnnx9yd3hn0dsyrr-shared-dep2154 CA: text:sha256:1vjv6gnlhbgkaghdki2i0zsa2k0l8casinrra7qldskcbzcvh9p021552026/11/11 23:37:16 INFO Vacuumed table table=pending_objects2156 client_pushes_test.go:112: Retrieved narinfo from S3:2157 StorePath: /build/TestClientFallsBackToClosures1023861771/001/store/sxl85lp026v99z2ax03s91k25fk324rg-b2158 URL: nar/1jlxambc34rj5nsy7df80j7g7k1cfvmfv3in6fca24f464d7hlpx.nar.zst2159 Compression: zstd2160 NarHash: sha256:1jlxambc34rj5nsy7df80j7g7k1cfvmfv3in6fca24f464d7hlpx2161 NarSize: 2162162 References: /build/TestClientFallsBackToClosures1023861771/001/store/vll67wwim2yszg3zsnnx9yd3hn0dsyrr-shared-dep2163 CA: text:sha256:1vjv6gnlhbgkaghdki2i0zsa2k0l8casinrra7qldskcbzcvh9p02164--- PASS: TestClientPushesUseOnePush (7.99s)21652026/11/11 23:37:16 INFO Vacuumed table table=multipart_uploads2166--- PASS: TestClientFallsBackToClosures (7.98s)21672026/11/11 23:37:16 INFO Vacuumed table table=closures21682026/11/11 23:37:16 INFO Vacuumed table table=objects21692026/11/11 23:37:16 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02170=== NAME TestClientIntegration2171 client_integration_test.go:371: Objects in database after GC:2172 client_integration_test.go:371: Successfully deleted all objects with GC --force2173--- PASS: TestClientIntegration (15.55s)21742026/11/11 23:37:17 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21752026/11/11 23:37:17 WARN Request failed, retrying attempt=2 backoff=214.976744ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21762026/11/11 23:37:17 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21772026/11/11 23:37:17 WARN Request failed, retrying attempt=3 backoff=381.660268ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21782026/11/11 23:37:18 INFO Received push request method=POST path=/api/pushes21792026/11/11 23:37:18 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)21802026/11/11 23:37:18 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign21812026/11/11 23:37:18 WARN Failed to register uploaded object key=1hbhqjy9017agk6yi8yn1lkqwyisfq89.ls error="server returned 404: 404 page not found\n"21822026/11/11 23:37:18 INFO Signed narinfos id=2 count=121832026/11/11 23:37:18 INFO Uploading 1 narinfos21842026/11/11 23:37:18 INFO Received complete push request method=POST path=/api/pushes/2/complete21852026/11/11 23:37:18 WARN Failed to register uploaded object key=1hbhqjy9017agk6yi8yn1lkqwyisfq89.narinfo error="server returned 404: 404 page not found\n"21862026/11/11 23:37:18 INFO Completed push id=2 objects=3 duration=2.729006ms21872026/11/11 23:37:18 INFO Upload complete. (331ms)2188=== NAME TestNARDeduplicationMetadataUploadBug2189 metadata_upload_test.go:76: Retrieved narinfo from S3:2190 StorePath: /build/TestNARDeduplicationMetadataUploadBug3047426480/001/store/1hbhqjy9017agk6yi8yn1lkqwyisfq89-file2.txt2191 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2192 Compression: zstd2193 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2194 NarSize: 1602195 References: 2196 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2197 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2198 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2199 {"version":1,"root":{"type":"regular","size":44}}2200--- PASS: TestNARDeduplicationMetadataUploadBug (6.68s)22012026/11/11 23:37:18 WARN Request failed, retrying attempt=4 backoff=759.956887ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22022026/11/11 23:37:18 INFO Received push request method=POST path=/api/pushes22032026/11/11 23:37:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)22042026/11/11 23:37:18 INFO Uploading klg9lybp8q2yvayphv1kxdhvggx7z3yq-unpinned-file.txt (128B)22052026/11/11 23:37:19 WARN Failed to register uploaded object key=klg9lybp8q2yvayphv1kxdhvggx7z3yq.ls error="server returned 404: 404 page not found\n"22062026/11/11 23:37:19 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign22072026/11/11 23:37:19 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"22082026/11/11 23:37:19 INFO Signed narinfos id=2 count=122092026/11/11 23:37:19 INFO Uploading 1 narinfos22102026/11/11 23:37:19 INFO Received complete push request method=POST path=/api/pushes/2/complete22112026/11/11 23:37:19 WARN Failed to register uploaded object key=klg9lybp8q2yvayphv1kxdhvggx7z3yq.narinfo error="server returned 404: 404 page not found\n"22122026/11/11 23:37:19 INFO Completed push id=2 objects=3 duration=1.802337ms22132026/11/11 23:37:19 INFO Upload complete. (1.314s)22142026/11/11 23:37:19 WARN Request failed, retrying attempt=5 backoff=1.670891364s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22152026/11/11 23:37:20 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"22162026/11/11 23:37:20 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22172026/11/11 23:37:20 WARN Request failed, retrying attempt=2 backoff=213.506337ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22182026/11/11 23:37:21 WARN Request failed, retrying attempt=3 backoff=431.902373ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22192026/11/11 23:37:21 WARN Request failed, retrying attempt=4 backoff=738.123921ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22202026/11/11 23:37:22 INFO Starting cleanup of old closures method=DELETE path=/api/closures22212026/11/11 23:37:22 INFO Garbage collection started22222026/11/11 23:37:22 INFO Aborted multipart uploads count=0 kept=022232026/11/11 23:37:22 WARN Request failed, retrying attempt=5 backoff=1.665380441s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22242026/11/11 23:37:22 WARN Force mode enabled - objects will be deleted immediately without grace period2225=== NAME TestClientCADerivations2226 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2227 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2228 error: binary cache 's3://bucket26?endpoint=http://localhost:43729®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations326494917/001/store'2229 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12230--- PASS: TestClientCADerivations (21.43s)22312026/11/11 23:37:22 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=022322026/11/11 23:37:22 INFO Vacuumed table table=pending_closures22332026/11/11 23:37:22 INFO Vacuumed table table=pending_objects22342026/11/11 23:37:22 INFO Vacuumed table table=multipart_uploads22352026/11/11 23:37:22 INFO Vacuumed table table=closures22362026/11/11 23:37:22 INFO Vacuumed table table=objects22372026/11/11 23:37:23 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22382026/11/11 23:37:24 WARN Request failed, retrying attempt=2 backoff=202.278593ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22392026/11/11 23:37:24 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=022402026/11/11 23:37:24 INFO Received create pin request method=POST path=/api/pins/myapp22412026/11/11 23:37:24 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2725197344/001/store/8qa0f2cdnghwdz9miprm1pdzbkm9kfll-pinned-file.txt narinfo_key=8qa0f2cdnghwdz9miprm1pdzbkm9kfll.narinfo22422026/11/11 23:37:24 INFO Starting cleanup of old closures method=DELETE path=/api/closures22432026/11/11 23:37:24 INFO Garbage collection started22442026/11/11 23:37:24 INFO Aborted multipart uploads count=0 kept=022452026/11/11 23:37:24 WARN Request failed, retrying attempt=3 backoff=420.819806ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22462026/11/11 23:37:24 WARN Force mode enabled - objects will be deleted immediately without grace period22472026/11/11 23:37:24 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 23:37:24 INFO Vacuumed table table=pending_closures22492026/11/11 23:37:24 INFO Vacuumed table table=pending_objects22502026/11/11 23:37:24 INFO Vacuumed table table=multipart_uploads22512026/11/11 23:37:24 INFO Vacuumed table table=closures22522026/11/11 23:37:24 INFO Vacuumed table table=objects22532026/11/11 23:37:24 WARN Request failed, retrying attempt=4 backoff=792.09289ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22542026/11/11 23:37:25 WARN Request failed, retrying attempt=5 backoff=1.645547203s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2255=== NAME TestPinProtectsFromGC2256 client_integration_test.go:888: Pin successfully protected closure from garbage collection2257--- PASS: TestPinProtectsFromGC (16.11s)2258--- PASS: TestClientErrorHandling (0.01s)2259 --- PASS: TestClientErrorHandling/InvalidStorePath (3.13s)2260 --- PASS: TestClientErrorHandling/InvalidAuthToken (5.86s)2261 --- PASS: TestClientErrorHandling/ServerNotAvailable (15.24s)2262PASS2263{"timestamp":"2026-11-11T23:37:27.131005421Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:38334","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(196)"}22642026-11-11 23:37:27.526 UTC [131] LOG: received smart shutdown request22652026-11-11 23:37:27.536 UTC [131] LOG: background worker "logical replication launcher" (PID 146) exited with exit code 122662026-11-11 23:37:27.551 UTC [139] LOG: shutting down22672026-11-11 23:37:27.552 UTC [139] LOG: checkpoint starting: shutdown immediate22682026-11-11 23:37:28.425 UTC [139] LOG: checkpoint complete: wrote 11227 buffers (68.5%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.457 s, sync=0.360 s, total=0.874 s; sync files=36842, longest=0.005 s, average=0.001 s; distance=531067 kB, estimate=531067 kB; lsn=0/21E04B30, redo lsn=0/21E04B3022692026-11-11 23:37:28.606 UTC [131] LOG: database system is shut down2270Running OIDC tests...2271=== RUN TestAudienceForIssuer2272=== PAUSE TestAudienceForIssuer2273=== RUN TestGlobMatch2274=== PAUSE TestGlobMatch2275=== RUN TestValidateToken_ValidToken2276=== PAUSE TestValidateToken_ValidToken2277=== RUN TestValidateToken_WrongAudience2278=== PAUSE TestValidateToken_WrongAudience2279=== RUN TestValidateToken_Expired2280=== PAUSE TestValidateToken_Expired2281=== RUN TestValidateToken_BoundClaimsMismatch2282=== PAUSE TestValidateToken_BoundClaimsMismatch2283=== RUN TestValidateToken_BoundSubjectMismatch2284=== PAUSE TestValidateToken_BoundSubjectMismatch2285=== RUN TestValidateToken_MultipleProviders2286=== PAUSE TestValidateToken_MultipleProviders2287=== RUN TestValidateToken_NoMatchingProvider2288=== PAUSE TestValidateToken_NoMatchingProvider2289=== RUN TestValidateToken_KubernetesServiceAccount2290=== PAUSE TestValidateToken_KubernetesServiceAccount2291=== RUN TestNewValidator_KubernetesRequiresCA2292=== PAUSE TestNewValidator_KubernetesRequiresCA2293=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2294=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2295=== RUN TestPins_ReservedForMatchingRule2296=== PAUSE TestPins_ReservedForMatchingRule2297=== RUN TestPins_TopLevelShorthand2298=== PAUSE TestPins_TopLevelShorthand2299=== RUN TestPins_ConfigValidation2300=== PAUSE TestPins_ConfigValidation2301=== RUN TestScopes_LegacyProviderDefaultsToWrite2302=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2303=== RUN TestScopes_Rules2304=== PAUSE TestScopes_Rules2305=== RUN TestScopes_ConfigValidation2306=== PAUSE TestScopes_ConfigValidation2307=== CONT TestAudienceForIssuer2308=== CONT TestValidateToken_KubernetesServiceAccount2309=== CONT TestValidateToken_BoundClaimsMismatch2310=== CONT TestValidateToken_WrongAudience2311--- PASS: TestAudienceForIssuer (0.00s)2312=== CONT TestValidateToken_ValidToken2313=== CONT TestGlobMatch2314=== RUN TestGlobMatch/foo_foo2315=== PAUSE TestGlobMatch/foo_foo2316=== RUN TestGlobMatch/foo_bar2317=== PAUSE TestGlobMatch/foo_bar2318=== RUN TestGlobMatch/*_2319=== PAUSE TestGlobMatch/*_2320=== RUN TestGlobMatch/*_anything2321=== PAUSE TestGlobMatch/*_anything2322=== RUN TestGlobMatch/foo*_foo2323=== PAUSE TestGlobMatch/foo*_foo2324=== RUN TestGlobMatch/foo*_foobar2325=== PAUSE TestGlobMatch/foo*_foobar2326=== RUN TestGlobMatch/foo*_bar2327=== PAUSE TestGlobMatch/foo*_bar2328=== RUN TestGlobMatch/*bar_bar2329=== PAUSE TestGlobMatch/*bar_bar2330=== RUN TestGlobMatch/*bar_foobar2331=== PAUSE TestGlobMatch/*bar_foobar2332=== RUN TestGlobMatch/*bar_foo2333=== PAUSE TestGlobMatch/*bar_foo2334=== RUN TestGlobMatch/foo*bar_foobar2335=== PAUSE TestGlobMatch/foo*bar_foobar2336=== RUN TestGlobMatch/foo*bar_foo123bar2337=== PAUSE TestGlobMatch/foo*bar_foo123bar2338=== RUN TestGlobMatch/foo*bar_foobarbaz2339=== PAUSE TestGlobMatch/foo*bar_foobarbaz2340=== RUN TestGlobMatch/*/*_foo/bar2341=== PAUSE TestGlobMatch/*/*_foo/bar2342=== RUN TestGlobMatch/*/*_foo2343=== PAUSE TestGlobMatch/*/*_foo2344=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2345=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2346=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02347=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02348=== RUN TestGlobMatch/refs/*/main_refs/heads/main2349=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2350=== RUN TestGlobMatch/fo?_foo2351=== PAUSE TestGlobMatch/fo?_foo2352=== RUN TestGlobMatch/fo?_fo2353=== PAUSE TestGlobMatch/fo?_fo2354=== RUN TestGlobMatch/fo?_fooo2355=== PAUSE TestGlobMatch/fo?_fooo2356=== RUN TestGlobMatch/?oo_foo2357=== PAUSE TestGlobMatch/?oo_foo2358=== RUN TestGlobMatch/?oo_boo2359=== PAUSE TestGlobMatch/?oo_boo2360=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2361=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2362=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2363=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2364=== CONT TestGlobMatch/foo_foo2365=== CONT TestValidateToken_MultipleProviders2366=== CONT TestValidateToken_NoMatchingProvider2367=== CONT TestPins_ConfigValidation2368--- PASS: TestPins_ConfigValidation (0.01s)2369=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02370=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2371=== CONT TestGlobMatch/*/*_foo2372=== CONT TestGlobMatch/*/*_foo/bar2373=== CONT TestGlobMatch/foo*bar_foobarbaz2374=== CONT TestGlobMatch/foo*bar_foo123bar2375=== CONT TestGlobMatch/foo*bar_foobar2376=== CONT TestGlobMatch/*bar_foo2377=== CONT TestGlobMatch/*bar_foobar2378=== CONT TestGlobMatch/*bar_bar2379=== CONT TestGlobMatch/foo*_bar2380=== CONT TestGlobMatch/foo*_foobar2381=== CONT TestGlobMatch/foo*_foo2382=== CONT TestGlobMatch/*_anything2383=== CONT TestGlobMatch/*_2384=== CONT TestGlobMatch/foo_bar2385=== CONT TestScopes_ConfigValidation2386=== CONT TestScopes_Rules2387=== CONT TestScopes_LegacyProviderDefaultsToWrite2388--- PASS: TestScopes_ConfigValidation (0.00s)2389=== CONT TestPins_ReservedForMatchingRule2390=== CONT TestPins_TopLevelShorthand23912026/11/11 23:37:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39931/oidc2392=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2393=== CONT TestValidateToken_BoundSubjectMismatch2394=== CONT TestNewValidator_KubernetesRequiresCA2395=== CONT TestValidateToken_Expired2396=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2397=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2398=== CONT TestGlobMatch/?oo_boo2399=== CONT TestGlobMatch/?oo_foo2400=== CONT TestGlobMatch/fo?_fooo2401=== CONT TestGlobMatch/fo?_fo2402=== CONT TestGlobMatch/fo?_foo2403=== CONT TestGlobMatch/refs/*/main_refs/heads/main2404--- PASS: TestGlobMatch (0.00s)2405 --- PASS: TestGlobMatch/foo_foo (0.00s)2406 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2407 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2408 --- PASS: TestGlobMatch/*/*_foo (0.00s)2409 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2410 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2411 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2412 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2413 --- PASS: TestGlobMatch/*bar_foo (0.00s)2414 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2415 --- PASS: TestGlobMatch/*bar_bar (0.00s)2416 --- PASS: TestGlobMatch/foo*_bar (0.00s)2417 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2418 --- PASS: TestGlobMatch/foo*_foo (0.00s)2419 --- PASS: TestGlobMatch/*_anything (0.00s)2420 --- PASS: TestGlobMatch/*_ (0.00s)2421 --- PASS: TestGlobMatch/foo_bar (0.00s)2422 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2423 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2424 --- PASS: TestGlobMatch/?oo_boo (0.00s)2425 --- PASS: TestGlobMatch/?oo_foo (0.00s)2426 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2427 --- PASS: TestGlobMatch/fo?_fo (0.00s)2428 --- PASS: TestGlobMatch/fo?_foo (0.00s)2429 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2430--- PASS: TestValidateToken_WrongAudience (1.59s)24312026/11/11 23:37:34 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:416152432--- PASS: TestValidateToken_KubernetesServiceAccount (1.60s)24332026/11/11 23:37:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45267/oidc2434--- PASS: TestValidateToken_ValidToken (2.16s)24352026/11/11 23:37:36 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:34415/oidc24362026/11/11 23:37:36 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:37039/oidc2437--- PASS: TestValidateToken_MultipleProviders (3.88s)24382026/11/11 23:37:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35825/oidc24392026/11/11 23:37:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40513/oidc2440--- PASS: TestValidateToken_BoundClaimsMismatch (3.97s)24412026/11/11 23:37:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41977/oidc24422026/11/11 23:37:37 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232443--- PASS: TestScopes_Rules (2.95s)2444--- PASS: TestPins_TopLevelShorthand (2.95s)2445--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (2.95s)24462026/11/11 23:37:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35409/oidc2447--- PASS: TestScopes_LegacyProviderDefaultsToWrite (2.98s)24482026/11/11 23:37:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36069/oidc24492026/11/11 23:37:37 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:42171/oidc2450--- PASS: TestValidateToken_NoMatchingProvider (3.98s)2451--- PASS: TestPins_ReservedForMatchingRule (3.00s)24522026/11/11 23:37:37 http: TLS handshake error from 127.0.0.1:59910: remote error: tls: bad certificate2453--- PASS: TestNewValidator_KubernetesRequiresCA (2.46s)24542026/11/11 23:37:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36839/oidc2455--- PASS: TestValidateToken_Expired (2.51s)24562026/11/11 23:37:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39547/oidc2457--- PASS: TestValidateToken_BoundSubjectMismatch (2.56s)2458PASS2459Running hook tests...2460=== RUN TestSendPathsEmpty2461=== PAUSE TestSendPathsEmpty2462=== RUN TestQueueEnqueueAndFetch2463=== PAUSE TestQueueEnqueueAndFetch2464=== RUN TestQueueDeduplication2465=== PAUSE TestQueueDeduplication2466=== RUN TestQueueRemove2467=== PAUSE TestQueueRemove2468=== RUN TestQueueFetchBatchLimit2469=== PAUSE TestQueueFetchBatchLimit2470=== RUN TestQueueRetryMovesToBack2471=== PAUSE TestQueueRetryMovesToBack2472=== RUN TestQueueFetchRemoveLifecycle2473=== PAUSE TestQueueFetchRemoveLifecycle2474=== RUN TestQueueConcurrentWriters2475=== PAUSE TestQueueConcurrentWriters2476=== RUN TestQueueRemoveLargeClosure2477=== PAUSE TestQueueRemoveLargeClosure2478=== RUN TestServerClientIntegration2479--- PASS: TestServerClientIntegration (0.01s)2480=== RUN TestServerQueueError24812026/11/11 23:37:37 ERROR Failed to queue paths error="permission denied" count=12482--- PASS: TestServerQueueError (0.00s)2483=== RUN TestGetListenerSocketActivation2484 server_test.go:220: === RUN TestGetListenerSocketActivation2485 --- PASS: TestGetListenerSocketActivation (0.00s)2486 PASS2487 2488--- PASS: TestGetListenerSocketActivation (0.20s)2489=== RUN TestServerStalledClientDoesNotBlockShutdown2490=== PAUSE TestServerStalledClientDoesNotBlockShutdown2491=== RUN TestServerBacksOffOnAcceptErrors2492=== PAUSE TestServerBacksOffOnAcceptErrors2493=== RUN TestDrainIsolatesPoisonPath2494=== PAUSE TestDrainIsolatesPoisonPath2495=== RUN TestRunNotBlockedByPoisonHead2496=== PAUSE TestRunNotBlockedByPoisonHead2497=== RUN TestDrainGivesUpWhenServerDown2498=== PAUSE TestDrainGivesUpWhenServerDown2499=== RUN TestFailedPathPrunedByLaterClosure2500=== PAUSE TestFailedPathPrunedByLaterClosure2501=== RUN TestWorkerUploadsAndRemoves2502=== PAUSE TestWorkerUploadsAndRemoves2503=== RUN TestWorkerSkipsGCdPaths2504=== PAUSE TestWorkerSkipsGCdPaths2505=== RUN TestWorkerPrunesClosureDeps2506=== PAUSE TestWorkerPrunesClosureDeps2507=== RUN TestDrainTimeout2508=== PAUSE TestDrainTimeout2509=== RUN TestWorkerRemoveFailureIsNotProgress2510=== PAUSE TestWorkerRemoveFailureIsNotProgress2511=== RUN TestWorkerKeepsPathItCannotStat2512=== PAUSE TestWorkerKeepsPathItCannotStat2513=== CONT TestSendPathsEmpty2514--- PASS: TestSendPathsEmpty (0.00s)2515=== CONT TestWorkerKeepsPathItCannotStat2516=== CONT TestWorkerRemoveFailureIsNotProgress25172026/11/11 23:37:37 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress1193157563/002/nonexistent25182026/11/11 23:37:37 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125192026/11/11 23:37:37 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress1193157563/002/nonexistent25202026/11/11 23:37:37 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125212026/11/11 23:37:37 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress1193157563/002/nonexistent25222026/11/11 23:37:37 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125232026/11/11 23:37:37 ERROR Drain finished with paths left in queue remaining=12524--- PASS: TestWorkerRemoveFailureIsNotProgress (0.01s)2525=== CONT TestDrainTimeout25262000/01/01 00:00:00 INFO Uploading batch count=22527=== CONT TestWorkerPrunesClosureDeps25282026/11/11 23:37:37 INFO Upload queue status pending=225292026/11/11 23:37:37 INFO Uploading batch count=12530=== CONT TestWorkerSkipsGCdPaths25312026/11/11 23:37:37 INFO Upload queue status pending=225322026/11/11 23:37:37 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths197572400/002/nonexistent25332026/11/11 23:37:37 INFO Uploading batch count=12534=== CONT TestWorkerUploadsAndRemoves25352026/11/11 23:37:37 INFO Upload queue status pending=225362026/11/11 23:37:37 INFO Uploading batch count=22537=== CONT TestFailedPathPrunedByLaterClosure25382026/11/11 23:37:37 INFO Uploading batch count=125392026/11/11 23:37:37 ERROR Upload failed error="upload failed" count=125402026/11/11 23:37:37 INFO Uploading batch count=125412026/11/11 23:37:37 INFO Uploading batch count=12542=== CONT TestDrainGivesUpWhenServerDown2543--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)25442000/01/01 00:00:00 ERROR Upload failed error="context deadline exceeded" count=225452000/01/01 00:00:00 ERROR Drain finished with paths left in queue remaining=42546=== CONT TestQueueRetryMovesToBack2547=== CONT TestQueueFetchBatchLimit2548=== CONT TestRunNotBlockedByPoisonHead2549=== CONT TestDrainIsolatesPoisonPath2550=== CONT TestQueueRemoveLargeClosure2551=== CONT TestServerBacksOffOnAcceptErrors25522000/01/01 00:00:00 ERROR Accept failed error="too many open files"25532000/01/01 00:00:00 ERROR Accept failed error="too many open files"25542000/01/01 00:00:00 ERROR Accept failed error="too many open files"25552000/01/01 00:00:00 ERROR Accept failed error="too many open files"25562000/01/01 00:00:00 ERROR Accept failed error="too many open files"25572000/01/01 00:00:00 ERROR Accept failed error="too many open files"25582000/01/01 00:00:00 ERROR Accept failed error="too many open files"25592000/01/01 00:00:00 ERROR Accept failed error="too many open files"2560=== CONT TestServerStalledClientDoesNotBlockShutdown2561--- PASS: TestServerBacksOffOnAcceptErrors (0.00s)2562--- PASS: TestDrainTimeout (0.02s)2563=== CONT TestQueueConcurrentWriters2564=== CONT TestQueueRemove2565=== CONT TestQueueDeduplication25662026/11/11 23:37:37 INFO Uploading batch count=225672026/11/11 23:37:37 ERROR Upload failed error="upload failed" count=225682026/11/11 23:37:37 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1763492020/002/a25692026/11/11 23:37:37 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat1623839883/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat1623839883/002/locked/aaa: permission denied"25702026/11/11 23:37:37 INFO Uploading batch count=425712026/11/11 23:37:37 ERROR Upload failed error="upload failed" count=42572=== CONT TestQueueFetchRemoveLifecycle2573--- PASS: TestQueueFetchBatchLimit (0.00s)2574=== CONT TestQueueEnqueueAndFetch25752026/11/11 23:37:37 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1763492020/002/b25762026/11/11 23:37:37 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath4123708634/002/bbb25772026/11/11 23:37:37 INFO Uploading batch count=225782026/11/11 23:37:37 ERROR Upload failed error="upload failed" count=225792026/11/11 23:37:37 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1763492020/002/c25802026/11/11 23:37:37 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1763492020/002/d25812026/11/11 23:37:37 INFO Uploading batch count=125822026/11/11 23:37:37 ERROR Upload failed error="upload failed" count=125832026/11/11 23:37:37 INFO Uploading batch count=125842026/11/11 23:37:37 ERROR Upload failed error="upload failed" count=125852026/11/11 23:37:37 INFO Uploading batch count=225862026/11/11 23:37:37 ERROR Upload failed error="upload failed" count=225872026/11/11 23:37:37 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1763492020/002/e2588--- PASS: TestWorkerUploadsAndRemoves (0.03s)25892026/11/11 23:37:42 ERROR Failed to decode request error="read unix /build/hook899745550/test.sock->@: i/o timeout"25902026/11/11 23:37:42 ERROR Failed to write response error="write unix /build/hook899745550/test.sock->@: i/o timeout"2591--- PASS: TestServerStalledClientDoesNotBlockShutdown (4.21s)25922026/11/11 23:37:42 INFO Uploading batch count=125932026/11/11 23:37:42 ERROR Upload failed error="upload failed" count=12594--- PASS: TestWorkerPrunesClosureDeps (4.23s)25952026/11/11 23:37:42 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat1623839883/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat1623839883/002/locked/aaa: permission denied"25962026/11/11 23:37:42 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1763492020/002/f25972026/11/11 23:37:42 INFO Upload queue status pending=325982026/11/11 23:37:42 ERROR Drain finished with paths left in queue remaining=125992026/11/11 23:37:42 INFO Uploading batch count=126002026/11/11 23:37:42 ERROR Upload failed error="upload failed" count=12601--- PASS: TestWorkerSkipsGCdPaths (4.23s)2602--- PASS: TestQueueDeduplication (4.21s)26032026/11/11 23:37:42 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat1623839883/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat1623839883/002/locked/aaa: permission denied"2604--- PASS: TestDrainIsolatesPoisonPath (4.22s)2605--- PASS: TestQueueRemove (4.22s)26062026/11/11 23:37:42 ERROR Drain finished with paths left in queue remaining=12607--- PASS: TestQueueRetryMovesToBack (4.22s)2608--- PASS: TestWorkerKeepsPathItCannotStat (4.27s)2609--- PASS: TestQueueEnqueueAndFetch (4.22s)2610--- PASS: TestQueueFetchRemoveLifecycle (4.22s)26112026/11/11 23:37:43 INFO Uploading batch count=126122026/11/11 23:37:43 INFO Uploading batch count=126132026/11/11 23:37:43 INFO Uploading batch count=126142026/11/11 23:37:43 ERROR Upload failed error="upload failed" count=126152026/11/11 23:37:43 INFO Uploading batch count=126162026/11/11 23:37:43 ERROR Upload failed error="upload failed" count=126172026/11/11 23:37:43 INFO Uploading batch count=126182026/11/11 23:37:43 ERROR Upload failed error="upload failed" count=126192026/11/11 23:37:43 INFO Uploading batch count=126202026/11/11 23:37:43 ERROR Upload failed error="upload failed" count=126212026/11/11 23:37:43 ERROR Drain finished with paths left in queue remaining=12622--- PASS: TestRunNotBlockedByPoisonHead (5.22s)26232026/11/11 23:37:44 ERROR Drain finished with paths left in queue remaining=102624--- PASS: TestDrainGivesUpWhenServerDown (6.51s)2625--- PASS: TestQueueRemoveLargeClosure (6.59s)2626--- PASS: TestQueueConcurrentWriters (6.59s)2627PASS2628Running signing tests...2629=== RUN TestExternalSigner2630=== PAUSE TestExternalSigner2631=== RUN TestExternalSignerWrongPublicKey2632=== PAUSE TestExternalSignerWrongPublicKey2633=== RUN TestExternalSignerErrors2634=== PAUSE TestExternalSignerErrors2635=== RUN TestExternalSignerRestartsAfterCrash2636=== PAUSE TestExternalSignerRestartsAfterCrash2637=== RUN TestExternalSignerProgramErrorKeepsProcess2638=== PAUSE TestExternalSignerProgramErrorKeepsProcess2639=== RUN TestExternalSignerClose2640=== PAUSE TestExternalSignerClose2641=== RUN TestExternalSignerRejectsInvalidPublicKey2642=== PAUSE TestExternalSignerRejectsInvalidPublicKey2643=== RUN TestExternalSignerCancellation2644=== PAUSE TestExternalSignerCancellation2645=== RUN TestGenerateFingerprint2646=== PAUSE TestGenerateFingerprint2647=== RUN TestParseSigningKey2648=== PAUSE TestParseSigningKey2649=== RUN TestSign2650=== PAUSE TestSign2651=== RUN TestSignBatch2652=== PAUSE TestSignBatch2653=== RUN TestNilKeyPublicKey2654=== PAUSE TestNilKeyPublicKey2655=== RUN TestSignErrors2656=== PAUSE TestSignErrors2657=== CONT TestExternalSigner2658=== CONT TestExternalSignerProgramErrorKeepsProcess2659=== CONT TestExternalSignerRejectsInvalidPublicKey2660=== RUN TestExternalSignerRejectsInvalidPublicKey/#002661=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002662=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2663=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2664=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2665=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2666=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2667=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2668=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2669=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2670=== CONT TestExternalSignerRejectsInvalidPublicKey/#002671=== CONT TestExternalSignerClose2672=== CONT TestExternalSignerCancellation2673=== CONT TestExternalSignerErrors2674=== RUN TestExternalSignerErrors/too_few_signatures2675=== PAUSE TestExternalSignerErrors/too_few_signatures2676=== RUN TestExternalSignerErrors/wrong_signature_length2677=== PAUSE TestExternalSignerErrors/wrong_signature_length2678=== RUN TestExternalSignerErrors/invalid_JSON2679=== PAUSE TestExternalSignerErrors/invalid_JSON2680=== RUN TestExternalSignerErrors/missing_signatures2681=== PAUSE TestExternalSignerErrors/missing_signatures2682=== RUN TestExternalSignerErrors/wrong_signature_name2683=== PAUSE TestExternalSignerErrors/wrong_signature_name2684=== RUN TestExternalSignerErrors/invalid_signature_base642685=== PAUSE TestExternalSignerErrors/invalid_signature_base642686=== RUN TestExternalSignerErrors/program_error2687=== PAUSE TestExternalSignerErrors/program_error2688=== RUN TestExternalSignerErrors/exit_at_startup2689=== PAUSE TestExternalSignerErrors/exit_at_startup2690=== RUN TestExternalSignerErrors/exit_on_request2691=== PAUSE TestExternalSignerErrors/exit_on_request2692=== RUN TestExternalSignerErrors/wrong_shape2693=== PAUSE TestExternalSignerErrors/wrong_shape2694=== RUN TestExternalSignerErrors/wrong_id2695=== PAUSE TestExternalSignerErrors/wrong_id2696=== RUN TestExternalSignerErrors/wrong_signatures_shape2697=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2698=== RUN TestExternalSignerErrors/unrequested_key2699=== PAUSE TestExternalSignerErrors/unrequested_key2700=== RUN TestExternalSignerErrors/missing_signature_name2701=== PAUSE TestExternalSignerErrors/missing_signature_name2702=== RUN TestExternalSignerErrors/null_signatures2703=== PAUSE TestExternalSignerErrors/null_signatures2704=== RUN TestExternalSignerErrors/null2705=== PAUSE TestExternalSignerErrors/null2706=== CONT TestExternalSignerErrors/too_few_signatures2707=== CONT TestExternalSignerWrongPublicKey2708=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2709=== CONT TestExternalSignerErrors/wrong_shape2710=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2711=== CONT TestSign2712=== CONT TestExternalSignerErrors/exit_on_request2713=== CONT TestExternalSignerErrors/exit_at_startup2714=== CONT TestExternalSignerErrors/program_error2715=== CONT TestGenerateFingerprint2716=== RUN TestGenerateFingerprint/basic_with_references2717=== PAUSE TestGenerateFingerprint/basic_with_references2718=== CONT TestExternalSignerErrors/invalid_signature_base642719=== CONT TestExternalSignerErrors/missing_signatures2720=== CONT TestExternalSignerErrors/invalid_JSON2721=== CONT TestExternalSignerErrors/wrong_signature_length2722=== CONT TestExternalSignerErrors/missing_signature_name2723--- PASS: TestSign (0.00s)2724=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2725=== CONT TestExternalSignerRestartsAfterCrash2726=== CONT TestExternalSignerErrors/null2727=== CONT TestExternalSignerErrors/null_signatures2728=== CONT TestSignBatch2729=== CONT TestSignErrors2730=== RUN TestSignErrors/nil_key2731=== CONT TestNilKeyPublicKey2732=== CONT TestExternalSignerErrors/wrong_signature_name2733=== RUN TestGenerateFingerprint/no_references2734=== CONT TestExternalSignerErrors/wrong_signatures_shape2735--- PASS: TestNilKeyPublicKey (0.00s)2736=== PAUSE TestSignErrors/nil_key2737=== PAUSE TestGenerateFingerprint/no_references2738=== RUN TestSignErrors/nil_narinfo2739=== PAUSE TestSignErrors/nil_narinfo2740=== RUN TestSignErrors/invalid_narinfo2741=== PAUSE TestSignErrors/invalid_narinfo2742=== RUN TestSignErrors/canceled2743=== CONT TestExternalSignerErrors/unrequested_key2744=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2745--- PASS: TestSignBatch (0.00s)2746=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2747--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2748 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2749 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2750 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2751 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2752 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2753=== CONT TestParseSigningKey2754=== CONT TestExternalSignerErrors/wrong_id2755--- PASS: TestExternalSignerClose (0.01s)2756=== PAUSE TestSignErrors/canceled2757=== CONT TestSignErrors/nil_key2758=== CONT TestSignErrors/invalid_narinfo2759=== CONT TestSignErrors/canceled2760=== RUN TestParseSigningKey/valid_32-byte_key2761=== CONT TestSignErrors/nil_narinfo2762--- PASS: TestSignErrors (0.00s)2763 --- PASS: TestSignErrors/nil_key (0.00s)2764 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2765 --- PASS: TestSignErrors/canceled (0.00s)2766 --- PASS: TestSignErrors/nil_narinfo (0.00s)2767=== PAUSE TestParseSigningKey/valid_32-byte_key2768=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2769=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2770=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2771=== RUN TestParseSigningKey/no_colon2772=== PAUSE TestParseSigningKey/no_colon2773=== RUN TestParseSigningKey/empty_name2774=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2775=== PAUSE TestParseSigningKey/empty_name2776=== RUN TestParseSigningKey/invalid_base642777=== PAUSE TestParseSigningKey/invalid_base642778=== RUN TestParseSigningKey/wrong_length2779=== PAUSE TestParseSigningKey/wrong_length2780=== CONT TestParseSigningKey/valid_32-byte_key2781=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2782=== CONT TestParseSigningKey/empty_name2783=== CONT TestParseSigningKey/invalid_base642784=== CONT TestParseSigningKey/wrong_length2785=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2786=== RUN TestGenerateFingerprint/invalid_nar_hash_length2787=== CONT TestParseSigningKey/no_colon2788--- PASS: TestParseSigningKey (0.01s)2789 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2790 --- PASS: TestParseSigningKey/empty_name (0.00s)2791 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2792 --- PASS: TestParseSigningKey/wrong_length (0.00s)2793 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2794 --- PASS: TestParseSigningKey/no_colon (0.00s)2795=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2796=== RUN TestGenerateFingerprint/invalid_store_path_prefix2797=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2798=== RUN TestGenerateFingerprint/invalid_reference_prefix2799=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2800=== CONT TestGenerateFingerprint/basic_with_references2801=== CONT TestGenerateFingerprint/invalid_reference_prefix2802=== CONT TestGenerateFingerprint/invalid_store_path_prefix2803=== CONT TestGenerateFingerprint/invalid_nar_hash_length2804=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2805=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2806=== CONT TestGenerateFingerprint/no_references2807--- PASS: TestGenerateFingerprint (0.01s)2808 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2809 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2810 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2811 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2812 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2813 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2814 --- PASS: TestGenerateFingerprint/no_references (0.00s)2815--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.02s)2816--- PASS: TestExternalSignerWrongPublicKey (0.02s)2817--- PASS: TestExternalSignerErrors (0.00s)2818 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2819 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2820 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2821 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2822 --- PASS: TestExternalSignerErrors/null (0.01s)2823 --- PASS: TestExternalSignerErrors/too_few_signatures (0.02s)2824 --- PASS: TestExternalSignerErrors/program_error (0.02s)2825 --- PASS: TestExternalSignerErrors/unrequested_key (0.02s)2826 --- PASS: TestExternalSignerErrors/null_signatures (0.02s)2827 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.02s)2828 --- PASS: TestExternalSignerErrors/invalid_JSON (0.02s)2829 --- PASS: TestExternalSignerErrors/missing_signatures (0.02s)2830 --- PASS: TestExternalSignerErrors/wrong_id (0.02s)2831 --- PASS: TestExternalSignerErrors/missing_signature_name (0.02s)2832 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.02s)2833 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.02s)2834--- PASS: TestExternalSignerCancellation (0.03s)2835--- PASS: TestExternalSignerRestartsAfterCrash (0.02s)2836--- PASS: TestExternalSigner (0.03s)2837PASS2838Running OpenBao signer tests...2839=== RUN TestSign2840=== PAUSE TestSign2841=== RUN TestSignErrors2842=== PAUSE TestSignErrors2843=== RUN TestServe2844=== PAUSE TestServe2845=== RUN TestServeRejectsGarbage2846=== PAUSE TestServeRejectsGarbage2847=== CONT TestSign2848=== CONT TestServe2849=== CONT TestSignErrors2850=== RUN TestSignErrors/http_error2851=== PAUSE TestSignErrors/http_error2852=== RUN TestSignErrors/invalid_json2853--- PASS: TestServe (0.00s)2854=== PAUSE TestSignErrors/invalid_json2855=== RUN TestSignErrors/no_prefix2856=== PAUSE TestSignErrors/no_prefix2857=== RUN TestSignErrors/invalid_base642858=== PAUSE TestSignErrors/invalid_base642859=== CONT TestSignErrors/http_error2860=== CONT TestServeRejectsGarbage2861--- PASS: TestServeRejectsGarbage (0.00s)2862=== CONT TestSignErrors/invalid_base642863=== CONT TestSignErrors/no_prefix2864=== CONT TestSignErrors/invalid_json2865--- PASS: TestSignErrors (0.00s)2866 --- PASS: TestSignErrors/http_error (1.76s)2867 --- PASS: TestSignErrors/invalid_json (1.76s)2868 --- PASS: TestSignErrors/no_prefix (1.76s)2869 --- PASS: TestSignErrors/invalid_base64 (1.76s)2870--- PASS: TestSign (1.76s)2871PASS