niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #443
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry5=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry6=== RUN TestRegisterUploadedObjectReusesConnections7=== PAUSE TestRegisterUploadedObjectReusesConnections8=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica9=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica10=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun11=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun12=== RUN TestCaseHackSuffix13=== PAUSE TestCaseHackSuffix14=== RUN TestFilterOversizedClosures15=== PAUSE TestFilterOversizedClosures16=== RUN TestUploadMultipart_PartsInParallel17=== PAUSE TestUploadMultipart_PartsInParallel18=== RUN TestUploadMultipart_FailedPartBufferNotReused19=== PAUSE TestUploadMultipart_FailedPartBufferNotReused20=== RUN TestPartSizeForNAR21=== PAUSE TestPartSizeForNAR22=== RUN TestUploadMultipart_SupersededByPeer23=== PAUSE TestUploadMultipart_SupersededByPeer24=== RUN TestDumpPathCaseHackMatchesNix25--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)26=== RUN TestDumpPathCaseHackCollision27--- PASS: TestDumpPathCaseHackCollision (0.00s)28=== RUN TestSupersededNARStillUploadsListing29=== PAUSE TestSupersededNARStillUploadsListing30=== RUN TestDumpPathMatchesNix31=== PAUSE TestDumpPathMatchesNix32=== RUN TestDumpPathSingleFile33=== PAUSE TestDumpPathSingleFile34=== RUN TestDumpPathWriterError35=== PAUSE TestDumpPathWriterError36=== RUN TestEncodeNixBase3237=== PAUSE TestEncodeNixBase3238=== RUN TestEncodeNixBase32WithRealHash39=== PAUSE TestEncodeNixBase32WithRealHash40=== RUN TestConvertHashToNix3241=== PAUSE TestConvertHashToNix3242=== RUN TestGetStorePathHash43=== PAUSE TestGetStorePathHash44=== RUN TestPathInfoHashCompatibility45=== PAUSE TestPathInfoHashCompatibility46=== RUN TestParsePathInfoJSON47=== PAUSE TestParsePathInfoJSON48=== RUN TestParsePathInfoJSONMultiplePaths49=== PAUSE TestParsePathInfoJSONMultiplePaths50=== RUN TestPathInfoCACompatibility51=== PAUSE TestPathInfoCACompatibility52=== RUN TestRateLimiterFeedback53=== PAUSE TestRateLimiterFeedback54=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess55=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess56=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer57=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer58=== RUN TestResolveStorePath59=== PAUSE TestResolveStorePath60=== RUN TestDoWithRetry_BodyReplayedViaGetBody61=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody62=== RUN TestRetryTimeoutOutlastsMaxRetries63=== PAUSE TestRetryTimeoutOutlastsMaxRetries64=== RUN TestDoWithRetry_FinalResponseBodyReadable65=== PAUSE TestDoWithRetry_FinalResponseBodyReadable66=== RUN TestShellSplit67=== PAUSE TestShellSplit68=== RUN TestShellSplitErrors69=== PAUSE TestShellSplitErrors70=== RUN TestStreamPushReportsEveryPath71=== PAUSE TestStreamPushReportsEveryPath72=== RUN TestStreamPushBatchesUnderLoad73=== PAUSE TestStreamPushBatchesUnderLoad74=== RUN TestStreamPushIsolatesFailures75=== PAUSE TestStreamPushIsolatesFailures76=== RUN TestStreamPushGivesUpOnDeadServer77=== PAUSE TestStreamPushGivesUpOnDeadServer78=== RUN TestStreamPushRequestLine79=== PAUSE TestStreamPushRequestLine80=== RUN TestStreamPushReportsSignatures81=== PAUSE TestStreamPushReportsSignatures82=== RUN TestStreamPushReportsSkippedPaths83=== PAUSE TestStreamPushReportsSkippedPaths84=== RUN TestClientSignaturesByStorePath85=== PAUSE TestClientSignaturesByStorePath86=== RUN TestStreamPushStopsWhenCanceled87=== PAUSE TestStreamPushStopsWhenCanceled88=== RUN TestSetClientTLS89=== PAUSE TestSetClientTLS90=== RUN TestSetClientTLSDoesNotMutateDefaultTransport91=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport92=== RUN TestSetClientTLSErrors93=== PAUSE TestSetClientTLSErrors94=== RUN TestStaticToken95=== PAUSE TestStaticToken96=== RUN TestFileTokenReadsAndCaches97=== PAUSE TestFileTokenReadsAndCaches98=== RUN TestFileTokenMissing99=== PAUSE TestFileTokenMissing100=== RUN TestFileTokenEmpty101=== PAUSE TestFileTokenEmpty102=== RUN TestScriptTokenNoExpiryRerunsEveryCall103=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall104=== RUN TestScriptTokenCachesUntilRefresh105=== PAUSE TestScriptTokenCachesUntilRefresh106=== RUN TestScriptTokenEmptyToken107=== PAUSE TestScriptTokenEmptyToken108=== RUN TestScriptTokenBadJSON109=== PAUSE TestScriptTokenBadJSON110=== RUN TestScriptTokenScriptFails111=== PAUSE TestScriptTokenScriptFails112=== RUN TestScriptTokenEmptyCommand113=== PAUSE TestScriptTokenEmptyCommand114=== CONT TestDoServerRequestAttachesToken115=== CONT TestRateLimiterFeedback116=== CONT TestStreamPushStopsWhenCanceled117=== RUN TestRateLimiterFeedback/429_enables_limiter118=== PAUSE TestRateLimiterFeedback/429_enables_limiter119=== RUN TestRateLimiterFeedback/503_enables_limiter120=== PAUSE TestRateLimiterFeedback/503_enables_limiter121=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter122=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter123=== CONT TestFileTokenReadsAndCaches124=== CONT TestScriptTokenEmptyCommand125--- PASS: TestStreamPushStopsWhenCanceled (0.00s)126=== CONT TestStreamPushGivesUpOnDeadServer127--- PASS: TestScriptTokenEmptyCommand (0.00s)128=== CONT TestSetClientTLSDoesNotMutateDefaultTransport129=== CONT TestScriptTokenScriptFails130=== CONT TestScriptTokenBadJSON131=== CONT TestScriptTokenEmptyToken1322026/10/27 08:54:47 ERROR Upload failed error="connection refused" count=201332026/10/27 08:54:47 ERROR Server seems unavailable, giving up on batch untried=17134=== CONT TestScriptTokenCachesUntilRefresh135--- PASS: TestFileTokenReadsAndCaches (0.00s)136=== CONT TestDumpPathMatchesNix137=== CONT TestScriptTokenNoExpiryRerunsEveryCall138=== CONT TestFileTokenEmpty139=== CONT TestFileTokenMissing140--- PASS: TestScriptTokenScriptFails (0.00s)141=== CONT TestSetClientTLSErrors142=== CONT TestDoWithRetry_FinalResponseBodyReadable143=== CONT TestStreamPushBatchesUnderLoad144=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false145=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false146=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true147=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true148=== CONT TestStreamPushReportsEveryPath149=== CONT TestShellSplitErrors150=== CONT TestStreamPushIsolatesFailures151=== CONT TestShellSplit152=== CONT TestStaticToken153=== CONT TestStreamPushReportsSkippedPaths154=== CONT TestClientSignaturesByStorePath155=== CONT TestStreamPushReportsSignatures156=== CONT TestSetClientTLS157=== CONT TestStreamPushRequestLine158=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter159--- PASS: TestFileTokenEmpty (0.00s)160--- PASS: TestFileTokenMissing (0.00s)161--- PASS: TestClientSignaturesByStorePath (0.00s)162=== CONT TestEncodeNixBase32163--- PASS: TestShellSplitErrors (0.00s)164=== RUN TestEncodeNixBase32/test_string_hash165=== PAUSE TestEncodeNixBase32/test_string_hash166=== CONT TestPathInfoHashCompatibility167=== CONT TestDumpPathWriterError168=== CONT TestConvertHashToNix32169=== CONT TestParsePathInfoJSON170=== CONT TestDumpPathSingleFile1712026/10/27 08:54:47 ERROR Upload failed error="bad path" count=3172=== RUN TestEncodeNixBase32/empty_input173=== PAUSE TestEncodeNixBase32/empty_input174=== CONT TestSupersededNARStillUploadsListing175=== RUN TestParsePathInfoJSON/Nix_format176--- PASS: TestShellSplit (0.00s)177=== CONT TestParsePathInfoJSONMultiplePaths178=== CONT TestEncodeNixBase32WithRealHash179=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)180=== CONT TestPathInfoCACompatibility181=== CONT TestGetStorePathHash182=== RUN TestConvertHashToNix32/SRI_format_to_Nix32183=== CONT TestResolveStorePath184=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter185=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)186=== RUN TestPathInfoCACompatibility/null_ca_field187=== PAUSE TestPathInfoCACompatibility/null_ca_field188=== RUN TestPathInfoCACompatibility/old_string_format_-_text189=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text190=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive191=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive192=== RUN TestPathInfoCACompatibility/new_structured_format_-_text193=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text194=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method195=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method196=== RUN TestGetStorePathHash/valid_store_path1972026/10/27 08:54:47 ERROR Upload failed error=boom count=1198=== PAUSE TestGetStorePathHash/valid_store_path199=== RUN TestGetStorePathHash/basename_without_hyphen_should_error200=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error201=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32202=== CONT TestDoWithRetry_BodyReplayedViaGetBody2032026/10/27 08:54:47 ERROR Upload failed error=boom count=1204=== RUN TestConvertHashToNix32/already_Nix32_format205=== PAUSE TestConvertHashToNix32/already_Nix32_format206=== RUN TestConvertHashToNix32/invalid_format207=== CONT TestPartSizeForNAR208=== PAUSE TestConvertHashToNix32/invalid_format209=== RUN TestPartSizeForNAR/zero_stays_at_minimum210=== CONT TestFilterOversizedClosures211=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum212=== RUN TestPartSizeForNAR/small_stays_at_minimum213=== PAUSE TestPartSizeForNAR/small_stays_at_minimum214=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum215=== RUN TestFilterOversizedClosures/no_limit_keeps_everything216=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything217=== RUN TestSupersededNARStillUploadsListing/small_NAR218=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error219=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error220=== CONT TestUploadMultipart_FailedPartBufferNotReused221=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon222=== CONT TestUploadMultipart_SupersededByPeer223=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon224=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum225--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)226--- PASS: TestStreamPushReportsSkippedPaths (0.00s)227--- PASS: TestStaticToken (0.00s)228--- PASS: TestScriptTokenBadJSON (0.00s)229=== CONT TestRetryTimeoutOutlastsMaxRetries230=== PAUSE TestSupersededNARStillUploadsListing/small_NAR231=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped232=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped233=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error234=== RUN TestFilterOversizedClosures/all_closures_skipped235=== PAUSE TestFilterOversizedClosures/all_closures_skipped236=== RUN TestUploadMultipart_SupersededByPeer/exists237=== PAUSE TestUploadMultipart_SupersededByPeer/exists238=== RUN TestUploadMultipart_SupersededByPeer/missing239=== PAUSE TestUploadMultipart_SupersededByPeer/missing240=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI241=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer242=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error243=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun244=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths245=== RUN TestSetClientTLSErrors/missing_cert_file246=== PAUSE TestParsePathInfoJSON/Nix_format247--- PASS: TestStreamPushReportsEveryPath (0.00s)248--- PASS: TestScriptTokenEmptyToken (0.01s)249--- PASS: TestStreamPushIsolatesFailures (0.00s)2502026/10/27 08:54:47 WARN Rate limiter enabled after throttle name=server-test rate=52512026/10/27 08:54:47 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:45221252=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica253=== CONT TestRegisterUploadedObjectReusesConnections254=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI255=== CONT TestCaseHackSuffix256=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts257=== CONT TestUploadMultipart_PartsInParallel258--- PASS: TestStreamPushReportsSignatures (0.00s)259=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry2602026/10/27 08:54:47 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:448832612026/10/27 08:54:47 WARN Rate limiter enabled after throttle name=server-test rate=52622026/10/27 08:54:47 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:45073263=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512264--- PASS: TestEncodeNixBase32WithRealHash (0.00s)265--- PASS: TestResolveStorePath (0.00s)266--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)267--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)268--- PASS: TestDumpPathSingleFile (0.03s)269=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess2702026/10/27 08:54:47 WARN Rate limiter backed off name=server-test rate=5271--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)272=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false273=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512274=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts275=== RUN TestPartSizeForNAR/1_TiB276=== RUN TestParsePathInfoJSON/Lix_format277=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true2782026/10/27 08:54:47 WARN Rate limiter backed off name=server-test rate=52792026/10/27 08:54:47 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:45073280=== RUN TestSupersededNARStillUploadsListing/dump_cut_short281=== PAUSE TestParsePathInfoJSON/Lix_format282=== PAUSE TestPartSizeForNAR/1_TiB283=== PAUSE TestSetClientTLSErrors/missing_cert_file2842026/10/27 08:54:47 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:44883285=== CONT TestEncodeNixBase32/empty_input286=== CONT TestRateLimiterFeedback/429_enables_limiter287=== RUN TestPartSizeForNAR/5_TiB_S3_max_object288--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.04s)289=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object290=== RUN TestPartSizeForNAR/capped_at_5_GiB291=== PAUSE TestPartSizeForNAR/capped_at_5_GiB292=== CONT TestEncodeNixBase32/test_string_hash293--- PASS: TestEncodeNixBase32 (0.00s)294 --- PASS: TestEncodeNixBase32/empty_input (0.00s)295 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)296=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method297=== CONT TestPathInfoCACompatibility/null_ca_field298--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.07s)299=== CONT TestPathInfoCACompatibility/new_structured_format_-_text300=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short301=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails302=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails3032026/10/27 08:54:47 WARN Rate limiter enabled after throttle name=server-test rate=5304=== CONT TestRateLimiterFeedback/503_enables_limiter305=== CONT TestConvertHashToNix32/SRI_format_to_Nix32306=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter307=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter308=== CONT TestPathInfoCACompatibility/old_string_format_-_text309--- PASS: TestDoServerRequestAttachesToken (0.04s)310=== CONT TestConvertHashToNix32/invalid_format311=== CONT TestConvertHashToNix32/already_Nix32_format312--- PASS: TestConvertHashToNix32 (0.00s)313 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)314 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)315 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)316=== CONT TestFilterOversizedClosures/no_limit_keeps_everything317=== CONT TestFilterOversizedClosures/all_closures_skipped3182026/10/27 08:54:47 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=50319=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3202026/10/27 08:54:47 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=2000321=== RUN TestSetClientTLS/rejects_connection_without_client_cert322--- PASS: TestFilterOversizedClosures (0.00s)323 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)324 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)325 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)326=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert327=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA328=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA329=== RUN TestSetClientTLS/preserves_debug_logging_transport330=== PAUSE TestSetClientTLS/preserves_debug_logging_transport3312026/10/27 08:54:47 WARN Rate limiter enabled after throttle name=server-test rate=53322026/10/27 08:54:47 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:39627333=== RUN TestSetClientTLSErrors/missing_key_file3342026/10/27 08:54:47 WARN Rate limiter backed off name=server-test rate=5335=== PAUSE TestSetClientTLSErrors/missing_key_file336=== RUN TestSetClientTLSErrors/missing_ca_file337=== PAUSE TestSetClientTLSErrors/missing_ca_file338=== RUN TestSetClientTLSErrors/invalid_ca_file339=== PAUSE TestSetClientTLSErrors/invalid_ca_file340=== CONT TestGetStorePathHash/valid_store_path341=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error342=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error343=== CONT TestGetStorePathHash/basename_without_hyphen_should_error344=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)345--- PASS: TestGetStorePathHash (0.00s)346 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)347 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)348 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)349 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)350=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512351=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI352=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon353=== CONT TestSupersededNARStillUploadsListing/small_NAR354--- PASS: TestPathInfoHashCompatibility (0.04s)355 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)356 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)357 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)358 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)359=== CONT TestPartSizeForNAR/zero_stays_at_minimum360=== CONT TestPartSizeForNAR/capped_at_5_GiB361=== CONT TestPartSizeForNAR/5_TiB_S3_max_object362=== CONT TestPartSizeForNAR/1_TiB363=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts364=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum365=== CONT TestPartSizeForNAR/small_stays_at_minimum366--- PASS: TestPartSizeForNAR (0.07s)367 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)368 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)369 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)370 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)371 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)372 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)373 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)374=== CONT TestSetClientTLS/rejects_connection_without_client_cert375=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive376--- PASS: TestPathInfoCACompatibility (0.00s)377 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)378 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)379 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)380 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)381 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)382=== RUN TestParsePathInfoJSON/empty_input383=== PAUSE TestParsePathInfoJSON/empty_input384=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths385=== RUN TestParsePathInfoJSON/whitespace_only386=== PAUSE TestParsePathInfoJSON/whitespace_only387=== RUN TestParsePathInfoJSON/invalid_JSON388=== PAUSE TestParsePathInfoJSON/invalid_JSON389=== CONT TestSetClientTLSErrors/missing_cert_file3902026/10/27 08:54:47 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:448833912026/10/27 08:54:47 INFO Uploading abc-hello (1.0GB)3922026/10/27 08:54:47 WARN Rate limiter enabled after throttle name=server-test rate=5393=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths394=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths395=== CONT TestSupersededNARStillUploadsListing/dump_cut_short3962026/10/27 08:54:47 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:468453972026/10/27 08:54:47 INFO Garbage collection started398=== CONT TestSetClientTLSErrors/invalid_ca_file3992026/10/27 08:54:47 WARN Rate limiter backed off name=server-test rate=5400=== CONT TestUploadMultipart_SupersededByPeer/exists401=== CONT TestSetClientTLSErrors/missing_key_file402=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails403=== CONT TestSetClientTLS/preserves_debug_logging_transport404--- PASS: TestStreamPushBatchesUnderLoad (0.00s)405 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)406 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.04s)407=== CONT TestParsePathInfoJSON/Nix_format408=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA409=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths410=== CONT TestParsePathInfoJSON/invalid_JSON411=== CONT TestParsePathInfoJSON/whitespace_only412=== CONT TestParsePathInfoJSON/empty_input413=== CONT TestParsePathInfoJSON/Lix_format414--- PASS: TestParsePathInfoJSON (0.07s)415 --- PASS: TestParsePathInfoJSON/Nix_format (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: TestRateLimiterFeedback (0.01s)421 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)422 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)423 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)424 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)4252026/10/27 08:54:47 INFO Uploading abc-hello (1.0GB)4262026/10/27 08:54:47 INFO Garbage collection started4272026/10/27 08:54:47 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=0428=== CONT TestUploadMultipart_SupersededByPeer/missing4292026/10/27 08:54:47 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:448834302026/10/27 08:54:47 WARN Garbage collection finished on another replica. Its statistics are not available here431=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths432=== CONT TestSetClientTLSErrors/missing_ca_file4332026/10/27 08:54:47 WARN Rate limiter enabled after throttle name=s3-test rate=54342026/10/27 08:54:47 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:45865435--- PASS: TestSetClientTLSErrors (0.07s)436 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)437 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)438 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)439 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)440--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.22s)441--- PASS: TestParsePathInfoJSONMultiplePaths (0.07s)442 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)443 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)444--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.25s)4452026/10/27 08:54:47 http: TLS handshake error from 127.0.0.1:37758: remote error: tls: bad certificate446--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.22s)4472026/10/27 08:54:47 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:44883448--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)449 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)450 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.18s)4512026/10/27 08:54:47 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:44883452--- PASS: TestCaseHackSuffix (0.22s)453--- PASS: TestSetClientTLS (0.07s)454 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.18s)455 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.18s)456 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.19s)4572026/10/27 08:54:47 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:448834582026/10/27 08:54:47 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:44883459--- PASS: TestStreamPushRequestLine (0.26s)4602026/10/27 08:54:47 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:448834612026/10/27 08:54:47 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:448834622026/10/27 08:54:47 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:44883463--- PASS: TestRegisterUploadedObjectReusesConnections (0.24s)4642026/10/27 08:54:47 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:448834652026/10/27 08:54:47 WARN Rate limiter enabled after throttle name=s3-test rate=54662026/10/27 08:54:47 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:448834672026/10/27 08:54:47 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:448834682026/10/27 08:54:47 INFO Uploading abc-hello (1.0GB)4692026/10/27 08:54:47 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:448834702026/10/27 08:54:47 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:448834712026/10/27 08:54:47 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:448834722026/10/27 08:54:47 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:44883473--- PASS: TestDumpPathWriterError (0.28s)4742026/10/27 08:54:47 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:44883475--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.28s)4762026/10/27 08:54:47 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:33699/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:33699/part/2477--- PASS: TestDumpPathMatchesNix (0.31s)4782026/10/27 08:54:47 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:33699/part/3\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:33699/part/34792026/10/27 08:54:47 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:33699/part/4\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:33699/part/44802026/10/27 08:54:47 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"481--- PASS: TestSupersededNARStillUploadsListing (0.07s)482 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.19s)483 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.19s)484 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.72s)485--- PASS: TestUploadMultipart_FailedPartBufferNotReused (0.82s)486--- PASS: TestUploadMultipart_PartsInParallel (0.82s)4872026/10/27 08:54:48 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:39453/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:39453/api/uploads/complete4882026/10/27 08:54:48 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4892026/10/27 08:54:48 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:39453/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:39453/api/uploads/complete4902026/10/27 08:54:48 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4912026/10/27 08:54:48 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:39453/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:39453/api/uploads/complete4922026/10/27 08:54:48 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"493--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)494--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.04s)495PASS496Running server tests...497The files belonging to this database system will be owned by user "nixbld".498This user must also own the server process.499500The database cluster will be initialized with locale "C".501The default database encoding has accordingly been set to "SQL_ASCII".502The default text search configuration will be set to "english".503504Data page checksums are enabled.505506creating directory /build/postgres2391826750/data ... ok507creating subdirectories ... ok508selecting dynamic shared memory implementation ... posix509selecting default "max_connections" ... 100510selecting default "shared_buffers" ... 128MB511selecting default time zone ... UTC512creating configuration files ... ok513running bootstrap script ... ok514performing post-bootstrap initialization ... ok515syncing data to disk ... ok516517initdb: warning: enabling "trust" authentication for local connections518initdb: 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.519520Success. You can now start the database server using:521522 pg_ctl -D /build/postgres2391826750/data -l logfile start523524/build/postgres2391826750:5432 - no response5252026-10-27 08:54:49.350 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit5262026-10-27 08:54:49.351 UTC [129] LOG: listening on Unix socket "/build/postgres2391826750/.s.PGSQL.5432"5272026-10-27 08:54:49.355 UTC [136] LOG: database system was shut down at 2026-10-27 08:54:49 UTC5282026-10-27 08:54:49.358 UTC [129] LOG: database system is ready to accept connections529/build/postgres2391826750:5432 - accepting connections530{"timestamp":"2026-10-27T08:54:49.549900187Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"698cebb9-b305-48d5-9d3c-18bd8c67da51","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":1,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(41)"}531=== RUN TestService_AuthMiddleware532=== PAUSE TestService_AuthMiddleware533=== RUN TestService_AuthMiddleware_MTLSProxyHeader534=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader535=== RUN TestService_AuthMiddleware_MTLSBoundSubjects536=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects537=== RUN TestService_ReadAuthMiddleware538=== PAUSE TestService_ReadAuthMiddleware539=== RUN TestService_AuthMiddleware_OIDC540=== PAUSE TestService_AuthMiddleware_OIDC541=== RUN TestService_RequireScope_OIDC542=== PAUSE TestService_RequireScope_OIDC543=== RUN TestService_ReadScope_PublicByDefault544=== PAUSE TestService_ReadScope_PublicByDefault545=== RUN TestCacheConfigHandler546=== PAUSE TestCacheConfigHandler547=== RUN TestCacheStatsHandler548=== PAUSE TestCacheStatsHandler549=== RUN TestClientCADerivations550=== PAUSE TestClientCADerivations551=== RUN TestClientErrorHandling552=== PAUSE TestClientErrorHandling553=== RUN TestClientIntegration554=== PAUSE TestClientIntegration555=== RUN TestClientMultipleUploads556=== PAUSE TestClientMultipleUploads557=== RUN TestClientWithDependencies558=== PAUSE TestClientWithDependencies559=== RUN TestClientSharedPathCommittedMidPush560=== PAUSE TestClientSharedPathCommittedMidPush561=== RUN TestPinProtectsFromGC562=== PAUSE TestPinProtectsFromGC563=== RUN TestClientPushesUseOnePush564=== PAUSE TestClientPushesUseOnePush565=== RUN TestClientFallsBackToClosures566=== PAUSE TestClientFallsBackToClosures567=== RUN TestDeleteClosuresRacingPins568=== PAUSE TestDeleteClosuresRacingPins569=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock570=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock571=== RUN TestResolveDBConnectionString572=== PAUSE TestResolveDBConnectionString573=== RUN TestConnectWaitsForAPeerMigration574=== PAUSE TestConnectWaitsForAPeerMigration575=== RUN TestLeadElectsOneAndHandsOver576=== PAUSE TestLeadElectsOneAndHandsOver577=== RUN TestLeadIncumbentWinsAfterRestart5782026/10/27 08:54:49 INFO lead: acquired remote=192.0.2.1:12345792026/10/27 08:54:50 INFO lead: released remote=192.0.2.1:12345802026/10/27 08:54:50 INFO lead: acquired remote=192.0.2.1:12345812026/10/27 08:54:51 INFO lead: released remote=192.0.2.1:1234582--- PASS: TestLeadIncumbentWinsAfterRestart (1.86s)583=== RUN TestLeadIncumbentAnnouncesAtOnce584=== PAUSE TestLeadIncumbentAnnouncesAtOnce585=== RUN TestLeadEndsOnShutdown586=== PAUSE TestLeadEndsOnShutdown587=== RUN TestLeadEndsWhenItsConnectionHangs5882026/10/27 08:54:51 INFO lead: acquired remote=192.0.2.1:12345892026-10-27 08:54:53.021 UTC [216] FATAL: terminating connection due to administrator command5902026/10/27 08:54:53 INFO lead: acquired remote=192.0.2.1:12345912026/10/27 08:54:54 WARN lead: lock connection lost error="timeout: context deadline exceeded"5922026/10/27 08:54:54 INFO lead: released remote=192.0.2.1:12345932026/10/27 08:54:54 INFO lead: released remote=192.0.2.1:1234594--- PASS: TestLeadEndsWhenItsConnectionHangs (3.11s)595=== RUN TestGCAdvisoryLockBlocksConcurrentRun596=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun597=== RUN TestGCBugBareHashReferences598=== PAUSE TestGCBugBareHashReferences599=== RUN TestGCMetrics600=== PAUSE TestGCMetrics601=== RUN TestPushDedupSurvivesConcurrentGC602=== PAUSE TestPushDedupSurvivesConcurrentGC603=== RUN TestDeduplicatedObjectsRecordedAsPending604=== PAUSE TestDeduplicatedObjectsRecordedAsPending605=== RUN TestGCSweepSkipsPendingObjects606=== PAUSE TestGCSweepSkipsPendingObjects607=== RUN TestTombstonedObjectOfferedWithoutWaiting608=== PAUSE TestTombstonedObjectOfferedWithoutWaiting609=== RUN TestGCSweepDeliversEachKeyOnce610=== PAUSE TestGCSweepDeliversEachKeyOnce611=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection612=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection613=== RUN TestForceGCDuringPushOffersSweptObject614=== PAUSE TestForceGCDuringPushOffersSweptObject615=== RUN TestFailedS3DeleteKeepsTombstone616=== PAUSE TestFailedS3DeleteKeepsTombstone617=== RUN TestSweepSkipsRowsLockedByPush618=== PAUSE TestSweepSkipsRowsLockedByPush619=== RUN TestRegisterCompletedObjectNeedsPendingRow620=== PAUSE TestRegisterCompletedObjectNeedsPendingRow621=== RUN TestGetExistingObjectsLocksRows622=== PAUSE TestGetExistingObjectsLocksRows623=== RUN TestSweepRechecksPendingAfterLocking624=== PAUSE TestSweepRechecksPendingAfterLocking625=== RUN TestPushWaitsForSweepHoldingRow626=== PAUSE TestPushWaitsForSweepHoldingRow627=== RUN TestCommitRacingPendingCleanupKeepsObjects628=== PAUSE TestCommitRacingPendingCleanupKeepsObjects629=== RUN TestGCEndsOnShutdown630=== PAUSE TestGCEndsOnShutdown631=== RUN TestGCTaskStore_StartNew632=== PAUSE TestGCTaskStore_StartNew633=== RUN TestGCTaskStore_DeduplicateSameParams634=== PAUSE TestGCTaskStore_DeduplicateSameParams635=== RUN TestGCTaskStore_ConflictDifferentParams636=== PAUSE TestGCTaskStore_ConflictDifferentParams637=== RUN TestGCTaskStore_GetEmpty638=== PAUSE TestGCTaskStore_GetEmpty639=== RUN TestGCTaskStore_GetReturnsLatest640=== PAUSE TestGCTaskStore_GetReturnsLatest641=== RUN TestGCTaskStore_CompletedAllowsNewTask642=== PAUSE TestGCTaskStore_CompletedAllowsNewTask643=== RUN TestGCTaskStore_PhaseUpdates644=== PAUSE TestGCTaskStore_PhaseUpdates645=== RUN TestGCTaskStore_Fail646=== PAUSE TestGCTaskStore_Fail647=== RUN TestGracefulShutdownDrainsInflight648=== PAUSE TestGracefulShutdownDrainsInflight649=== RUN TestService_healthCheckHandler650=== PAUSE TestService_healthCheckHandler651=== RUN TestService_readinessHandler652=== PAUSE TestService_readinessHandler653=== RUN TestGenerateLandingPage654=== PAUSE TestGenerateLandingPage655=== RUN TestCacheConfigHandlerMaxNarSize656=== PAUSE TestCacheConfigHandlerMaxNarSize657=== RUN TestCreatePendingClosureRejectsOversizedNAR658=== PAUSE TestCreatePendingClosureRejectsOversizedNAR659=== RUN TestNARDeduplicationMetadataUploadBug660=== PAUSE TestNARDeduplicationMetadataUploadBug661=== RUN TestMetricsInventory662=== PAUSE TestMetricsInventory663=== RUN TestMetricsCommit664=== PAUSE TestMetricsCommit665=== RUN TestService_NativeMTLS666=== PAUSE TestService_NativeMTLS667=== RUN TestServerTLSConfig668=== PAUSE TestServerTLSConfig669=== RUN TestMultipartCleanup670=== PAUSE TestMultipartCleanup671=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded672=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded673=== RUN TestPendingCleanupUsesOneCutoff674=== PAUSE TestPendingCleanupUsesOneCutoff675=== RUN TestObjectStatsTrigger676=== PAUSE TestObjectStatsTrigger677=== RUN TestObjectStatsUpdatedOncePerCommit678=== PAUSE TestObjectStatsUpdatedOncePerCommit679=== RUN TestOrphanedObjectsGC680=== PAUSE TestOrphanedObjectsGC681=== RUN TestOrphanedObjectsGCStressTest682=== PAUSE TestOrphanedObjectsGCStressTest683=== RUN TestCreatePin_ReservedPins684=== PAUSE TestCreatePin_ReservedPins685=== RUN TestPresentReportsOnlyClosureRoots686=== PAUSE TestPresentReportsOnlyClosureRoots687=== RUN TestPresentRefreshesOnlyStaleClosures688=== PAUSE TestPresentRefreshesOnlyStaleClosures689=== RUN TestPresentNotReportedWhileGCDeletesClosure690=== PAUSE TestPresentNotReportedWhileGCDeletesClosure691=== RUN TestParseSingleRange692=== PAUSE TestParseSingleRange693=== RUN TestProxyHeadersOnlyTrustedOnSocket6942026/10/27 08:54:54 INFO Starting HTTP server address=127.0.0.1:373116952026/10/27 08:54:54 INFO Starting HTTP server address=proxy.sock6962026/10/27 08:54:54 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6972026/10/27 08:54:54 INFO Shutdown signal received, draining in-flight requests timeout=10s698--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.09s)699=== RUN TestIsValidCachePath700=== PAUSE TestIsValidCachePath701=== RUN TestReadProxyNarinfo702=== PAUSE TestReadProxyNarinfo703=== RUN TestReadProxyNarinfoAlreadyDecompressed704=== PAUSE TestReadProxyNarinfoAlreadyDecompressed705=== RUN TestReadProxyContentNegotiation706=== PAUSE TestReadProxyContentNegotiation707=== RUN TestReadProxyNarStreaming708=== PAUSE TestReadProxyNarStreaming709=== RUN TestReadProxy404710=== PAUSE TestReadProxy404711=== RUN TestReadProxyInvalidPath712=== PAUSE TestReadProxyInvalidPath713=== RUN TestReadProxyHead714=== PAUSE TestReadProxyHead715=== RUN TestReadProxyOutlastsServerWriteTimeout716=== PAUSE TestReadProxyOutlastsServerWriteTimeout717=== RUN TestReadProxyConditionalGet718=== PAUSE TestReadProxyConditionalGet719=== RUN TestReadProxyRootRedirectsToIndexHTML720=== PAUSE TestReadProxyRootRedirectsToIndexHTML721=== RUN TestReadProxyDisabled722=== PAUSE TestReadProxyDisabled723=== RUN TestReadRedirectNar724=== PAUSE TestReadRedirectNar725=== RUN TestReadRedirectKeepsNarinfoProxied726=== PAUSE TestReadRedirectKeepsNarinfoProxied727=== RUN TestReadProxyRangeRequest728=== PAUSE TestReadProxyRangeRequest729=== RUN TestReadRedirectUsesPublicS3URL730=== PAUSE TestReadRedirectUsesPublicS3URL731=== RUN TestPush_OverlappingRootsStoreOneRowPerKey732=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey733=== RUN TestPush_CompleteCommitsEveryRoot734=== PAUSE TestPush_CompleteCommitsEveryRoot735=== RUN TestPush_RepeatedRootCommitsOnce736=== PAUSE TestPush_RepeatedRootCommitsOnce737=== RUN TestPush_CompleteWaitsForCleanupOfThePush738=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush739=== RUN TestPush_RootsAreLockedInByteOrder740=== PAUSE TestPush_RootsAreLockedInByteOrder741=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit742=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit743=== RUN TestPush_RejectsBadRequests744=== PAUSE TestPush_RejectsBadRequests745=== RUN TestPush_SignsNarinfosOfItsPendingObjects746=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects747=== RUN TestRedundantMultipartUpload748=== PAUSE TestRedundantMultipartUpload749=== RUN TestCompleteMultipartUpload_ErrorButObjectExists750=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists751=== RUN TestCompletedNarNotReofferedAcrossClosures752=== PAUSE TestCompletedNarNotReofferedAcrossClosures753=== RUN TestPresignedUploadRegisteredBeforeCommit754=== PAUSE TestPresignedUploadRegisteredBeforeCommit755=== RUN TestService_Rustfstest756=== PAUSE TestService_Rustfstest757=== RUN TestParseSize758=== PAUSE TestParseSize759=== RUN TestSkippedUploadsHandler760=== PAUSE TestSkippedUploadsHandler761=== RUN TestSystemdListenerNotActivated762--- PASS: TestSystemdListenerNotActivated (0.00s)763=== RUN TestWatchdogBeatsWhenHealthy764--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)765=== RUN TestWatchdogSkipsWhenUnhealthy7662026/10/27 08:54:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7672026/10/27 08:54:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7682026/10/27 08:54:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7692026/10/27 08:54:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7702026/10/27 08:54:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7712026/10/27 08:54:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7722026/10/27 08:54:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7732026/10/27 08:54:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7742026/10/27 08:54:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7752026/10/27 08:54:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"776--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)777=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle778=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle779=== RUN TestProxyWriteTimeout780=== PAUSE TestProxyWriteTimeout781=== RUN TestPendingClosureWriteTimeout782=== PAUSE TestPendingClosureWriteTimeout783=== RUN TestIsValidUploadKey784=== PAUSE TestIsValidUploadKey785=== RUN TestUploadHandlersRejectInvalidKeys786=== PAUSE TestUploadHandlersRejectInvalidKeys787=== RUN TestUploadHandlersRejectOversizedBody788=== PAUSE TestUploadHandlersRejectOversizedBody789=== RUN TestService_cleanupPendingClosuresHandler790=== PAUSE TestService_cleanupPendingClosuresHandler791=== RUN TestService_createPendingClosureHandler792=== PAUSE TestService_createPendingClosureHandler793=== RUN TestService_verifyS3Integrity794=== PAUSE TestService_verifyS3Integrity795=== RUN TestCompleteMultipartUnregistered796=== PAUSE TestCompleteMultipartUnregistered797=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT798=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT799=== CONT TestService_AuthMiddleware800=== CONT TestService_createPendingClosureHandler801=== CONT TestReadProxyDisabled802=== CONT TestObjectStatsTrigger803=== CONT TestReadProxyNarinfo804=== CONT TestCacheConfigHandlerMaxNarSize805=== CONT TestService_NativeMTLS806=== CONT TestGCTaskStore_Fail807=== CONT TestReadProxy404808--- PASS: TestGCTaskStore_Fail (0.00s)809=== CONT TestGenerateLandingPage810=== CONT TestMetricsInventory811=== CONT TestGCTaskStore_DeduplicateSameParams812--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)813=== CONT TestReadProxyInvalidPath814=== CONT TestUploadHandlersRejectInvalidKeys815--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)816=== CONT TestIsValidUploadKey817=== CONT TestReadProxyNarStreaming818=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info819=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info820=== CONT TestCompleteMultipartUnregistered821=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal822=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal823=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key824=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key825=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key826=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key827=== CONT TestPendingClosureWriteTimeout828=== RUN TestPendingClosureWriteTimeout/empty829=== PAUSE TestPendingClosureWriteTimeout/empty830=== RUN TestPendingClosureWriteTimeout/400_objects831=== PAUSE TestPendingClosureWriteTimeout/400_objects832=== RUN TestPendingClosureWriteTimeout/670k_objects833=== PAUSE TestPendingClosureWriteTimeout/670k_objects834=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline835=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline836=== CONT TestService_verifyS3Integrity837=== CONT TestReadRedirectKeepsNarinfoProxied838=== CONT TestReadRedirectNar839=== CONT TestReadProxyOutlastsServerWriteTimeout840=== CONT TestReadProxyHead841=== CONT TestCompletedNarNotReofferedAcrossClosures842=== CONT TestService_cleanupPendingClosuresHandler843--- PASS: TestGenerateLandingPage (0.00s)844=== CONT TestProxyWriteTimeout845=== RUN TestProxyWriteTimeout/narinfo846=== CONT TestUploadHandlersRejectOversizedBody847=== CONT TestReadProxyRangeRequest848=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT849=== RUN TestIsValidUploadKey/narinfo850=== PAUSE TestIsValidUploadKey/narinfo851=== CONT TestReadProxyConditionalGet852=== PAUSE TestProxyWriteTimeout/narinfo853=== RUN TestIsValidUploadKey/nar_zst854=== PAUSE TestIsValidUploadKey/nar_zst855=== RUN TestProxyWriteTimeout/1_GiB_nar856=== PAUSE TestProxyWriteTimeout/1_GiB_nar857=== RUN TestIsValidUploadKey/nar_xz858=== PAUSE TestIsValidUploadKey/nar_xz859=== RUN TestProxyWriteTimeout/10_GiB_nar860=== RUN TestIsValidUploadKey/nar_plain861=== PAUSE TestProxyWriteTimeout/10_GiB_nar862=== RUN TestProxyWriteTimeout/unknown_size863=== PAUSE TestIsValidUploadKey/nar_plain864=== RUN TestIsValidUploadKey/listing865=== PAUSE TestProxyWriteTimeout/unknown_size866=== PAUSE TestIsValidUploadKey/listing867=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle868=== RUN TestIsValidUploadKey/build_log869=== PAUSE TestIsValidUploadKey/build_log870=== RUN TestIsValidUploadKey/build_log_home-manager_file871=== PAUSE TestIsValidUploadKey/build_log_home-manager_file872=== RUN TestIsValidUploadKey/build_log_plus_in_name873=== PAUSE TestIsValidUploadKey/build_log_plus_in_name874=== RUN TestIsValidUploadKey/build_log_question_mark875=== PAUSE TestIsValidUploadKey/build_log_question_mark876=== RUN TestIsValidUploadKey/build_log_equals877=== PAUSE TestIsValidUploadKey/build_log_equals878=== RUN TestIsValidUploadKey/realisation879=== PAUSE TestIsValidUploadKey/realisation880=== RUN TestIsValidUploadKey/realisation_plus_in_output881=== PAUSE TestIsValidUploadKey/realisation_plus_in_output882=== RUN TestIsValidUploadKey/nix-cache-info883=== PAUSE TestIsValidUploadKey/nix-cache-info884=== RUN TestIsValidUploadKey/index.html885=== PAUSE TestIsValidUploadKey/index.html886=== RUN TestIsValidUploadKey/narinfo_key,_nar_type887=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type888=== RUN TestIsValidUploadKey/nar_key,_narinfo_type889=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type890=== RUN TestIsValidUploadKey/listing_key,_narinfo_type891=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type892=== RUN TestIsValidUploadKey/traversal893=== PAUSE TestIsValidUploadKey/traversal894=== RUN TestIsValidUploadKey/traversal_nar895=== PAUSE TestIsValidUploadKey/traversal_nar896=== RUN TestIsValidUploadKey/absolute897=== PAUSE TestIsValidUploadKey/absolute898=== RUN TestIsValidUploadKey/empty_key899=== PAUSE TestIsValidUploadKey/empty_key900=== RUN TestIsValidUploadKey/unknown_type901=== PAUSE TestIsValidUploadKey/unknown_type902=== CONT TestReadProxyRootRedirectsToIndexHTML903=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure904=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure905=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart906=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart907=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts908=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts909=== CONT TestSkippedUploadsHandler9102026/10/27 08:54:55 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000911--- PASS: TestSkippedUploadsHandler (0.00s)912=== CONT TestParseSize913--- PASS: TestParseSize (0.00s)914=== CONT TestNARDeduplicationMetadataUploadBug915--- PASS: TestReadProxyInvalidPath (0.36s)916=== CONT TestService_Rustfstest9172026/10/27 08:54:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9182026/10/27 08:54:55 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst919--- PASS: TestCompleteMultipartUnregistered (0.39s)920=== CONT TestReadProxyContentNegotiation921--- PASS: TestMetricsInventory (0.44s)922=== CONT TestPresignedUploadRegisteredBeforeCommit9232026/10/27 08:54:55 INFO Received uploads request method=POST path=/api/pending_closures9242026/10/27 08:54:55 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>925--- PASS: TestReadProxyNarinfo (0.48s)926=== CONT TestCreatePendingClosureRejectsOversizedNAR9272026/10/27 08:54:55 INFO Received uploads request method=POST path=/api/pending_closures928--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)929=== CONT TestReadProxyNarinfoAlreadyDecompressed930--- PASS: TestObjectStatsTrigger (0.51s)931=== CONT TestService_readinessHandler932--- PASS: TestReadProxy404 (0.51s)933=== CONT TestService_healthCheckHandler9342026/10/27 08:54:55 WARN mTLS auth: subject not in bound subjects subject="CN=reader"9352026/10/27 08:54:55 WARN mTLS auth: subject not in bound subjects subject="CN=reader"936--- PASS: TestService_NativeMTLS (0.53s)937=== CONT TestMetricsCommit9382026/10/27 08:54:55 INFO Received cleanup request method=DELETE path=/api/pending_closures9392026/10/27 08:54:55 INFO Aborted multipart uploads count=0 kept=09402026/10/27 08:54:55 INFO Received uploads request method=POST path=/api/pending_closures9412026/10/27 08:54:55 INFO Received cleanup request method=DELETE path=/api/pending_closures9422026/10/27 08:54:55 INFO Aborted multipart uploads count=1 kept=09432026/10/27 08:54:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9442026-10-27 08:54:55.513 UTC [298] ERROR: Closure does not exist: id=19452026-10-27 08:54:55.513 UTC [298] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9462026-10-27 08:54:55.513 UTC [298] STATEMENT: -- name: CommitPendingClosure :one947 SELECT commit_pending_closure($1::bigint)::bigint948 949--- PASS: TestService_cleanupPendingClosuresHandler (0.57s)950=== CONT TestLeadElectsOneAndHandsOver9512026/10/27 08:54:55 INFO Received uploads request method=POST path=/api/pending_closures9522026/10/27 08:54:55 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"953--- PASS: TestService_AuthMiddleware (0.61s)954=== CONT TestGCTaskStore_GetReturnsLatest955--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)956=== CONT TestGCTaskStore_StartNew957--- PASS: TestGCTaskStore_StartNew (0.00s)958=== CONT TestGCTaskStore_PhaseUpdates959--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)960=== CONT TestGCEndsOnShutdown961=== RUN TestGCEndsOnShutdown/before_the_run962=== PAUSE TestGCEndsOnShutdown/before_the_run963=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete964=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete965=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark966=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark967=== CONT TestGCTaskStore_CompletedAllowsNewTask968--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)969=== CONT TestCommitRacingPendingCleanupKeepsObjects970--- PASS: TestReadRedirectNar (0.64s)971=== CONT TestGracefulShutdownDrainsInflight9722026/10/27 08:54:55 INFO Starting HTTP server address=127.0.0.1:371399732026/10/27 08:54:55 INFO Shutdown signal received, draining in-flight requests timeout=10s974--- PASS: TestReadRedirectKeepsNarinfoProxied (0.67s)975=== CONT TestPushWaitsForSweepHoldingRow976--- PASS: TestReadProxyDisabled (0.68s)977=== CONT TestClientIntegration9782026/10/27 08:54:55 INFO Received uploads request method=POST path=/api/pending_closures979--- PASS: TestGracefulShutdownDrainsInflight (0.07s)980=== CONT TestSweepRechecksPendingAfterLocking981--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.71s)982=== CONT TestConnectWaitsForAPeerMigration9832026/10/27 08:54:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete984--- PASS: TestReadProxyNarStreaming (0.75s)985=== CONT TestGetExistingObjectsLocksRows9862026/10/27 08:54:55 INFO Received uploads request method=POST path=/api/pending_closures9872026/10/27 08:54:55 INFO Received uploads request method=POST path=/api/pending_closures9882026/10/27 08:54:55 INFO Received uploads request method=POST path=/api/pending_closures9892026/10/27 08:54:55 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MGRmNzExMzktYWFiOC00ZWFhLTg0MDgtYWQ3NzExYTVlY2Y1LmQ1OTg3NmMwLTQ2ZmUtNGVlNS1iOTlhLTg5MDI1ZDAyZGYwZngxNzkzMDkxMjk1NDEwNjY4NzEx parts=109902026/10/27 08:54:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9912026/10/27 08:54:55 INFO Completed upload id=1 objects=2 duration=8.266347ms9922026/10/27 08:54:55 INFO Received uploads request method=POST path=/api/pending_closures9932026/10/27 08:54:55 INFO Received uploads request method=POST path=/api/pending_closures9942026/10/27 08:54:55 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9952026/10/27 08:54:55 WARN Found objects in DB but missing from S3, will re-upload count=1996--- PASS: TestService_verifyS3Integrity (0.79s)997=== CONT TestResolveDBConnectionString998=== RUN TestResolveDBConnectionString/flag_wins999=== PAUSE TestResolveDBConnectionString/flag_wins1000=== RUN TestResolveDBConnectionString/file_when_flag_empty1001=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1002=== RUN TestResolveDBConnectionString/missing_file_is_an_error1003=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1004=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1005=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1006=== RUN TestResolveDBConnectionString/nothing_configured1007=== PAUSE TestResolveDBConnectionString/nothing_configured1008=== CONT TestRegisterCompletedObjectNeedsPendingRow1009--- PASS: TestReadProxyConditionalGet (0.81s)1010=== CONT TestSweepSkipsRowsLockedByPush10112026/10/27 08:54:55 INFO Received uploads request method=POST path=/api/pending_closures1012--- PASS: TestReadProxyHead (0.88s)1013=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock10142026/10/27 08:54:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1015--- PASS: TestReadProxyRangeRequest (1.02s)1016=== CONT TestFailedS3DeleteKeepsTombstone10172026/10/27 08:54:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10182026/10/27 08:54:55 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MGRmNzExMzktYWFiOC00ZWFhLTg0MDgtYWQ3NzExYTVlY2Y1LjZkNDU1ZDg4LTNiZjQtNDY4YS05Y2VhLTA1MTEyYTk0YmU2OHgxNzkzMDkxMjk1NTI0NTIxODA4 parts=1210192026/10/27 08:54:55 INFO Received uploads request method=POST path=/api/pending_closures1020--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.06s)1021=== CONT TestDeleteClosuresRacingPins1022--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.01s)1023=== CONT TestClientFallsBackToClosures1024=== NAME TestNARDeduplicationMetadataUploadBug1025 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2081756021/001/store/11h2w8pw9flrk1xqx2k1431qf6alvspa-file1.txt1026--- PASS: TestService_Rustfstest (0.75s)1027=== CONT TestClientPushesUseOnePush10282026/10/27 08:54:56 INFO Received uploads request method=POST path=/api/pending_closures10292026/10/27 08:54:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10302026/10/27 08:54:56 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10312026/10/27 08:54:56 INFO Received uploads request method=POST path=/api/pending_closures1032--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.74s)1033=== CONT TestPinProtectsFromGC10342026/10/27 08:54:56 INFO Received push request method=POST path=/api/pushes1035--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.70s)1036=== CONT TestForceGCDuringPushOffersSweptObject1037=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1038=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1039=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1040=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1041=== CONT TestClientSharedPathCommittedMidPush10422026/10/27 08:54:56 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10432026/10/27 08:54:56 INFO Uploading 11h2w8pw9flrk1xqx2k1431qf6alvspa-file1.txt (160B)10442026/10/27 08:54:56 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MGRmNzExMzktYWFiOC00ZWFhLTg0MDgtYWQ3NzExYTVlY2Y1LmQxY2JmNDNhLTliZTItNDFmNi1hNzI0LTRmY2ZiNGNkMTIxOHgxNzkzMDkxMjk1NzE0NTgxODg4 parts=1010452026/10/27 08:54:56 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10462026/10/27 08:54:56 WARN Failed to register uploaded object key=11h2w8pw9flrk1xqx2k1431qf6alvspa.ls error="server returned 404: 404 page not found\n"10472026/10/27 08:54:56 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"10482026/10/27 08:54:56 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1049--- PASS: TestReadProxyContentNegotiation (0.81s)1050=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10512026/10/27 08:54:56 INFO Signed narinfos id=1 count=110522026/10/27 08:54:56 INFO Uploading 1 narinfos10532026/10/27 08:54:56 INFO Completed upload id=1 objects=2 duration=3.438658ms10542026/10/27 08:54:56 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010552026/10/27 08:54:56 INFO Received uploads request method=POST path=/api/pending_closures10562026/10/27 08:54:56 INFO Received complete push request method=POST path=/api/pushes/1/complete10572026/10/27 08:54:56 WARN Failed to register uploaded object key=11h2w8pw9flrk1xqx2k1431qf6alvspa.narinfo error="server returned 404: 404 page not found\n"10582026/10/27 08:54:56 INFO Starting cleanup of old closures method=DELETE path=/api/closures10592026/10/27 08:54:56 INFO Completed push id=1 objects=3 duration=5.341693ms10602026/10/27 08:54:56 INFO Upload complete. (67ms)10612026/10/27 08:54:56 WARN readiness check failed error="closed pool"1062--- PASS: TestService_readinessHandler (0.70s)1063=== CONT TestClientWithDependencies10642026/10/27 08:54:56 INFO Aborted multipart uploads count=0 kept=01065=== NAME TestNARDeduplicationMetadataUploadBug1066 metadata_upload_test.go:54: Retrieved narinfo from S3:1067 StorePath: /build/TestNARDeduplicationMetadataUploadBug2081756021/001/store/11h2w8pw9flrk1xqx2k1431qf6alvspa-file1.txt1068 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1069 Compression: zstd1070 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1071 NarSize: 1601072 References: 1073 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1074 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1075 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1076 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}10772026/10/27 08:54:56 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=010782026/10/27 08:54:56 INFO Vacuumed table table=pending_closures1079--- PASS: TestService_healthCheckHandler (0.72s)1080=== CONT TestGCSweepDeliversEachKeyOnce10812026/10/27 08:54:56 INFO Vacuumed table table=pending_objects10822026/10/27 08:54:56 INFO Vacuumed table table=multipart_uploads10832026/10/27 08:54:56 INFO Vacuumed table table=closures10842026/10/27 08:54:56 INFO Vacuumed table table=objects1085=== NAME TestNARDeduplicationMetadataUploadBug1086 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2081756021/001/store/y2m7z466063ygmmq3m3mfv2pph7byqix-file2.txt10872026/10/27 08:54:56 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001088--- PASS: TestService_createPendingClosureHandler (1.25s)1089=== CONT TestClientMultipleUploads10902026/10/27 08:54:56 INFO Received push request method=POST path=/api/pushes10912026/10/27 08:54:56 INFO lead: acquired remote=192.0.2.1:123410922026/10/27 08:54:56 INFO Received complete push request method=POST path=/api/pushes/1/complete10932026/10/27 08:54:56 INFO Completed push id=1 objects=4 duration=10.090021ms10942026/10/27 08:54:56 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10952026/10/27 08:54:56 INFO Completed upload id=2 objects=2 duration=1.936745ms1096--- PASS: TestMetricsCommit (0.76s)1097=== CONT TestTombstonedObjectOfferedWithoutWaiting10982026/10/27 08:54:56 INFO Received push request method=POST path=/api/pushes10992026/10/27 08:54:56 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11002026/10/27 08:54:56 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11012026/10/27 08:54:56 WARN Failed to register uploaded object key=y2m7z466063ygmmq3m3mfv2pph7byqix.ls error="server returned 404: 404 page not found\n"11022026/10/27 08:54:56 INFO Signed narinfos id=2 count=111032026/10/27 08:54:56 INFO Uploading 1 narinfos11042026/10/27 08:54:56 INFO Received uploads request method=POST path=/api/pending_closures11052026/10/27 08:54:56 INFO Received complete push request method=POST path=/api/pushes/2/complete11062026/10/27 08:54:56 WARN Failed to register uploaded object key=y2m7z466063ygmmq3m3mfv2pph7byqix.narinfo error="server returned 404: 404 page not found\n"11072026/10/27 08:54:56 INFO Aborted multipart uploads count=0 kept=011082026/10/27 08:54:56 INFO Completed push id=2 objects=3 duration=1.938895ms11092026/10/27 08:54:56 INFO Upload complete. (49ms)1110=== NAME TestNARDeduplicationMetadataUploadBug1111 metadata_upload_test.go:76: Retrieved narinfo from S3:1112 StorePath: /build/TestNARDeduplicationMetadataUploadBug2081756021/001/store/y2m7z466063ygmmq3m3mfv2pph7byqix-file2.txt1113 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1114 Compression: zstd1115 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1116 NarSize: 1601117 References: 1118 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1119 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1120 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1121 {"version":1,"root":{"type":"regular","size":44}}11222026/10/27 08:54:56 WARN Force mode enabled - objects will be deleted immediately without grace period1123--- PASS: TestNARDeduplicationMetadataUploadBug (1.18s)1124=== CONT TestGCSweepSkipsPendingObjects11252026/10/27 08:54:56 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011262026/10/27 08:54:56 INFO Vacuumed table table=pending_closures11272026/10/27 08:54:56 INFO Vacuumed table table=pending_objects11282026/10/27 08:54:56 INFO Vacuumed table table=multipart_uploads11292026/10/27 08:54:56 INFO Vacuumed table table=closures11302026/10/27 08:54:56 INFO Vacuumed table table=objects1131--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.75s)1132=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded11332026/10/27 08:54:56 INFO Aborted multipart uploads count=0 kept=011342026/10/27 08:54:56 WARN Force mode enabled - objects will be deleted immediately without grace period1135=== NAME TestClientIntegration1136 client_integration_test.go:291: Created store path: /build/TestClientIntegration3186173876/002/store/q49y5414x2nwc42if4whynl0wl1pwlgw-test-file.txt11372026/10/27 08:54:56 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011382026/10/27 08:54:56 INFO Vacuumed table table=pending_closures11392026/10/27 08:54:56 INFO Vacuumed table table=pending_objects11402026/10/27 08:54:56 INFO Vacuumed table table=multipart_uploads11412026/10/27 08:54:56 INFO Vacuumed table table=closures1142--- PASS: TestGetExistingObjectsLocksRows (0.65s)1143=== CONT TestDeduplicatedObjectsRecordedAsPending11442026/10/27 08:54:56 INFO Vacuumed table table=objects1145--- PASS: TestSweepRechecksPendingAfterLocking (0.69s)1146=== CONT TestPendingCleanupUsesOneCutoff1147--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.61s)1148=== CONT TestPushDedupSurvivesConcurrentGC11492026/10/27 08:54:56 INFO Aborted multipart uploads count=0 kept=011502026/10/27 08:54:56 WARN Force mode enabled - objects will be deleted immediately without grace period11512026/10/27 08:54:56 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011522026/10/27 08:54:56 INFO Vacuumed table table=pending_closures11532026/10/27 08:54:56 INFO Vacuumed table table=pending_objects11542026/10/27 08:54:56 INFO Received push request method=POST path=/api/pushes11552026/10/27 08:54:56 INFO Vacuumed table table=multipart_uploads11562026/10/27 08:54:56 INFO Vacuumed table table=closures11572026/10/27 08:54:56 INFO Vacuumed table table=objects11582026/10/27 08:54:56 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11592026/10/27 08:54:56 INFO Uploading q49y5414x2nwc42if4whynl0wl1pwlgw-test-file.txt (152B)11602026/10/27 08:54:56 INFO Received uploads request method=POST path=/api/pending_closures11612026/10/27 08:54:56 INFO Aborted multipart uploads count=0 kept=011622026/10/27 08:54:56 WARN Failed to register uploaded object key=q49y5414x2nwc42if4whynl0wl1pwlgw.ls error="server returned 404: 404 page not found\n"11632026/10/27 08:54:56 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11642026/10/27 08:54:56 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"11652026/10/27 08:54:56 INFO Signed narinfos id=1 count=111662026/10/27 08:54:56 INFO Uploading 1 narinfos11672026/10/27 08:54:56 WARN Force mode enabled - objects will be deleted immediately without grace period11682026/10/27 08:54:56 INFO Received complete push request method=POST path=/api/pushes/1/complete11692026/10/27 08:54:56 WARN Failed to register uploaded object key=q49y5414x2nwc42if4whynl0wl1pwlgw.narinfo error="server returned 404: 404 page not found\n"11702026/10/27 08:54:56 INFO Completed push id=1 objects=3 duration=4.276494ms11712026/10/27 08:54:56 INFO Upload complete. (61ms)11722026/10/27 08:54:56 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=1 objects-failed-to-delete=011732026/10/27 08:54:56 INFO Vacuumed table table=pending_closures11742026/10/27 08:54:56 INFO Vacuumed table table=pending_objects11752026/10/27 08:54:56 INFO Vacuumed table table=multipart_uploads11762026/10/27 08:54:56 INFO Vacuumed table table=closures11772026/10/27 08:54:56 INFO Vacuumed table table=objects1178--- PASS: TestSweepSkipsRowsLockedByPush (0.68s)1179=== CONT TestGCMetrics11802026/10/27 08:54:56 INFO All 1 paths already cached1181=== NAME TestClientIntegration1182 client_integration_test.go:317: Retrieved narinfo from S3:1183 StorePath: /build/TestClientIntegration3186173876/002/store/q49y5414x2nwc42if4whynl0wl1pwlgw-test-file.txt1184 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1185 Compression: zstd1186 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11187 NarSize: 1521188 References: 1189 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11190 client_integration_test.go:318: Retrieved .ls file from S3 (compressed size: 77 bytes)1191 client_integration_test.go:318: Decompressed .ls content (64 bytes):1192 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}11932026/10/27 08:54:56 INFO Received uploads request method=POST path=/api/pending_closures11942026/10/27 08:54:56 INFO Received uploads request method=POST path=/api/pending_closures11952026/10/27 08:54:56 INFO Received cleanup request method=DELETE path=/api/pending_closures11962026/10/27 08:54:56 INFO Aborted multipart uploads count=0 kept=011972026/10/27 08:54:56 WARN Force mode enabled - objects will be deleted immediately without grace period11982026/10/27 08:54:56 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."11992026/10/27 08:54:56 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1200--- PASS: TestFailedS3DeleteKeepsTombstone (0.54s)1201=== CONT TestService_ReadScope_PublicByDefault12022026/10/27 08:54:56 INFO Received push request method=POST path=/api/pushes12032026/10/27 08:54:56 INFO Object in database but missing from S3 key=q49y5414x2nwc42if4whynl0wl1pwlgw.ls12042026/10/27 08:54:56 WARN Found objects in DB but missing from S3, will re-upload count=112052026/10/27 08:54:56 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12062026/10/27 08:54:56 INFO Received complete push request method=POST path=/api/pushes/2/complete12072026/10/27 08:54:56 WARN Failed to register uploaded object key=q49y5414x2nwc42if4whynl0wl1pwlgw.ls error="server returned 404: 404 page not found\n"12082026/10/27 08:54:56 INFO Completed push id=2 objects=3 duration=2.658982ms12092026/10/27 08:54:56 INFO Upload complete. (47ms)1210=== NAME TestClientIntegration1211 client_integration_test.go:335: Retrieved .ls file from S3 (compressed size: 62 bytes)1212 client_integration_test.go:335: Decompressed .ls content (49 bytes):1213 {"version":1,"root":{"type":"regular","size":39}}12142026/10/27 08:54:56 INFO Received uploads request method=POST path=/api/pending_closures1215--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.76s)1216=== CONT TestGCBugBareHashReferences1217=== NAME TestPinProtectsFromGC1218 client_integration_test.go:778: Pinned store path: /build/TestPinProtectsFromGC4184140075/001/store/93paqgqj39w2ximcm48cxsr8i3k3m4px-pinned-file.txt1219 client_integration_test.go:779: Unpinned store path: /build/TestPinProtectsFromGC4184140075/001/store/1mdwi1lhsqj5199ira9pw7m0w83z473j-unpinned-file.txt12202026/10/27 08:54:56 INFO Received uploads request method=POST path=/api/pending_closures12212026/10/27 08:54:56 INFO Received uploads request method=POST path=/api/pending_closures12222026/10/27 08:54:56 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12232026/10/27 08:54:56 INFO Uploading 9a23bza0zk0g066i3gid71iyb6njafb2-a (216B)12242026/10/27 08:54:56 INFO Uploading 40s04vvf4zpm5h9ydm9s30r9a5krgrvh-shared-dep (136B)12252026/10/27 08:54:56 INFO Received push request method=POST path=/api/pushes12262026/10/27 08:54:56 WARN Failed to register uploaded object key=nar/0rqq9d36dr8hgrfkrzn2b5rdcnjk9a7f7dl3j0jcdrshyjlss1c5.nar.zst error="server returned 404: 404 page not found\n"12272026/10/27 08:54:56 WARN Failed to register uploaded object key=b7gnybmaaf3m2674kaqda6fnvlgrzh8k.ls error="server returned 404: 404 page not found\n"12282026/10/27 08:54:56 WARN Failed to register uploaded object key=9a23bza0zk0g066i3gid71iyb6njafb2.ls error="server returned 404: 404 page not found\n"12292026/10/27 08:54:56 INFO Aborted multipart uploads count=0 kept=012302026/10/27 08:54:56 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12312026/10/27 08:54:56 WARN Failed to register uploaded object key=40s04vvf4zpm5h9ydm9s30r9a5krgrvh.ls error="server returned 404: 404 page not found\n"12322026/10/27 08:54:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12332026/10/27 08:54:56 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12342026/10/27 08:54:56 INFO Signed narinfos id=1 count=212352026/10/27 08:54:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12362026/10/27 08:54:56 INFO Signed narinfos id=2 count=212372026/10/27 08:54:56 INFO Uploading 4 narinfos12382026/10/27 08:54:56 INFO Received complete push request method=POST path=/api/pushes/3/complete12392026/10/27 08:54:56 WARN Failed to register uploaded object key=q49y5414x2nwc42if4whynl0wl1pwlgw.ls error="server returned 404: 404 page not found\n"12402026/10/27 08:54:56 WARN Force mode enabled - objects will be deleted immediately without grace period12412026/10/27 08:54:56 INFO Completed push id=3 objects=3 duration=2.49461ms12422026/10/27 08:54:56 WARN Failed to register uploaded object key=b7gnybmaaf3m2674kaqda6fnvlgrzh8k.narinfo error="server returned 404: 404 page not found\n"12432026/10/27 08:54:56 WARN Failed to register uploaded object key=40s04vvf4zpm5h9ydm9s30r9a5krgrvh.narinfo error="server returned 404: 404 page not found\n"12442026/10/27 08:54:56 INFO Upload complete. (49ms)12452026/10/27 08:54:56 WARN Failed to register uploaded object key=9a23bza0zk0g066i3gid71iyb6njafb2.narinfo error="server returned 404: 404 page not found\n"1246=== NAME TestClientIntegration1247 client_integration_test.go:352: Retrieved .ls file from S3 (compressed size: 62 bytes)1248 client_integration_test.go:352: Decompressed .ls content (49 bytes):1249 {"version":1,"root":{"type":"regular","size":39}}1250 client_integration_test.go:363: Testing garbage collection...12512026/10/27 08:54:56 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12522026/10/27 08:54:56 WARN Failed to register uploaded object key=40s04vvf4zpm5h9ydm9s30r9a5krgrvh.narinfo error="server returned 404: 404 page not found\n"12532026/10/27 08:54:56 INFO Completed upload id=1 objects=6 duration=4.650057ms12542026/10/27 08:54:56 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12552026/10/27 08:54:56 INFO Completed upload id=2 objects=6 duration=878.567µs12562026/10/27 08:54:56 INFO Upload complete. (69ms)12572026/10/27 08:54:56 INFO Received push request method=POST path=/api/pushes12582026/10/27 08:54:56 INFO Received push request method=POST path=/api/pushes1259=== NAME TestClientFallsBackToClosures1260 client_pushes_test.go:112: Retrieved narinfo from S3:1261 StorePath: /build/TestClientFallsBackToClosures2746697058/001/store/40s04vvf4zpm5h9ydm9s30r9a5krgrvh-shared-dep1262 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1263 Compression: zstd1264 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821265 NarSize: 1361266 References: 1267 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n12682026/10/27 08:54:56 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12692026/10/27 08:54:56 INFO Uploading 93paqgqj39w2ximcm48cxsr8i3k3m4px-pinned-file.txt (128B)1270 client_pushes_test.go:112: Retrieved narinfo from S3:1271 StorePath: /build/TestClientFallsBackToClosures2746697058/001/store/9a23bza0zk0g066i3gid71iyb6njafb2-a1272 URL: nar/0rqq9d36dr8hgrfkrzn2b5rdcnjk9a7f7dl3j0jcdrshyjlss1c5.nar.zst1273 Compression: zstd1274 NarHash: sha256:0rqq9d36dr8hgrfkrzn2b5rdcnjk9a7f7dl3j0jcdrshyjlss1c51275 NarSize: 2161276 References: /build/TestClientFallsBackToClosures2746697058/001/store/40s04vvf4zpm5h9ydm9s30r9a5krgrvh-shared-dep1277 CA: text:sha256:012fpaqawmm4z579y2gx8kcbhvm03z8486b7317p4rsmgxyb6yqp12782026/10/27 08:54:56 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12792026/10/27 08:54:56 INFO Uploading zab6azg7slscw8jfdfsg0vrvz5pqppn5-b (216B)12802026/10/27 08:54:56 INFO Uploading a6xqnvvcfjv73vnr60v73sizy24hb59k-shared-dep (136B)1281 client_pushes_test.go:112: Retrieved narinfo from S3:1282 StorePath: /build/TestClientFallsBackToClosures2746697058/001/store/b7gnybmaaf3m2674kaqda6fnvlgrzh8k-b1283 URL: nar/0rqq9d36dr8hgrfkrzn2b5rdcnjk9a7f7dl3j0jcdrshyjlss1c5.nar.zst1284 Compression: zstd1285 NarHash: sha256:0rqq9d36dr8hgrfkrzn2b5rdcnjk9a7f7dl3j0jcdrshyjlss1c51286 NarSize: 2161287 References: /build/TestClientFallsBackToClosures2746697058/001/store/40s04vvf4zpm5h9ydm9s30r9a5krgrvh-shared-dep1288 CA: text:sha256:012fpaqawmm4z579y2gx8kcbhvm03z8486b7317p4rsmgxyb6yqp12892026/10/27 08:54:56 INFO Received uploads request method=POST path=/api/pending_closures1290--- PASS: TestClientFallsBackToClosures (0.64s)1291=== CONT TestClientErrorHandling1292=== RUN TestClientErrorHandling/InvalidStorePath1293=== PAUSE TestClientErrorHandling/InvalidStorePath1294=== RUN TestClientErrorHandling/InvalidAuthToken1295=== PAUSE TestClientErrorHandling/InvalidAuthToken1296=== RUN TestClientErrorHandling/ServerNotAvailable1297=== PAUSE TestClientErrorHandling/ServerNotAvailable1298=== CONT TestGCAdvisoryLockBlocksConcurrentRun12992026/10/27 08:54:56 WARN Failed to register uploaded object key=93paqgqj39w2ximcm48cxsr8i3k3m4px.ls error="server returned 404: 404 page not found\n"13002026/10/27 08:54:56 WARN Failed to register uploaded object key=zab6azg7slscw8jfdfsg0vrvz5pqppn5.ls error="server returned 404: 404 page not found\n"13012026/10/27 08:54:56 WARN Failed to register uploaded object key=nar/0njs66f4ci5975qas9mfhv5b19xdg3g2b0y0j7skj5and92x4wsg.nar.zst error="server returned 404: 404 page not found\n"13022026/10/27 08:54:56 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"13032026/10/27 08:54:56 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13042026/10/27 08:54:56 WARN Failed to register uploaded object key=b8yl35myv4x712lvs9b8iwzz4d8b61ay.ls error="server returned 404: 404 page not found\n"13052026/10/27 08:54:56 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13062026/10/27 08:54:56 INFO Signed narinfos id=1 count=11307--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.43s)1308=== CONT TestClientCADerivations13092026/10/27 08:54:56 INFO Uploading 1 narinfos13102026/10/27 08:54:56 WARN Failed to register uploaded object key=a6xqnvvcfjv73vnr60v73sizy24hb59k.ls error="server returned 404: 404 page not found\n"13112026/10/27 08:54:56 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13122026/10/27 08:54:56 INFO Signed narinfos id=1 count=313132026/10/27 08:54:56 INFO Uploading 3 narinfos1314=== NAME TestClientWithDependencies1315 client_integration_test.go:660: Built derivation: /build/TestClientWithDependencies3027868240/001/store/3ymp61llfyb1l3wsxfsfc7hvw7f5nlmx-test-script13162026/10/27 08:54:56 INFO Received complete push request method=POST path=/api/pushes/1/complete13172026/10/27 08:54:56 WARN Failed to register uploaded object key=b8yl35myv4x712lvs9b8iwzz4d8b61ay.narinfo error="server returned 404: 404 page not found\n"13182026/10/27 08:54:56 WARN Failed to register uploaded object key=93paqgqj39w2ximcm48cxsr8i3k3m4px.narinfo error="server returned 404: 404 page not found\n"13192026/10/27 08:54:56 WARN Failed to register uploaded object key=a6xqnvvcfjv73vnr60v73sizy24hb59k.narinfo error="server returned 404: 404 page not found\n"13202026/10/27 08:54:56 INFO Received complete push request method=POST path=/api/pushes/1/complete13212026/10/27 08:54:56 WARN Failed to register uploaded object key=zab6azg7slscw8jfdfsg0vrvz5pqppn5.narinfo error="server returned 404: 404 page not found\n"13222026/10/27 08:54:56 INFO Completed push id=1 objects=3 duration=5.199932ms13232026/10/27 08:54:56 INFO Upload complete. (64ms)13242026/10/27 08:54:56 INFO Starting cleanup of old closures method=DELETE path=/api/closures13252026/10/27 08:54:56 INFO Garbage collection started13262026/10/27 08:54:56 INFO Completed push id=1 objects=8 duration=6.986156ms13272026/10/27 08:54:56 INFO Upload complete. (61ms)1328=== NAME TestClientPushesUseOnePush1329 client_pushes_test.go:97: Retrieved narinfo from S3:1330 StorePath: /build/TestClientPushesUseOnePush2670094627/001/store/a6xqnvvcfjv73vnr60v73sizy24hb59k-shared-dep1331 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1332 Compression: zstd1333 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821334 NarSize: 1361335 References: 1336 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n13372026/10/27 08:54:56 INFO Received push request method=POST path=/api/pushes1338=== NAME TestClientMultipleUploads1339 client_integration_test.go:405: Created store path 0: /build/TestClientMultipleUploads1892964784/001/store/4as2a6qa0k4c3my3wsa44mjwd71ra584-test-file-0.txt1340=== NAME TestClientPushesUseOnePush1341 client_pushes_test.go:97: Retrieved narinfo from S3:1342 StorePath: /build/TestClientPushesUseOnePush2670094627/001/store/b8yl35myv4x712lvs9b8iwzz4d8b61ay-a1343 URL: nar/0njs66f4ci5975qas9mfhv5b19xdg3g2b0y0j7skj5and92x4wsg.nar.zst1344 Compression: zstd1345 NarHash: sha256:0njs66f4ci5975qas9mfhv5b19xdg3g2b0y0j7skj5and92x4wsg1346 NarSize: 2161347 References: /build/TestClientPushesUseOnePush2670094627/001/store/a6xqnvvcfjv73vnr60v73sizy24hb59k-shared-dep1348 CA: text:sha256:1al133gb4nm39wwrzr5z56z07m64s7lihr4hzq4kv8ywbgylcscs13492026/10/27 08:54:56 INFO Aborted multipart uploads count=0 kept=013502026/10/27 08:54:56 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=013512026/10/27 08:54:56 INFO Vacuumed table table=pending_closures13522026/10/27 08:54:56 INFO Vacuumed table table=pending_objects13532026/10/27 08:54:56 INFO Vacuumed table table=multipart_uploads1354 client_pushes_test.go:97: Retrieved narinfo from S3:1355 StorePath: /build/TestClientPushesUseOnePush2670094627/001/store/zab6azg7slscw8jfdfsg0vrvz5pqppn5-b1356 URL: nar/0njs66f4ci5975qas9mfhv5b19xdg3g2b0y0j7skj5and92x4wsg.nar.zst1357 Compression: zstd1358 NarHash: sha256:0njs66f4ci5975qas9mfhv5b19xdg3g2b0y0j7skj5and92x4wsg1359 NarSize: 2161360 References: /build/TestClientPushesUseOnePush2670094627/001/store/a6xqnvvcfjv73vnr60v73sizy24hb59k-shared-dep1361 CA: text:sha256:1al133gb4nm39wwrzr5z56z07m64s7lihr4hzq4kv8ywbgylcscs13622026/10/27 08:54:56 INFO Vacuumed table table=closures1363--- PASS: TestClientPushesUseOnePush (0.65s)1364=== CONT TestLeadEndsOnShutdown13652026/10/27 08:54:56 WARN Force mode enabled - objects will be deleted immediately without grace period13662026/10/27 08:54:56 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)13672026/10/27 08:54:56 INFO Uploading ikxdra31gfardhgpvckqr4w3zj0y6ssj-shared-dep (136B)13682026/10/27 08:54:56 INFO Uploading 7mfbk3z95virjl0vjy8lbym2c8vblgp0-top (224B)13692026/10/27 08:54:56 INFO Received uploads request method=POST path=/api/pending_closures13702026/10/27 08:54:56 INFO Vacuumed table table=objects1371--- PASS: TestGCSweepDeliversEachKeyOnce (0.54s)1372=== CONT TestCacheStatsHandler13732026/10/27 08:54:56 WARN Failed to register uploaded object key=7mfbk3z95virjl0vjy8lbym2c8vblgp0.ls error="server returned 404: 404 page not found\n"1374=== NAME TestClientWithDependencies1375 client_integration_test.go:662: Found 1 dependencies (including self)13762026/10/27 08:54:56 WARN Failed to register uploaded object key=ikxdra31gfardhgpvckqr4w3zj0y6ssj.ls error="server returned 404: 404 page not found\n"13772026/10/27 08:54:56 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13782026/10/27 08:54:56 WARN Failed to register uploaded object key=nar/15621gvd59cjy62npfik5b38i29crrripj21r37i4swcv3w9s2yg.nar.zst error="server returned 404: 404 page not found\n"13792026/10/27 08:54:56 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13802026/10/27 08:54:56 INFO Signed narinfos id=1 count=213812026/10/27 08:54:56 INFO Uploading 2 narinfos13822026/10/27 08:54:56 INFO Received complete push request method=POST path=/api/pushes/1/complete13832026/10/27 08:54:56 WARN Failed to register uploaded object key=7mfbk3z95virjl0vjy8lbym2c8vblgp0.narinfo error="server returned 404: 404 page not found\n"13842026/10/27 08:54:56 WARN Failed to register uploaded object key=ikxdra31gfardhgpvckqr4w3zj0y6ssj.narinfo error="server returned 404: 404 page not found\n"13852026/10/27 08:54:56 INFO Aborted multipart uploads count=0 kept=01386=== NAME TestClientMultipleUploads1387 client_integration_test.go:405: Created store path 1: /build/TestClientMultipleUploads1892964784/001/store/c8rc4kd38ibrs5ldkgbljq9wn2rzm3v6-test-file-1.txt13882026/10/27 08:54:56 WARN Force mode enabled - objects will be deleted immediately without grace period13892026/10/27 08:54:56 INFO Completed push id=1 objects=6 duration=9.281744ms13902026/10/27 08:54:56 INFO Upload complete. (81ms)1391=== NAME TestClientSharedPathCommittedMidPush1392 client_integration_test.go:727: Retrieved narinfo from S3:1393 StorePath: /build/TestClientSharedPathCommittedMidPush1530846028/001/store/ikxdra31gfardhgpvckqr4w3zj0y6ssj-shared-dep1394 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1395 Compression: zstd1396 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821397 NarSize: 1361398 References: 1399 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n14002026/10/27 08:54:56 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=014012026/10/27 08:54:56 INFO Received uploads request method=POST path=/api/pending_closures1402 client_integration_test.go:727: Retrieved narinfo from S3:1403 StorePath: /build/TestClientSharedPathCommittedMidPush1530846028/001/store/7mfbk3z95virjl0vjy8lbym2c8vblgp0-top1404 URL: nar/15621gvd59cjy62npfik5b38i29crrripj21r37i4swcv3w9s2yg.nar.zst1405 Compression: zstd1406 NarHash: sha256:15621gvd59cjy62npfik5b38i29crrripj21r37i4swcv3w9s2yg1407 NarSize: 2241408 References: /build/TestClientSharedPathCommittedMidPush1530846028/001/store/ikxdra31gfardhgpvckqr4w3zj0y6ssj-shared-dep1409 CA: text:sha256:03cfx4vg4x94xal3710hasavnv77z3rh3ybnm2afczfxqrfpghhl14102026/10/27 08:54:56 INFO Vacuumed table table=pending_closures14112026/10/27 08:54:56 INFO Vacuumed table table=pending_objects14122026/10/27 08:54:56 INFO Vacuumed table table=multipart_uploads1413--- PASS: TestClientSharedPathCommittedMidPush (0.61s)1414=== CONT TestLeadIncumbentAnnouncesAtOnce14152026/10/27 08:54:56 INFO Vacuumed table table=closures14162026/10/27 08:54:56 INFO Vacuumed table table=objects14172026/10/27 08:54:56 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=01418--- PASS: TestGCSweepSkipsPendingObjects (0.47s)1419=== CONT TestCacheConfigHandler1420=== RUN TestCacheConfigHandler/full_config,_no_issuer1421=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1422=== RUN TestCacheConfigHandler/no_cache_url_configured1423=== PAUSE TestCacheConfigHandler/no_cache_url_configured1424=== RUN TestCacheConfigHandler/no_signing_keys1425=== PAUSE TestCacheConfigHandler/no_signing_keys1426=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1427=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1428=== CONT TestService_ReadAuthMiddleware14292026/10/27 08:54:56 INFO Received push request method=POST path=/api/pushes14302026/10/27 08:54:56 INFO Vacuumed table table=pending_closures1431--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.46s)1432=== CONT TestGCTaskStore_GetEmpty1433--- PASS: TestGCTaskStore_GetEmpty (0.00s)1434=== CONT TestService_RequireScope_OIDC14352026/10/27 08:54:56 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14362026/10/27 08:54:56 INFO Uploading 1mdwi1lhsqj5199ira9pw7m0w83z473j-unpinned-file.txt (128B)14372026/10/27 08:54:56 INFO Vacuumed table table=pending_objects14382026/10/27 08:54:56 INFO Vacuumed table table=multipart_uploads14392026/10/27 08:54:56 WARN Failed to register uploaded object key=1mdwi1lhsqj5199ira9pw7m0w83z473j.ls error="server returned 404: 404 page not found\n"14402026/10/27 08:54:56 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14412026/10/27 08:54:56 INFO Vacuumed table table=closures14422026/10/27 08:54:56 INFO Signed narinfos id=2 count=114432026/10/27 08:54:56 INFO Uploading 1 narinfos14442026/10/27 08:54:56 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"1445--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.64s)1446=== CONT TestService_AuthMiddleware_OIDC14472026/10/27 08:54:56 INFO Vacuumed table table=objects14482026/10/27 08:54:56 INFO Received complete push request method=POST path=/api/pushes/2/complete14492026/10/27 08:54:56 WARN Failed to register uploaded object key=1mdwi1lhsqj5199ira9pw7m0w83z473j.narinfo error="server returned 404: 404 page not found\n"1450=== NAME TestClientMultipleUploads1451 client_integration_test.go:405: Created store path 2: /build/TestClientMultipleUploads1892964784/001/store/cjmnpfi6qs0s8va5gzfjli1gh82fc9pj-test-file-2.txt14522026/10/27 08:54:56 INFO Received uploads request method=POST path=/api/pending_closures14532026/10/27 08:54:56 INFO Completed push id=2 objects=3 duration=8.68237ms14542026/10/27 08:54:56 INFO Upload complete. (67ms)1455--- PASS: TestPushWaitsForSweepHoldingRow (1.18s)1456=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1457--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.45s)1458=== CONT TestMultipartCleanup14592026/10/27 08:54:56 INFO Received push request method=POST path=/api/pushes14602026/10/27 08:54:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36831/oidc14612026/10/27 08:54:56 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14622026/10/27 08:54:56 INFO Uploading 3ymp61llfyb1l3wsxfsfc7hvw7f5nlmx-test-script (136B)14632026/10/27 08:54:56 WARN Failed to register uploaded object key=3ymp61llfyb1l3wsxfsfc7hvw7f5nlmx.ls error="server returned 404: 404 page not found\n"14642026/10/27 08:54:56 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"14652026/10/27 08:54:56 WARN Failed to register uploaded object key=log/40vmg64lm5qm43si0fj67nmsf7diqwgm-test-script.drv error="server returned 404: 404 page not found\n"14662026/10/27 08:54:56 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14672026/10/27 08:54:56 INFO Signed narinfos id=1 count=114682026/10/27 08:54:56 INFO Uploading 1 narinfos14692026/10/27 08:54:56 INFO Received complete push request method=POST path=/api/pushes/1/complete14702026/10/27 08:54:56 WARN Failed to register uploaded object key=3ymp61llfyb1l3wsxfsfc7hvw7f5nlmx.narinfo error="server returned 404: 404 page not found\n"14712026/10/27 08:54:56 INFO Completed push id=1 objects=4 duration=7.280808ms14722026/10/27 08:54:56 INFO Upload complete. (73ms)14732026/10/27 08:54:56 INFO Starting cleanup of old closures method=DELETE path=/api/closures14742026/10/27 08:54:56 INFO Garbage collection started1475=== NAME TestClientWithDependencies1476 client_integration_test.go:664: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3027868240/001/store) requires matching store prefix1477--- PASS: TestClientWithDependencies (0.68s)1478=== CONT TestPresentReportsOnlyClosureRoots14792026/10/27 08:54:56 INFO Received uploads request method=POST path=/api/pending_closures14802026/10/27 08:54:56 INFO Aborted multipart uploads count=0 kept=014812026/10/27 08:54:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46415/oidc14822026/10/27 08:54:56 WARN Force mode enabled - objects will be deleted immediately without grace period14832026/10/27 08:54:56 INFO Aborted multipart uploads count=0 kept=014842026/10/27 08:54:56 WARN Force mode enabled - objects will be deleted immediately without grace period14852026/10/27 08:54:56 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=014862026/10/27 08:54:56 INFO Vacuumed table table=pending_closures14872026/10/27 08:54:56 INFO Received push request method=POST path=/api/pushes14882026/10/27 08:54:56 INFO Vacuumed table table=pending_objects14892026/10/27 08:54:56 INFO Vacuumed table table=multipart_uploads14902026/10/27 08:54:56 INFO Vacuumed table table=closures14912026/10/27 08:54:56 INFO Vacuumed table table=objects1492--- PASS: TestGCMetrics (0.43s)1493=== CONT TestIsValidCachePath1494=== RUN TestIsValidCachePath/narinfo1495=== PAUSE TestIsValidCachePath/narinfo1496=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1497=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1498=== RUN TestIsValidCachePath/nar_zst1499=== PAUSE TestIsValidCachePath/nar_zst1500=== RUN TestIsValidCachePath/nar_xz1501=== PAUSE TestIsValidCachePath/nar_xz1502=== RUN TestIsValidCachePath/nar_bz21503=== PAUSE TestIsValidCachePath/nar_bz21504=== RUN TestIsValidCachePath/nar_uncompressed1505=== PAUSE TestIsValidCachePath/nar_uncompressed1506=== RUN TestIsValidCachePath/ls1507=== PAUSE TestIsValidCachePath/ls1508=== RUN TestIsValidCachePath/log1509=== PAUSE TestIsValidCachePath/log1510=== RUN TestIsValidCachePath/realisation1511=== PAUSE TestIsValidCachePath/realisation1512=== RUN TestIsValidCachePath/nix-cache-info1513=== PAUSE TestIsValidCachePath/nix-cache-info1514=== RUN TestIsValidCachePath/index.html1515=== PAUSE TestIsValidCachePath/index.html1516=== RUN TestIsValidCachePath/traversal_parent1517=== PAUSE TestIsValidCachePath/traversal_parent1518=== RUN TestIsValidCachePath/traversal_in_middle1519=== PAUSE TestIsValidCachePath/traversal_in_middle1520=== RUN TestIsValidCachePath/invalid_char_e1521=== PAUSE TestIsValidCachePath/invalid_char_e1522=== RUN TestIsValidCachePath/invalid_char_u1523=== PAUSE TestIsValidCachePath/invalid_char_u1524=== RUN TestIsValidCachePath/random_path1525=== PAUSE TestIsValidCachePath/random_path1526=== RUN TestIsValidCachePath/empty1527=== PAUSE TestIsValidCachePath/empty1528=== RUN TestIsValidCachePath/leading_slash1529=== PAUSE TestIsValidCachePath/leading_slash1530=== RUN TestIsValidCachePath/wrong_extension1531=== PAUSE TestIsValidCachePath/wrong_extension1532=== RUN TestIsValidCachePath/short_hash1533=== PAUSE TestIsValidCachePath/short_hash1534=== CONT TestPush_RootsAreLockedInByteOrder15352026/10/27 08:54:56 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15362026/10/27 08:54:56 INFO Uploading 4as2a6qa0k4c3my3wsa44mjwd71ra584-test-file-0.txt (160B)15372026/10/27 08:54:56 INFO Uploading c8rc4kd38ibrs5ldkgbljq9wn2rzm3v6-test-file-1.txt (160B)15382026/10/27 08:54:56 INFO Uploading cjmnpfi6qs0s8va5gzfjli1gh82fc9pj-test-file-2.txt (160B)1539--- PASS: TestService_ReadScope_PublicByDefault (0.37s)1540=== CONT TestCompleteMultipartUpload_ErrorButObjectExists15412026/10/27 08:54:56 WARN Failed to register uploaded object key=c8rc4kd38ibrs5ldkgbljq9wn2rzm3v6.ls error="server returned 404: 404 page not found\n"15422026/10/27 08:54:56 WARN Failed to register uploaded object key=4as2a6qa0k4c3my3wsa44mjwd71ra584.ls error="server returned 404: 404 page not found\n"15432026/10/27 08:54:56 WARN Failed to register uploaded object key=cjmnpfi6qs0s8va5gzfjli1gh82fc9pj.ls error="server returned 404: 404 page not found\n"15442026/10/27 08:54:56 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15452026/10/27 08:54:56 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15462026/10/27 08:54:56 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15472026/10/27 08:54:56 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15482026/10/27 08:54:56 INFO Signed narinfos id=1 count=315492026/10/27 08:54:56 INFO Uploading 3 narinfos15502026/10/27 08:54:56 WARN Failed to register uploaded object key=cjmnpfi6qs0s8va5gzfjli1gh82fc9pj.narinfo error="server returned 404: 404 page not found\n"15512026/10/27 08:54:56 WARN Failed to register uploaded object key=c8rc4kd38ibrs5ldkgbljq9wn2rzm3v6.narinfo error="server returned 404: 404 page not found\n"15522026/10/27 08:54:56 INFO Received complete push request method=POST path=/api/pushes/1/complete15532026/10/27 08:54:56 WARN Failed to register uploaded object key=4as2a6qa0k4c3my3wsa44mjwd71ra584.narinfo error="server returned 404: 404 page not found\n"15542026/10/27 08:54:56 INFO Completed push id=1 objects=9 duration=18.305018ms15552026/10/27 08:54:56 INFO Upload complete. (92ms)1556=== NAME TestClientMultipleUploads1557 client_integration_test.go:416: Uploaded 3 paths in 131.752241ms15582026/10/27 08:54:56 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=015592026/10/27 08:54:56 INFO Aborted multipart uploads count=0 kept=015602026/10/27 08:54:56 INFO Vacuumed table table=pending_closures1561--- PASS: TestClientMultipleUploads (0.73s)1562=== CONT TestParseSingleRange1563=== RUN TestParseSingleRange/none1564=== PAUSE TestParseSingleRange/none1565=== RUN TestParseSingleRange/unknown_unit1566=== PAUSE TestParseSingleRange/unknown_unit1567=== RUN TestParseSingleRange/multi-range_ignored1568=== PAUSE TestParseSingleRange/multi-range_ignored1569=== RUN TestParseSingleRange/malformed_no_dash1570=== PAUSE TestParseSingleRange/malformed_no_dash1571=== RUN TestParseSingleRange/malformed_both_empty1572=== PAUSE TestParseSingleRange/malformed_both_empty1573=== RUN TestParseSingleRange/malformed_end_before_start1574=== PAUSE TestParseSingleRange/malformed_end_before_start1575=== RUN TestParseSingleRange/closed1576=== PAUSE TestParseSingleRange/closed1577=== RUN TestParseSingleRange/open-ended1578=== PAUSE TestParseSingleRange/open-ended1579=== RUN TestParseSingleRange/end_clamped_to_size1580=== PAUSE TestParseSingleRange/end_clamped_to_size1581=== RUN TestParseSingleRange/suffix1582=== PAUSE TestParseSingleRange/suffix1583=== RUN TestParseSingleRange/suffix_exceeds_size1584=== PAUSE TestParseSingleRange/suffix_exceeds_size1585=== RUN TestParseSingleRange/single_byte1586=== PAUSE TestParseSingleRange/single_byte1587=== RUN TestParseSingleRange/start_past_EOF1588=== PAUSE TestParseSingleRange/start_past_EOF1589=== RUN TestParseSingleRange/start_far_past_EOF1590=== PAUSE TestParseSingleRange/start_far_past_EOF1591=== CONT TestRedundantMultipartUpload15922026/10/27 08:54:56 INFO Vacuumed table table=pending_objects15932026/10/27 08:54:56 INFO Vacuumed table table=multipart_uploads15942026/10/27 08:54:56 INFO Vacuumed table table=closures15952026/10/27 08:54:56 INFO Vacuumed table table=objects15962026/10/27 08:54:56 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=015972026/10/27 08:54:56 INFO Vacuumed table table=pending_closures15982026/10/27 08:54:56 INFO Vacuumed table table=pending_objects15992026/10/27 08:54:56 INFO Vacuumed table table=multipart_uploads16002026/10/27 08:54:56 INFO Vacuumed table table=closures16012026/10/27 08:54:56 INFO Vacuumed table table=objects16022026/10/27 08:54:56 INFO Aborted multipart uploads count=0 kept=016032026/10/27 08:54:56 WARN Force mode enabled - objects will be deleted immediately without grace period16042026/10/27 08:54:56 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"1605--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.28s)1606=== CONT TestPresentNotReportedWhileGCDeletesClosure1607=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1608=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1609=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1610=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1611=== CONT TestPush_SignsNarinfosOfItsPendingObjects16122026/10/27 08:54:56 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=016132026/10/27 08:54:56 INFO Vacuumed table table=pending_closures16142026/10/27 08:54:56 INFO Vacuumed table table=pending_objects16152026/10/27 08:54:56 INFO Vacuumed table table=multipart_uploads16162026/10/27 08:54:56 INFO Vacuumed table table=closures16172026/10/27 08:54:56 INFO Vacuumed table table=objects1618--- PASS: TestPushDedupSurvivesConcurrentGC (0.61s)1619=== CONT TestPresentRefreshesOnlyStaleClosures16202026/10/27 08:54:56 INFO lead: acquired remote=192.0.2.1:12341621--- PASS: TestCacheStatsHandler (0.32s)1622=== CONT TestPush_RejectsBadRequests16232026/10/27 08:54:57 INFO lead: acquired remote=192.0.2.1:123416242026/10/27 08:54:57 INFO lead: released remote=192.0.2.1:12341625--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.29s)1626=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1627--- PASS: TestService_ReadAuthMiddleware (0.30s)1628=== CONT TestOrphanedObjectsGCStressTest1629=== NAME TestClientCADerivations1630 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3475608654/001/store/bx6kwy1cwawlp882rnhw5cqhgg185czp-ca-test1631 client_ca_test.go:139: Found 1 dependencies (including self)1632--- PASS: TestGCBugBareHashReferences (0.60s)1633=== CONT TestServerTLSConfig1634=== RUN TestServerTLSConfig/no_client_CA1635=== PAUSE TestServerTLSConfig/no_client_CA1636=== RUN TestServerTLSConfig/missing_CA_file1637=== PAUSE TestServerTLSConfig/missing_CA_file1638=== RUN TestServerTLSConfig/not_a_PEM_file1639=== PAUSE TestServerTLSConfig/not_a_PEM_file1640=== CONT TestCreatePin_ReservedPins1641=== RUN TestService_RequireScope_OIDC/builder_may_write1642=== PAUSE TestService_RequireScope_OIDC/builder_may_write1643=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1644=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1645=== RUN TestService_RequireScope_OIDC/ops_may_admin1646=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1647=== RUN TestService_RequireScope_OIDC/ops_may_not_write1648=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1649=== RUN TestService_RequireScope_OIDC/reader_may_not_write1650=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1651=== RUN TestService_RequireScope_OIDC/static_token_may_admin1652=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1653=== RUN TestService_RequireScope_OIDC/static_token_may_write1654=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1655=== RUN TestService_RequireScope_OIDC/reader_may_read1656=== PAUSE TestService_RequireScope_OIDC/reader_may_read1657=== RUN TestService_RequireScope_OIDC/writer_implies_read1658=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1659=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1660=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1661=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1662=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1663=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1664=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1665=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1666=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1667=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1668=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1669=== CONT TestPush_CompleteCommitsEveryRoot16702026/10/27 08:54:57 INFO Received uploads request method=POST path=/api/pending_closures16712026/10/27 08:54:57 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16722026/10/27 08:54:57 WARN mTLS auth: bound subjects configured but subject DN unavailable16732026/10/27 08:54:57 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1674--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.48s)1675=== CONT TestPush_RepeatedRootCommitsOnce16762026/10/27 08:54:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32931/oidc16772026/10/27 08:54:57 INFO Received push request method=POST path=/api/pushes16782026/10/27 08:54:57 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16792026/10/27 08:54:57 INFO Uploading bx6kwy1cwawlp882rnhw5cqhgg185czp-ca-test (144B)1680--- PASS: TestPresentReportsOnlyClosureRoots (0.47s)1681=== CONT TestPush_CompleteWaitsForCleanupOfThePush16822026/10/27 08:54:57 WARN Failed to register uploaded object key=bx6kwy1cwawlp882rnhw5cqhgg185czp.ls error="server returned 404: 404 page not found\n"16832026/10/27 08:54:57 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16842026/10/27 08:54:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16852026/10/27 08:54:57 WARN Failed to register uploaded object key=log/7vx0zmrj7bmybnnxi1ygyx1iik2cjhr5-ca-test.drv error="server returned 404: 404 page not found\n"16862026/10/27 08:54:57 INFO Signed narinfos id=1 count=116872026/10/27 08:54:57 INFO Uploading 1 narinfos16882026/10/27 08:54:57 INFO Received complete push request method=POST path=/api/pushes/1/complete16892026/10/27 08:54:57 WARN Failed to register uploaded object key=bx6kwy1cwawlp882rnhw5cqhgg185czp.narinfo error="server returned 404: 404 page not found\n"1690=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1691=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1692=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1693=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1694=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1695=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1696=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1697=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1698=== CONT TestService_AuthMiddleware_MTLSProxyHeader16992026/10/27 08:54:57 INFO Completed push id=1 objects=4 duration=5.457664ms17002026/10/27 08:54:57 INFO Upload complete. (102ms)1701=== NAME TestClientCADerivations1702 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3475608654/001/store/bx6kwy1cwawlp882rnhw5cqhgg185czp-ca-test1703 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1704 Compression: zstd1705 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1706 NarSize: 1441707 References: 1708 Deriver: /build/TestClientCADerivations3475608654/001/store/7vx0zmrj7bmybnnxi1ygyx1iik2cjhr5-ca-test.drv1709 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1710 client_ca_test.go:185: Checking for realisation files in S3...1711 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1712 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache17132026/10/27 08:54:57 INFO Received push request method=POST path=/api/pushes17142026/10/27 08:54:57 INFO Received cleanup request method=DELETE path=/api/pending_closures17152026/10/27 08:54:57 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket70/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""17162026/10/27 08:54:57 INFO Aborted multipart uploads count=0 kept=117172026/10/27 08:54:57 INFO Received cleanup request method=DELETE path=/api/pending_closures17182026/10/27 08:54:57 INFO Aborted multipart uploads count=1 kept=01719--- PASS: TestMultipartCleanup (0.57s)1720=== CONT TestGCTaskStore_ConflictDifferentParams1721--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1722=== CONT TestOrphanedObjectsGC17232026/10/27 08:54:57 INFO Received uploads request method=POST path=/api/pending_closures17242026-10-27 08:54:57.372 UTC [1478] ERROR: could not obtain lock on row in relation "closures"17252026-10-27 08:54:57.372 UTC [1478] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT17262026-10-27 08:54:57.373 UTC [1478] ERROR: could not obtain lock on row in relation "closures"17272026-10-27 08:54:57.373 UTC [1478] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT17282026-10-27 08:54:57.374 UTC [1478] ERROR: could not obtain lock on row in relation "closures"17292026-10-27 08:54:57.374 UTC [1478] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT17302026-10-27 08:54:57.376 UTC [1478] ERROR: could not obtain lock on row in relation "closures"17312026-10-27 08:54:57.376 UTC [1478] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT17322026-10-27 08:54:57.376 UTC [1478] ERROR: could not obtain lock on row in relation "closures"17332026-10-27 08:54:57.376 UTC [1478] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1734--- PASS: TestPush_RootsAreLockedInByteOrder (0.52s)1735=== CONT TestPush_OverlappingRootsStoreOneRowPerKey17362026/10/27 08:54:57 INFO Received uploads request method=POST path=/api/pending_closures1737=== NAME TestClientCADerivations1738 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1739 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1740 error: binary cache 's3://bucket64?endpoint=http://localhost:40339®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3475608654/001/store'1741 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11742--- PASS: TestClientCADerivations (0.73s)1743=== CONT TestObjectStatsUpdatedOncePerCommit17442026/10/27 08:54:57 INFO Received uploads request method=POST path=/api/pending_closures17452026/10/27 08:54:57 INFO Received push request method=POST path=/api/pushes17462026/10/27 08:54:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17472026/10/27 08:54:57 INFO Signed narinfos id=1 count=117482026/10/27 08:54:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17492026/10/27 08:54:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17502026/10/27 08:54:57 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"17512026/10/27 08:54:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17522026/10/27 08:54:57 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"17532026/10/27 08:54:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17542026/10/27 08:54:57 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=117552026/10/27 08:54:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17562026/10/27 08:54:57 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1757--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.48s)1758=== CONT TestReadRedirectUsesPublicS3URL1759--- PASS: TestPresentRefreshesOnlyStaleClosures (0.50s)1760=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17612026/10/27 08:54:57 INFO Received uploads request method=POST path=/1762=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17632026/10/27 08:54:57 INFO Received complete multipart upload request method=POST path=/1764=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17652026/10/27 08:54:57 INFO Received request for more parts method=POST path=/1766=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17672026/10/27 08:54:57 INFO Received uploads request method=POST path=/1768--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1769 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1770 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1771 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1772 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1773=== CONT TestPendingClosureWriteTimeout/empty1774=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline17752026/10/27 08:54:57 INFO lead: released remote=192.0.2.1:12341776=== RUN TestPush_RejectsBadRequests/root_not_in_objects1777=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1778=== RUN TestPush_RejectsBadRequests/no_roots1779=== PAUSE TestPush_RejectsBadRequests/no_roots1780=== RUN TestPush_RejectsBadRequests/no_objects1781=== PAUSE TestPush_RejectsBadRequests/no_objects1782=== RUN TestPush_RejectsBadRequests/bad_root1783=== PAUSE TestPush_RejectsBadRequests/bad_root1784=== CONT TestPendingClosureWriteTimeout/670k_objects1785=== CONT TestPendingClosureWriteTimeout/400_objects1786=== CONT TestProxyWriteTimeout/narinfo1787=== CONT TestProxyWriteTimeout/unknown_size1788=== CONT TestProxyWriteTimeout/10_GiB_nar1789=== CONT TestProxyWriteTimeout/1_GiB_nar1790--- PASS: TestProxyWriteTimeout (0.00s)1791 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1792 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1793 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1794 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1795=== CONT TestIsValidUploadKey/narinfo1796=== CONT TestIsValidUploadKey/realisation_plus_in_output1797=== CONT TestIsValidUploadKey/unknown_type1798=== CONT TestIsValidUploadKey/empty_key1799=== CONT TestIsValidUploadKey/absolute1800=== CONT TestIsValidUploadKey/traversal_nar1801=== CONT TestIsValidUploadKey/traversal1802=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1803=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1804=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1805=== CONT TestIsValidUploadKey/index.html1806=== CONT TestIsValidUploadKey/nix-cache-info1807=== CONT TestIsValidUploadKey/build_log_home-manager_file1808=== CONT TestIsValidUploadKey/realisation1809=== CONT TestIsValidUploadKey/build_log_equals1810=== CONT TestIsValidUploadKey/build_log_question_mark1811=== CONT TestIsValidUploadKey/build_log_plus_in_name1812=== CONT TestIsValidUploadKey/nar_plain1813=== CONT TestIsValidUploadKey/listing1814=== CONT TestIsValidUploadKey/nar_xz1815=== CONT TestIsValidUploadKey/nar_zst1816=== CONT TestIsValidUploadKey/build_log1817--- PASS: TestIsValidUploadKey (0.08s)1818 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1819 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1820 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1821 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1822 --- PASS: TestIsValidUploadKey/absolute (0.00s)1823 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1824 --- PASS: TestIsValidUploadKey/traversal (0.00s)1825 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1826 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1827 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1828 --- PASS: TestIsValidUploadKey/index.html (0.00s)1829 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1830 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1831 --- PASS: TestIsValidUploadKey/realisation (0.00s)1832 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1833 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1834 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1835 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1836 --- PASS: TestIsValidUploadKey/listing (0.00s)1837 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1838 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1839 --- PASS: TestIsValidUploadKey/build_log (0.00s)1840=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18412026/10/27 08:54:57 INFO Received uploads request method=POST path=/18422026/10/27 08:54:57 INFO Received push request method=POST path=/api/pushes18432026/10/27 08:54:57 INFO lead: acquired remote=192.0.2.1:123418442026/10/27 08:54:57 INFO Received complete push request method=POST path=/api/pushes/1/complete18452026/10/27 08:54:57 INFO Completed push id=1 objects=4 duration=7.897814ms18462026/10/27 08:54:57 INFO Received push request method=POST path=/api/pushes18472026/10/27 08:54:57 INFO Received push request method=POST path=/api/pushes18482026/10/27 08:54:57 INFO Received complete push request method=POST path=/api/pushes/1/complete18492026/10/27 08:54:57 INFO Received push request method=POST path=/api/pushes18502026/10/27 08:54:57 INFO Completed push id=1 objects=6 duration=6.29503ms1851--- PASS: TestPush_CompleteCommitsEveryRoot (0.39s)1852=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18532026/10/27 08:54:57 INFO Received request for more parts method=POST path=/18542026/10/27 08:54:57 INFO Received complete push request method=POST path=/api/pushes/1/complete18552026/10/27 08:54:57 INFO Aborted multipart uploads count=0 kept=018562026/10/27 08:54:57 WARN Force mode enabled - objects will be deleted immediately without grace period18572026/10/27 08:54:57 INFO Completed push id=1 objects=4 duration=7.774512ms1858--- PASS: TestPush_RepeatedRootCommitsOnce (0.34s)1859=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18602026/10/27 08:54:57 INFO Received complete multipart upload request method=POST path=/18612026/10/27 08:54:57 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18622026/10/27 08:54:57 WARN Refused reserved pin name=worker-x86_64-linux18632026/10/27 08:54:57 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18642026/10/27 08:54:57 INFO Received create pin request method=POST path=/api/pins/my-app18652026/10/27 08:54:57 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1866--- PASS: TestCreatePin_ReservedPins (0.42s)1867=== CONT TestGCEndsOnShutdown/before_the_run18682026/10/27 08:54:57 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=018692026/10/27 08:54:57 INFO Vacuumed table table=pending_closures18702026/10/27 08:54:57 INFO Vacuumed table table=pending_objects18712026/10/27 08:54:57 INFO Vacuumed table table=multipart_uploads18722026/10/27 08:54:57 INFO Vacuumed table table=closures18732026/10/27 08:54:57 INFO Vacuumed table table=objects18742026/10/27 08:54:57 INFO Received complete push request method=POST path=/api/pushes/2/complete1875=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark18762026/10/27 08:54:57 INFO Completed push id=2 objects=4 duration=3.198456ms1877--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.59s)1878=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete18792026/10/27 08:54:57 INFO Received push request method=POST path=/api/pushes1880=== CONT TestResolveDBConnectionString/flag_wins1881=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1882=== CONT TestResolveDBConnectionString/nothing_configured1883=== CONT TestResolveDBConnectionString/missing_file_is_an_error1884=== CONT TestResolveDBConnectionString/file_when_flag_empty1885=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1886--- PASS: TestResolveDBConnectionString (0.00s)1887 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1888 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1889 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1890 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1891 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1892--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.34s)1893=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1894--- PASS: TestDeleteClosuresRacingPins (1.71s)1895=== CONT TestClientErrorHandling/InvalidStorePath18962026/10/27 08:54:57 INFO Received push request method=POST path=/api/pushes18972026/10/27 08:54:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18982026/10/27 08:54:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1899--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.35s)1900=== CONT TestClientErrorHandling/ServerNotAvailable19012026/10/27 08:54:57 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MGRmNzExMzktYWFiOC00ZWFhLTg0MDgtYWQ3NzExYTVlY2Y1LmEwZTlhYzE1LTY2MWEtNGFhMi1iM2MzLTQxMjBmYmQyMmU5OHgxNzkzMDkxMjk3MzY0NzM1Nzk219022026/10/27 08:54:57 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MGRmNzExMzktYWFiOC00ZWFhLTg0MDgtYWQ3NzExYTVlY2Y1LjcxODBlOWQ3LWIxMzktNGZiOS1hOTA5LTViNzc1NjE1ZWQ4NHgxNzkzMDkxMjk3Mzk1MTMzNzIw parts=1219032026/10/27 08:54:57 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MGRmNzExMzktYWFiOC00ZWFhLTg0MDgtYWQ3NzExYTVlY2Y1LmEwZTlhYzE1LTY2MWEtNGFhMi1iM2MzLTQxMjBmYmQyMmU5OHgxNzkzMDkxMjk3MzY0NzM1Nzk2 parts=119042026/10/27 08:54:57 INFO Received uploads request method=POST path=/api/pending_closures1905--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.88s)1906=== CONT TestClientErrorHandling/InvalidAuthToken19072026/10/27 08:54:57 INFO Received uploads request method=POST path=/api/pending_closures1908--- PASS: TestObjectStatsUpdatedOncePerCommit (0.37s)1909=== CONT TestCacheConfigHandler/full_config,_no_issuer1910=== CONT TestCacheConfigHandler/no_signing_keys1911=== CONT TestCacheConfigHandler/no_cache_url_configured1912=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1913--- PASS: TestCacheConfigHandler (0.00s)1914 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1915 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1916 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1917 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1918=== CONT TestIsValidCachePath/narinfo1919=== CONT TestIsValidCachePath/index.html1920=== CONT TestIsValidCachePath/short_hash1921=== CONT TestIsValidCachePath/wrong_extension1922=== CONT TestIsValidCachePath/leading_slash1923=== CONT TestIsValidCachePath/empty1924=== CONT TestIsValidCachePath/random_path1925=== CONT TestIsValidCachePath/invalid_char_u1926=== CONT TestIsValidCachePath/invalid_char_e1927=== CONT TestIsValidCachePath/traversal_in_middle1928=== CONT TestIsValidCachePath/traversal_parent1929=== CONT TestIsValidCachePath/nar_uncompressed1930=== CONT TestIsValidCachePath/nix-cache-info1931=== CONT TestIsValidCachePath/realisation1932=== CONT TestIsValidCachePath/log1933=== CONT TestIsValidCachePath/ls1934=== CONT TestIsValidCachePath/nar_xz1935=== CONT TestIsValidCachePath/nar_bz21936=== CONT TestIsValidCachePath/nar_zst1937=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1938--- PASS: TestIsValidCachePath (0.00s)1939 --- PASS: TestIsValidCachePath/narinfo (0.00s)1940 --- PASS: TestIsValidCachePath/index.html (0.00s)1941 --- PASS: TestIsValidCachePath/short_hash (0.00s)1942 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1943 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1944 --- PASS: TestIsValidCachePath/empty (0.00s)1945 --- PASS: TestIsValidCachePath/random_path (0.00s)1946 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1947 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1948 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1949 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1950 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1951 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1952 --- PASS: TestIsValidCachePath/realisation (0.00s)1953 --- PASS: TestIsValidCachePath/log (0.00s)1954 --- PASS: TestIsValidCachePath/ls (0.00s)1955 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1956 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1957 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1958 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1959=== CONT TestParseSingleRange/none1960=== CONT TestParseSingleRange/open-ended1961=== CONT TestParseSingleRange/start_far_past_EOF1962=== CONT TestParseSingleRange/start_past_EOF1963=== CONT TestParseSingleRange/single_byte1964=== CONT TestParseSingleRange/malformed_both_empty1965=== CONT TestParseSingleRange/closed1966=== CONT TestParseSingleRange/malformed_end_before_start1967=== CONT TestParseSingleRange/multi-range_ignored1968=== CONT TestParseSingleRange/malformed_no_dash1969=== CONT TestParseSingleRange/suffix1970=== CONT TestParseSingleRange/unknown_unit1971=== CONT TestParseSingleRange/suffix_exceeds_size1972=== CONT TestParseSingleRange/end_clamped_to_size1973--- PASS: TestParseSingleRange (0.00s)1974 --- PASS: TestParseSingleRange/none (0.00s)1975 --- PASS: TestParseSingleRange/open-ended (0.00s)1976 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1977 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1978 --- PASS: TestParseSingleRange/single_byte (0.00s)1979 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1980 --- PASS: TestParseSingleRange/closed (0.00s)1981 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1982 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1983 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1984 --- PASS: TestParseSingleRange/suffix (0.00s)1985 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1986 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1987 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1988=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1989--- PASS: TestReadRedirectUsesPublicS3URL (0.36s)1990=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh19912026/10/27 08:54:57 INFO Received uploads request method=POST path=/api/pending_closures19922026/10/27 08:54:57 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/present1993=== CONT TestServerTLSConfig/no_client_CA1994=== CONT TestService_RequireScope_OIDC/builder_may_write1995=== CONT TestService_RequireScope_OIDC/reader_may_read1996=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1997=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19982026/10/27 08:54:57 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]1999=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2000=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2001=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2002=== CONT TestService_RequireScope_OIDC/writer_implies_read2003=== CONT TestService_RequireScope_OIDC/reader_may_not_write2004=== CONT TestService_RequireScope_OIDC/static_token_may_write2005=== CONT TestService_RequireScope_OIDC/static_token_may_admin2006=== CONT TestServerTLSConfig/not_a_PEM_file2007=== CONT TestService_RequireScope_OIDC/ops_may_admin2008=== CONT TestService_RequireScope_OIDC/ops_may_not_write2009=== CONT TestServerTLSConfig/missing_CA_file2010--- PASS: TestServerTLSConfig (0.00s)2011 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2012 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2013 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2014=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2015=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2016--- PASS: TestService_RequireScope_OIDC (0.43s)2017 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2018 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2019 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2020 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2021 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2022 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2023 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2024 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2025 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2026 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2027 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2028 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2029 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2030 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2031=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20322026/10/27 08:54:57 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]2033=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2034=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20352026/10/27 08:54:57 WARN Authentication failed token_preview=eyJhbGciOi...WqwoaWIT_Q token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2036=== CONT TestPush_RejectsBadRequests/root_not_in_objects20372026/10/27 08:54:57 INFO Received push request method=POST path=/api/pushes2038=== CONT TestPush_RejectsBadRequests/no_objects20392026/10/27 08:54:57 INFO Received push request method=POST path=/api/pushes2040=== CONT TestPush_RejectsBadRequests/bad_root20412026/10/27 08:54:57 INFO Received push request method=POST path=/api/pushes2042=== CONT TestPush_RejectsBadRequests/no_roots20432026/10/27 08:54:57 INFO Received push request method=POST path=/api/pushes2044--- PASS: TestPush_RejectsBadRequests (0.45s)2045 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2046 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2047 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2048 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2049--- PASS: TestService_AuthMiddleware_OIDC (0.54s)2050 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2051 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2052 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2053 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)20542026/10/27 08:54:57 INFO Aborted multipart uploads count=0 kept=020552026/10/27 08:54:57 WARN Force mode enabled - objects will be deleted immediately without grace period20562026-10-27 08:54:57.868 UTC [1600] ERROR: canceling statement due to user request20572026-10-27 08:54:57.868 UTC [1600] CONTEXT: SQL statement "UPDATE object_stats s2058 SET object_count = s.object_count + n.n - o.n,2059 total_bytes = s.total_bytes + n.bytes - o.bytes2060 FROM (2061 SELECT count(*) AS n, coalesce(sum(size), 0) AS bytes2062 FROM new_rows WHERE deleted_at IS NULL2063 ) AS n,2064 (2065 SELECT count(*) AS n, coalesce(sum(size), 0) AS bytes2066 FROM old_rows WHERE deleted_at IS NULL2067 ) AS o2068 WHERE s.id AND (n.n <> o.n OR n.bytes <> o.bytes)"2069 PL/pgSQL function object_stats_update() line 3 at SQL statement20702026-10-27 08:54:57.868 UTC [1600] STATEMENT: -- name: MarkStaleObjects :execrows2071 WITH RECURSIVE ct AS (2072 SELECT timezone('UTC', now()) AS now2073 ),2074 closure_reach AS (2075 -- Start with all closure keys2076 SELECT o.key, o.refs2077 FROM objects o2078 INNER JOIN closures c ON o.key = c.key2079 UNION2080 -- Recursively add all referenced objects2081 SELECT o.key, o.refs2082 FROM objects o2083 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2084 ),2085 reachable_objects AS (2086 SELECT DISTINCT key FROM closure_reach2087 ),2088 stale_objects AS (2089 SELECT o.key2090 FROM objects AS o, ct2091 WHERE2092 NOT EXISTS (2093 SELECT 12094 FROM reachable_objects ro2095 WHERE ro.key = o.key2096 )2097 AND NOT EXISTS (2098 SELECT 12099 FROM pending_objects AS po2100 WHERE po.key = o.key2101 )2102 AND o.deleted_at IS NULL -- Only mark fresh objects2103 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2104 FOR UPDATE2105 )2106 UPDATE objects2107 SET2108 deleted_at = ct.now,2109 first_deleted_at = COALESCE(first_deleted_at, ct.now)2110 FROM stale_objects, ct2111 WHERE objects.key = stale_objects.key2112 21132026/10/27 08:54:57 INFO Aborted multipart uploads count=0 kept=021142026/10/27 08:54:57 WARN Force mode enabled - objects will be deleted immediately without grace period21152026/10/27 08:54:57 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:40339/bucket94/?delete=\": context canceled"2116--- PASS: TestGCEndsOnShutdown (0.00s)2117 --- PASS: TestGCEndsOnShutdown/before_the_run (0.22s)2118 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.25s)2119 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.27s)21202026/10/27 08:54:57 INFO Received uploads request method=POST path=/api/pending_closures21212026/10/27 08:54:57 INFO Aborted multipart uploads count=0 kept=021222026/10/27 08:54:57 WARN Force mode enabled - objects will be deleted immediately without grace period21232026/10/27 08:54:57 INFO Received uploads request method=POST path=/api/pending_closures21242026/10/27 08:54:57 INFO Aborted multipart uploads count=0 kept=021252026/10/27 08:54:57 WARN Request failed, retrying attempt=2 backoff=203.981032ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21262026/10/27 08:54:57 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=021272026/10/27 08:54:57 INFO Vacuumed table table=pending_closures21282026/10/27 08:54:57 INFO Vacuumed table table=pending_objects21292026/10/27 08:54:57 INFO Vacuumed table table=multipart_uploads21302026/10/27 08:54:57 INFO Vacuumed table table=closures21312026/10/27 08:54:57 INFO Vacuumed table table=objects21322026/10/27 08:54:57 WARN Force mode enabled - objects will be deleted immediately without grace period21332026/10/27 08:54:57 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=021342026/10/27 08:54:57 INFO Vacuumed table table=pending_closures21352026/10/27 08:54:57 INFO Vacuumed table table=pending_objects21362026/10/27 08:54:57 INFO Vacuumed table table=multipart_uploads21372026/10/27 08:54:57 INFO Vacuumed table table=closures21382026/10/27 08:54:57 INFO Vacuumed table table=objects2139--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2140 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.30s)2141 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.29s)21422026-10-27 08:54:57.942 UTC [1537] ERROR: Push does not exist: id=121432026-10-27 08:54:57.942 UTC [1537] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE21442026-10-27 08:54:57.942 UTC [1537] STATEMENT: SELECT commit_push($1)2145--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.65s)21462026/10/27 08:54:58 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2147=== NAME TestOrphanedObjectsGC2148 orphaned_objects_gc_test.go:287: GC Test Summary:2149 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A2150 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B2151 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)2152 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)2153 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects2154--- PASS: TestOrphanedObjectsGC (0.66s)21552026/10/27 08:54:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21562026/10/27 08:54:58 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MGRmNzExMzktYWFiOC00ZWFhLTg0MDgtYWQ3NzExYTVlY2Y1LjkxNmRkMGM0LTg3MjUtNDQwZC05NzViLTc3MmY5MTdiYzFkYngxNzkzMDkxMjk3NzUzMzQ5OTk1 error="Get \"http://127.0.0.1:1/bucket76/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"21572026/10/27 08:54:58 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MGRmNzExMzktYWFiOC00ZWFhLTg0MDgtYWQ3NzExYTVlY2Y1Ljk2YzA0OWJlLTM1ZTYtNGExYS05NWZlLTBhNWQzNjA4NGQwMXgxNzkzMDkxMjk3NzQ3MDM5MTI0 parts=1221582026/10/27 08:54:58 INFO Received cleanup request method=DELETE path=/api/pending_closures21592026/10/27 08:54:58 INFO Aborted multipart uploads count=1 kept=02160--- PASS: TestRedundantMultipartUpload (1.12s)21612026/10/27 08:54:58 INFO lead: released remote=192.0.2.1:12342162--- PASS: TestLeadEndsOnShutdown (1.34s)21632026/10/27 08:54:58 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2164--- PASS: TestUploadHandlersRejectOversizedBody (0.15s)2165 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)2166 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.04s)2167 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.63s)21682026/10/27 08:54:58 WARN Request failed, retrying attempt=3 backoff=431.837425ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2169--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2170 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.69s)2171 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.69s)21722026/10/27 08:54:58 WARN Request failed, retrying attempt=4 backoff=848.375883ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21732026/10/27 08:54:58 INFO lead: released remote=192.0.2.1:12342174--- PASS: TestLeadElectsOneAndHandsOver (3.11s)21752026/10/27 08:54:58 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02176=== NAME TestClientIntegration2177 client_integration_test.go:370: Objects in database after GC:2178 client_integration_test.go:370: Successfully deleted all objects with GC --force2179--- PASS: TestClientIntegration (3.06s)2180--- PASS: TestPendingClosureWriteTimeout (0.00s)2181 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2182 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2183 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2184 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.30s)2185=== NAME TestOrphanedObjectsGCStressTest2186 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2187 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion21882026/10/27 08:54:58 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=021892026/10/27 08:54:58 INFO Received create pin request method=POST path=/api/pins/myapp21902026/10/27 08:54:58 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC4184140075/001/store/93paqgqj39w2ximcm48cxsr8i3k3m4px-pinned-file.txt narinfo_key=93paqgqj39w2ximcm48cxsr8i3k3m4px.narinfo21912026/10/27 08:54:58 INFO Starting cleanup of old closures method=DELETE path=/api/closures21922026/10/27 08:54:58 INFO Garbage collection started21932026/10/27 08:54:58 INFO Aborted multipart uploads count=0 kept=021942026/10/27 08:54:58 WARN Force mode enabled - objects will be deleted immediately without grace period21952026/10/27 08:54:58 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=021962026/10/27 08:54:58 INFO Vacuumed table table=pending_closures21972026/10/27 08:54:58 INFO Vacuumed table table=pending_objects21982026/10/27 08:54:58 INFO Vacuumed table table=multipart_uploads21992026/10/27 08:54:58 INFO Vacuumed table table=closures22002026/10/27 08:54:58 INFO Vacuumed table table=objects2201 orphaned_objects_gc_test.go:503: Stress test completed successfully:2202 orphaned_objects_gc_test.go:504: - Active objects preserved: 202203 orphaned_objects_gc_test.go:505: - Objects deleted: 2102204 orphaned_objects_gc_test.go:506: - Total GC'd: 2102205--- PASS: TestOrphanedObjectsGCStressTest (2.19s)22062026/10/27 08:54:59 WARN Request failed, retrying attempt=5 backoff=1.577240366s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22072026/10/27 08:54:59 WARN Rate limiter enabled after throttle name=s3-test rate=522082026/10/27 08:54:59 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2209=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2210 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102211 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002212--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.64s)2213--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.73s)2214--- PASS: TestConnectWaitsForAPeerMigration (5.14s)2215=== NAME TestPinProtectsFromGC2216 client_integration_test.go:887: Pin successfully protected closure from garbage collection2217--- PASS: TestPinProtectsFromGC (4.72s)22182026/10/27 08:55:01 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-config22192026/10/27 08:55:01 WARN Request failed, retrying attempt=2 backoff=188.780083ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22202026/10/27 08:55:01 WARN Request failed, retrying attempt=3 backoff=369.838275ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22212026/10/27 08:55:01 WARN Request failed, retrying attempt=4 backoff=848.252976ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22222026/10/27 08:55:02 INFO Aborted multipart uploads count=1 kept=022232026/10/27 08:55:02 INFO Received cleanup request method=DELETE path=/api/pending_closures22242026/10/27 08:55:02 INFO Aborted multipart uploads count=1 kept=02225--- PASS: TestPendingCleanupUsesOneCutoff (6.18s)22262026/10/27 08:55:02 WARN Request failed, retrying attempt=5 backoff=1.635716704s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22272026/10/27 08:55:04 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"22282026/10/27 08:55:04 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-config22292026/10/27 08:55:04 WARN Request failed, retrying attempt=2 backoff=202.527729ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22302026/10/27 08:55:04 WARN Request failed, retrying attempt=3 backoff=422.766538ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22312026/10/27 08:55:04 WARN Request failed, retrying attempt=4 backoff=784.86291ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22322026/10/27 08:55:05 WARN Request failed, retrying attempt=5 backoff=1.609496133s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22332026/10/27 08:55:07 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_closures22342026/10/27 08:55:07 WARN Request failed, retrying attempt=2 backoff=202.818833ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22352026/10/27 08:55:07 WARN Request failed, retrying attempt=3 backoff=389.610816ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22362026/10/27 08:55:07 WARN Request failed, retrying attempt=4 backoff=763.367458ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22372026/10/27 08:55:08 WARN Request failed, retrying attempt=5 backoff=1.544867781s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2238--- PASS: TestClientErrorHandling (0.00s)2239 --- PASS: TestClientErrorHandling/InvalidStorePath (0.24s)2240 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.30s)2241 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.56s)2242PASS22432026-10-27 08:55:10.413 UTC [129] LOG: received smart shutdown request22442026-10-27 08:55:10.418 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 122452026-10-27 08:55:10.424 UTC [134] LOG: shutting down22462026-10-27 08:55:10.424 UTC [134] LOG: checkpoint starting: shutdown immediate22472026-10-27 08:55:11.448 UTC [134] LOG: checkpoint complete: wrote 11044 buffers (67.4%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 30 recycled; write=0.168 s, sync=0.822 s, total=1.024 s; sync files=34046, longest=0.002 s, average=0.001 s; distance=494061 kB, estimate=494061 kB; lsn=0/1F9E1128, redo lsn=0/1F9E112822482026-10-27 08:55:11.494 UTC [129] LOG: database system is shut down2249Running OIDC tests...2250=== RUN TestAudienceForIssuer2251=== PAUSE TestAudienceForIssuer2252=== RUN TestGlobMatch2253=== PAUSE TestGlobMatch2254=== RUN TestValidateToken_ValidToken2255=== PAUSE TestValidateToken_ValidToken2256=== RUN TestValidateToken_WrongAudience2257=== PAUSE TestValidateToken_WrongAudience2258=== RUN TestValidateToken_Expired2259=== PAUSE TestValidateToken_Expired2260=== RUN TestValidateToken_BoundClaimsMismatch2261=== PAUSE TestValidateToken_BoundClaimsMismatch2262=== RUN TestValidateToken_BoundSubjectMismatch2263=== PAUSE TestValidateToken_BoundSubjectMismatch2264=== RUN TestValidateToken_MultipleProviders2265=== PAUSE TestValidateToken_MultipleProviders2266=== RUN TestValidateToken_NoMatchingProvider2267=== PAUSE TestValidateToken_NoMatchingProvider2268=== RUN TestValidateToken_KubernetesServiceAccount2269=== PAUSE TestValidateToken_KubernetesServiceAccount2270=== RUN TestNewValidator_KubernetesRequiresCA2271=== PAUSE TestNewValidator_KubernetesRequiresCA2272=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2273=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2274=== RUN TestPins_ReservedForMatchingRule2275=== PAUSE TestPins_ReservedForMatchingRule2276=== RUN TestPins_TopLevelShorthand2277=== PAUSE TestPins_TopLevelShorthand2278=== RUN TestPins_ConfigValidation2279=== PAUSE TestPins_ConfigValidation2280=== RUN TestScopes_LegacyProviderDefaultsToWrite2281=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2282=== RUN TestScopes_Rules2283=== PAUSE TestScopes_Rules2284=== RUN TestScopes_ConfigValidation2285=== PAUSE TestScopes_ConfigValidation2286=== CONT TestAudienceForIssuer2287=== CONT TestValidateToken_KubernetesServiceAccount2288=== CONT TestPins_ConfigValidation2289--- PASS: TestAudienceForIssuer (0.00s)2290=== CONT TestValidateToken_Expired2291=== CONT TestValidateToken_WrongAudience2292=== CONT TestValidateToken_BoundClaimsMismatch2293=== CONT TestPins_ReservedForMatchingRule2294=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2295=== CONT TestValidateToken_ValidToken2296=== CONT TestScopes_Rules2297=== CONT TestValidateToken_MultipleProviders2298=== CONT TestScopes_ConfigValidation2299=== CONT TestPins_TopLevelShorthand2300=== CONT TestValidateToken_BoundSubjectMismatch2301=== CONT TestScopes_LegacyProviderDefaultsToWrite2302=== CONT TestGlobMatch2303=== RUN TestGlobMatch/foo_foo2304=== PAUSE TestGlobMatch/foo_foo2305=== RUN TestGlobMatch/foo_bar2306=== PAUSE TestGlobMatch/foo_bar2307=== RUN TestGlobMatch/*_2308=== PAUSE TestGlobMatch/*_2309=== CONT TestNewValidator_KubernetesRequiresCA2310=== RUN TestGlobMatch/*_anything2311=== PAUSE TestGlobMatch/*_anything2312--- PASS: TestPins_ConfigValidation (0.00s)2313=== CONT TestValidateToken_NoMatchingProvider2314--- PASS: TestScopes_ConfigValidation (0.00s)2315=== RUN TestGlobMatch/foo*_foo2316=== PAUSE TestGlobMatch/foo*_foo2317=== RUN TestGlobMatch/foo*_foobar2318=== PAUSE TestGlobMatch/foo*_foobar2319=== RUN TestGlobMatch/foo*_bar2320=== PAUSE TestGlobMatch/foo*_bar2321=== RUN TestGlobMatch/*bar_bar2322=== PAUSE TestGlobMatch/*bar_bar2323=== RUN TestGlobMatch/*bar_foobar2324=== PAUSE TestGlobMatch/*bar_foobar2325=== RUN TestGlobMatch/*bar_foo2326=== PAUSE TestGlobMatch/*bar_foo2327=== RUN TestGlobMatch/foo*bar_foobar2328=== PAUSE TestGlobMatch/foo*bar_foobar2329=== RUN TestGlobMatch/foo*bar_foo123bar2330=== PAUSE TestGlobMatch/foo*bar_foo123bar2331=== RUN TestGlobMatch/foo*bar_foobarbaz2332=== PAUSE TestGlobMatch/foo*bar_foobarbaz2333=== RUN TestGlobMatch/*/*_foo/bar2334=== PAUSE TestGlobMatch/*/*_foo/bar2335=== RUN TestGlobMatch/*/*_foo2336=== PAUSE TestGlobMatch/*/*_foo2337=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2338=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2339=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02340=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02341=== RUN TestGlobMatch/refs/*/main_refs/heads/main2342=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2343=== RUN TestGlobMatch/fo?_foo2344=== PAUSE TestGlobMatch/fo?_foo2345=== RUN TestGlobMatch/fo?_fo2346=== PAUSE TestGlobMatch/fo?_fo2347=== RUN TestGlobMatch/fo?_fooo2348=== PAUSE TestGlobMatch/fo?_fooo2349=== RUN TestGlobMatch/?oo_foo2350=== PAUSE TestGlobMatch/?oo_foo2351=== RUN TestGlobMatch/?oo_boo2352=== PAUSE TestGlobMatch/?oo_boo2353=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2354=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2355=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2356=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2357=== CONT TestGlobMatch/foo_foo2358=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2359=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2360=== CONT TestGlobMatch/?oo_boo2361=== CONT TestGlobMatch/?oo_foo2362=== CONT TestGlobMatch/fo?_fooo2363=== CONT TestGlobMatch/fo?_fo2364=== CONT TestGlobMatch/fo?_foo2365=== CONT TestGlobMatch/refs/*/main_refs/heads/main2366=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02367=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2368=== CONT TestGlobMatch/*/*_foo2369=== CONT TestGlobMatch/*/*_foo/bar2370=== CONT TestGlobMatch/foo*bar_foobarbaz2371=== CONT TestGlobMatch/foo*bar_foo123bar2372=== CONT TestGlobMatch/foo*bar_foobar2373=== CONT TestGlobMatch/*bar_foo2374=== CONT TestGlobMatch/*bar_foobar2375=== CONT TestGlobMatch/*bar_bar2376=== CONT TestGlobMatch/foo*_bar2377=== CONT TestGlobMatch/foo*_foobar2378=== CONT TestGlobMatch/foo*_foo2379=== CONT TestGlobMatch/*_anything2380=== CONT TestGlobMatch/*_2381=== CONT TestGlobMatch/foo_bar2382--- PASS: TestGlobMatch (0.00s)2383 --- PASS: TestGlobMatch/foo_foo (0.00s)2384 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2385 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2386 --- PASS: TestGlobMatch/?oo_boo (0.00s)2387 --- PASS: TestGlobMatch/?oo_foo (0.00s)2388 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2389 --- PASS: TestGlobMatch/fo?_fo (0.00s)2390 --- PASS: TestGlobMatch/fo?_foo (0.00s)2391 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2392 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2393 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2394 --- PASS: TestGlobMatch/*/*_foo (0.00s)2395 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2396 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2397 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2398 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2399 --- PASS: TestGlobMatch/*bar_foo (0.00s)2400 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2401 --- PASS: TestGlobMatch/*bar_bar (0.00s)2402 --- PASS: TestGlobMatch/foo*_bar (0.00s)2403 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2404 --- PASS: TestGlobMatch/foo*_foo (0.00s)2405 --- PASS: TestGlobMatch/*_anything (0.00s)2406 --- PASS: TestGlobMatch/*_ (0.00s)2407 --- PASS: TestGlobMatch/foo_bar (0.00s)24082026/10/27 08:55:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42879/oidc2409--- PASS: TestValidateToken_BoundSubjectMismatch (0.03s)24102026/10/27 08:55:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39199/oidc2411--- PASS: TestValidateToken_WrongAudience (0.04s)24122026/10/27 08:55:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46269/oidc2413--- PASS: TestPins_TopLevelShorthand (0.04s)24142026/10/27 08:55:13 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:42857/oidc24152026/10/27 08:55:13 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:40541/oidc2416--- PASS: TestValidateToken_MultipleProviders (0.07s)24172026/10/27 08:55:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41335/oidc2418--- PASS: TestScopes_Rules (0.07s)24192026/10/27 08:55:13 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12324202026/10/27 08:55:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32991/oidc24212026/10/27 08:55:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33083/oidc2422--- PASS: TestValidateToken_Expired (0.09s)2423--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.09s)24242026/10/27 08:55:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45545/oidc2425--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.09s)2426--- PASS: TestValidateToken_ValidToken (0.09s)24272026/10/27 08:55:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46631/oidc2428--- PASS: TestPins_ReservedForMatchingRule (0.10s)24292026/10/27 08:55:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46107/oidc2430--- PASS: TestValidateToken_BoundClaimsMismatch (0.13s)24312026/10/27 08:55:13 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:416192432--- PASS: TestValidateToken_KubernetesServiceAccount (0.15s)24332026/10/27 08:55:13 http: TLS handshake error from 127.0.0.1:33660: remote error: tls: bad certificate2434--- PASS: TestNewValidator_KubernetesRequiresCA (0.17s)24352026/10/27 08:55:13 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:38835/oidc2436--- PASS: TestValidateToken_NoMatchingProvider (0.22s)2437PASS2438Running hook tests...2439=== RUN TestSendPathsEmpty2440=== PAUSE TestSendPathsEmpty2441=== RUN TestQueueEnqueueAndFetch2442=== PAUSE TestQueueEnqueueAndFetch2443=== RUN TestQueueDeduplication2444=== PAUSE TestQueueDeduplication2445=== RUN TestQueueRemove2446=== PAUSE TestQueueRemove2447=== RUN TestQueueFetchBatchLimit2448=== PAUSE TestQueueFetchBatchLimit2449=== RUN TestQueueRetryMovesToBack2450=== PAUSE TestQueueRetryMovesToBack2451=== RUN TestQueueFetchRemoveLifecycle2452=== PAUSE TestQueueFetchRemoveLifecycle2453=== RUN TestQueueConcurrentWriters2454=== PAUSE TestQueueConcurrentWriters2455=== RUN TestQueueRemoveLargeClosure2456=== PAUSE TestQueueRemoveLargeClosure2457=== RUN TestServerClientIntegration2458--- PASS: TestServerClientIntegration (0.00s)2459=== RUN TestServerQueueError24602026/10/27 08:55:13 ERROR Failed to queue paths error="permission denied" count=12461--- PASS: TestServerQueueError (0.00s)2462=== RUN TestGetListenerSocketActivation2463 server_test.go:218: === RUN TestGetListenerSocketActivation2464 --- PASS: TestGetListenerSocketActivation (0.00s)2465 PASS2466 2467--- PASS: TestGetListenerSocketActivation (0.00s)2468=== RUN TestServerStalledClientDoesNotBlockShutdown2469=== PAUSE TestServerStalledClientDoesNotBlockShutdown2470=== RUN TestServerBacksOffOnAcceptErrors2471=== PAUSE TestServerBacksOffOnAcceptErrors2472=== RUN TestDrainIsolatesPoisonPath2473=== PAUSE TestDrainIsolatesPoisonPath2474=== RUN TestRunNotBlockedByPoisonHead2475=== PAUSE TestRunNotBlockedByPoisonHead2476=== RUN TestDrainGivesUpWhenServerDown2477=== PAUSE TestDrainGivesUpWhenServerDown2478=== RUN TestFailedPathPrunedByLaterClosure2479=== PAUSE TestFailedPathPrunedByLaterClosure2480=== RUN TestWorkerUploadsAndRemoves2481=== PAUSE TestWorkerUploadsAndRemoves2482=== RUN TestWorkerSkipsGCdPaths2483=== PAUSE TestWorkerSkipsGCdPaths2484=== RUN TestWorkerPrunesClosureDeps2485=== PAUSE TestWorkerPrunesClosureDeps2486=== RUN TestDrainTimeout2487=== PAUSE TestDrainTimeout2488=== RUN TestWorkerRemoveFailureIsNotProgress2489=== PAUSE TestWorkerRemoveFailureIsNotProgress2490=== RUN TestWorkerKeepsPathItCannotStat2491=== PAUSE TestWorkerKeepsPathItCannotStat2492=== CONT TestSendPathsEmpty2493=== CONT TestWorkerKeepsPathItCannotStat2494=== CONT TestQueueDeduplication2495=== CONT TestQueueFetchBatchLimit2496--- PASS: TestSendPathsEmpty (0.00s)2497=== CONT TestQueueEnqueueAndFetch2498=== CONT TestDrainIsolatesPoisonPath2499=== CONT TestServerBacksOffOnAcceptErrors2500=== CONT TestServerStalledClientDoesNotBlockShutdown2501=== CONT TestQueueRemoveLargeClosure2502=== CONT TestQueueConcurrentWriters2503=== CONT TestQueueRemove2504=== CONT TestQueueFetchRemoveLifecycle25052026/10/27 08:55:13 ERROR Accept failed error="too many open files"2506=== CONT TestQueueRetryMovesToBack2507=== CONT TestWorkerSkipsGCdPaths2508=== CONT TestFailedPathPrunedByLaterClosure2509=== CONT TestWorkerRemoveFailureIsNotProgress2510=== CONT TestDrainTimeout2511=== CONT TestWorkerUploadsAndRemoves2512=== CONT TestWorkerPrunesClosureDeps2513=== CONT TestRunNotBlockedByPoisonHead2514=== CONT TestDrainGivesUpWhenServerDown25152026/10/27 08:55:13 ERROR Accept failed error="too many open files"25162026/10/27 08:55:13 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2939220187/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat2939220187/002/locked/aaa: permission denied"25172026/10/27 08:55:13 INFO Uploading batch count=125182026/10/27 08:55:13 ERROR Upload failed error="upload failed" count=125192026/10/27 08:55:13 INFO Upload queue status pending=225202026/10/27 08:55:13 INFO Uploading batch count=225212026/10/27 08:55:13 INFO Uploading batch count=425222026/10/27 08:55:13 ERROR Upload failed error="upload failed" count=425232026/10/27 08:55:13 INFO Upload queue status pending=225242026/10/27 08:55:13 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths118702623/002/nonexistent25252026/10/27 08:55:13 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3177652433/002/bbb2526--- PASS: TestQueueFetchBatchLimit (0.01s)25272026/10/27 08:55:13 INFO Uploading batch count=125282026/10/27 08:55:13 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2939220187/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat2939220187/002/locked/aaa: permission denied"25292026/10/27 08:55:13 INFO Upload queue status pending=225302026/10/27 08:55:13 INFO Uploading batch count=22531--- PASS: TestQueueEnqueueAndFetch (0.02s)25322026/10/27 08:55:13 ERROR Accept failed error="too many open files"25332026/10/27 08:55:13 INFO Upload queue status pending=325342026/10/27 08:55:13 INFO Uploading batch count=125352026/10/27 08:55:13 ERROR Upload failed error="upload failed" count=125362026/10/27 08:55:13 INFO Uploading batch count=125372026/10/27 08:55:13 INFO Uploading batch count=225382026/10/27 08:55:13 ERROR Upload failed error="upload failed" count=225392026/10/27 08:55:13 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3743943939/002/a25402026/10/27 08:55:13 INFO Uploading batch count=125412026/10/27 08:55:13 ERROR Upload failed error="upload failed" count=12542--- PASS: TestQueueRemove (0.02s)25432026/10/27 08:55:13 INFO Uploading batch count=125442026/10/27 08:55:13 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2939220187/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat2939220187/002/locked/aaa: permission denied"25452026/10/27 08:55:13 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3743943939/002/b2546--- PASS: TestQueueFetchRemoveLifecycle (0.02s)2547--- PASS: TestQueueRetryMovesToBack (0.02s)25482026/10/27 08:55:13 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress2338468587/002/nonexistent25492026/10/27 08:55:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125502026/10/27 08:55:13 INFO Uploading batch count=125512026/10/27 08:55:13 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress2338468587/002/nonexistent25522026/10/27 08:55:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125532026/10/27 08:55:13 INFO Uploading batch count=125542026/10/27 08:55:13 ERROR Upload failed error="upload failed" count=125552026/10/27 08:55:13 INFO Uploading batch count=225562026/10/27 08:55:13 ERROR Upload failed error="upload failed" count=225572026/10/27 08:55:13 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3743943939/002/c25582026/10/27 08:55:13 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress2338468587/002/nonexistent25592026/10/27 08:55:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125602026/10/27 08:55:13 ERROR Drain finished with paths left in queue remaining=125612026/10/27 08:55:13 ERROR Drain finished with paths left in queue remaining=125622026/10/27 08:55:13 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3743943939/002/d25632026/10/27 08:55:13 INFO Uploading batch count=125642026/10/27 08:55:13 ERROR Upload failed error="upload failed" count=12565--- PASS: TestQueueDeduplication (0.02s)25662026/10/27 08:55:13 INFO Uploading batch count=225672026/10/27 08:55:13 ERROR Upload failed error="upload failed" count=225682026/10/27 08:55:13 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3743943939/002/e2569--- PASS: TestWorkerRemoveFailureIsNotProgress (0.02s)25702026/10/27 08:55:13 ERROR Drain finished with paths left in queue remaining=125712026/10/27 08:55:13 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3743943939/002/f25722026/10/27 08:55:13 ERROR Drain finished with paths left in queue remaining=102573--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)2574--- PASS: TestWorkerKeepsPathItCannotStat (0.02s)2575--- PASS: TestDrainIsolatesPoisonPath (0.02s)2576--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2577--- PASS: TestWorkerUploadsAndRemoves (0.03s)2578--- PASS: TestWorkerSkipsGCdPaths (0.03s)25792026/10/27 08:55:13 ERROR Accept failed error="too many open files"2580--- PASS: TestWorkerPrunesClosureDeps (0.04s)2581--- PASS: TestQueueRemoveLargeClosure (0.06s)25822026/10/27 08:55:13 ERROR Accept failed error="too many open files"2583--- PASS: TestQueueConcurrentWriters (0.10s)25842026/10/27 08:55:13 ERROR Accept failed error="too many open files"25852026/10/27 08:55:13 ERROR Failed to decode request error="read unix /build/hook2979644722/test.sock->@: i/o timeout"25862026/10/27 08:55:13 ERROR Failed to write response error="write unix /build/hook2979644722/test.sock->@: i/o timeout"2587--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)25882026/10/27 08:55:13 ERROR Upload failed error="context deadline exceeded" count=225892026/10/27 08:55:13 ERROR Drain finished with paths left in queue remaining=42590--- PASS: TestDrainTimeout (0.22s)25912026/10/27 08:55:13 ERROR Accept failed error="too many open files"25922026/10/27 08:55:13 ERROR Accept failed error="too many open files"2593--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)25942026/10/27 08:55:14 INFO Uploading batch count=125952026/10/27 08:55:14 INFO Uploading batch count=125962026/10/27 08:55:14 INFO Uploading batch count=125972026/10/27 08:55:14 ERROR Upload failed error="upload failed" count=125982026/10/27 08:55:14 INFO Uploading batch count=125992026/10/27 08:55:14 ERROR Upload failed error="upload failed" count=126002026/10/27 08:55:14 INFO Uploading batch count=126012026/10/27 08:55:14 ERROR Upload failed error="upload failed" count=126022026/10/27 08:55:14 INFO Uploading batch count=126032026/10/27 08:55:14 ERROR Upload failed error="upload failed" count=126042026/10/27 08:55:14 ERROR Drain finished with paths left in queue remaining=12605--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2606PASS2607Running signing tests...2608=== RUN TestExternalSigner2609=== PAUSE TestExternalSigner2610=== RUN TestExternalSignerWrongPublicKey2611=== PAUSE TestExternalSignerWrongPublicKey2612=== RUN TestExternalSignerErrors2613=== PAUSE TestExternalSignerErrors2614=== RUN TestExternalSignerRestartsAfterCrash2615=== PAUSE TestExternalSignerRestartsAfterCrash2616=== RUN TestExternalSignerProgramErrorKeepsProcess2617=== PAUSE TestExternalSignerProgramErrorKeepsProcess2618=== RUN TestExternalSignerClose2619=== PAUSE TestExternalSignerClose2620=== RUN TestExternalSignerRejectsInvalidPublicKey2621=== PAUSE TestExternalSignerRejectsInvalidPublicKey2622=== RUN TestExternalSignerCancellation2623=== PAUSE TestExternalSignerCancellation2624=== RUN TestGenerateFingerprint2625=== PAUSE TestGenerateFingerprint2626=== RUN TestParseSigningKey2627=== PAUSE TestParseSigningKey2628=== RUN TestSign2629=== PAUSE TestSign2630=== RUN TestSignBatch2631=== PAUSE TestSignBatch2632=== RUN TestNilKeyPublicKey2633=== PAUSE TestNilKeyPublicKey2634=== RUN TestSignErrors2635=== PAUSE TestSignErrors2636=== CONT TestExternalSigner2637=== CONT TestExternalSignerCancellation2638=== CONT TestExternalSignerProgramErrorKeepsProcess2639=== CONT TestSignErrors2640=== CONT TestExternalSignerRejectsInvalidPublicKey2641=== CONT TestExternalSignerClose2642=== CONT TestExternalSignerRestartsAfterCrash2643=== CONT TestExternalSignerWrongPublicKey2644=== CONT TestSign2645=== CONT TestSignBatch2646=== CONT TestParseSigningKey2647=== CONT TestNilKeyPublicKey2648=== RUN TestParseSigningKey/valid_32-byte_key2649--- PASS: TestNilKeyPublicKey (0.00s)2650=== CONT TestGenerateFingerprint2651=== RUN TestExternalSignerRejectsInvalidPublicKey/#002652=== RUN TestGenerateFingerprint/basic_with_references2653=== PAUSE TestParseSigningKey/valid_32-byte_key2654=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002655=== CONT TestExternalSignerErrors2656=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2657=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2658=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2659=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2660=== RUN TestExternalSignerErrors/unrequested_key2661=== RUN TestParseSigningKey/no_colon2662=== PAUSE TestParseSigningKey/no_colon2663=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2664=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2665=== RUN TestParseSigningKey/empty_name2666=== PAUSE TestExternalSignerErrors/unrequested_key2667=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2668=== PAUSE TestParseSigningKey/empty_name2669=== RUN TestParseSigningKey/invalid_base642670=== RUN TestExternalSignerErrors/missing_signature_name2671=== PAUSE TestExternalSignerErrors/missing_signature_name2672=== RUN TestExternalSignerErrors/wrong_signature_length2673=== PAUSE TestParseSigningKey/invalid_base642674=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2675=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2676=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2677=== PAUSE TestGenerateFingerprint/basic_with_references2678=== RUN TestGenerateFingerprint/no_references2679=== PAUSE TestGenerateFingerprint/no_references2680=== PAUSE TestExternalSignerErrors/wrong_signature_length2681=== RUN TestParseSigningKey/wrong_length2682=== PAUSE TestParseSigningKey/wrong_length2683=== CONT TestParseSigningKey/wrong_length2684=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2685=== CONT TestParseSigningKey/valid_32-byte_key2686=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2687=== CONT TestExternalSignerRejectsInvalidPublicKey/#002688=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2689=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2690=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2691--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2692 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2693 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2694 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2695 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2696 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2697=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2698=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2699=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2700=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2701=== RUN TestGenerateFingerprint/invalid_nar_hash_length2702=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2703=== RUN TestGenerateFingerprint/invalid_store_path_prefix2704=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2705=== RUN TestSignErrors/nil_key2706=== PAUSE TestSignErrors/nil_key2707=== RUN TestSignErrors/nil_narinfo2708=== PAUSE TestSignErrors/nil_narinfo2709=== RUN TestSignErrors/invalid_narinfo2710=== PAUSE TestSignErrors/invalid_narinfo2711=== RUN TestSignErrors/canceled2712=== PAUSE TestSignErrors/canceled2713=== CONT TestSignErrors/nil_key2714=== RUN TestGenerateFingerprint/invalid_reference_prefix2715=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2716=== CONT TestGenerateFingerprint/basic_with_references2717=== CONT TestSignErrors/canceled2718=== CONT TestSignErrors/invalid_narinfo2719=== CONT TestSignErrors/nil_narinfo2720--- PASS: TestSignErrors (0.00s)2721 --- PASS: TestSignErrors/nil_key (0.00s)2722 --- PASS: TestSignErrors/canceled (0.00s)2723 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2724 --- PASS: TestSignErrors/nil_narinfo (0.00s)2725=== CONT TestParseSigningKey/invalid_base642726=== CONT TestParseSigningKey/empty_name2727=== CONT TestParseSigningKey/no_colon2728=== RUN TestExternalSignerErrors/program_error2729=== CONT TestGenerateFingerprint/invalid_nar_hash_length2730=== CONT TestGenerateFingerprint/no_references2731=== PAUSE TestExternalSignerErrors/program_error2732=== RUN TestExternalSignerErrors/exit_at_startup2733=== CONT TestGenerateFingerprint/invalid_reference_prefix2734=== PAUSE TestExternalSignerErrors/exit_at_startup2735=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2736=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2737=== CONT TestGenerateFingerprint/invalid_store_path_prefix2738=== RUN TestExternalSignerErrors/exit_on_request2739--- PASS: TestGenerateFingerprint (0.00s)2740 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2741 --- PASS: TestGenerateFingerprint/no_references (0.00s)2742 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2743 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2744 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2745 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2746 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2747=== PAUSE TestExternalSignerErrors/exit_on_request2748--- PASS: TestSign (0.00s)2749=== RUN TestExternalSignerErrors/invalid_JSON2750=== PAUSE TestExternalSignerErrors/invalid_JSON2751=== RUN TestExternalSignerErrors/null2752--- PASS: TestParseSigningKey (0.00s)2753 --- PASS: TestParseSigningKey/wrong_length (0.00s)2754 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2755 --- PASS: TestParseSigningKey/empty_name (0.00s)2756 --- PASS: TestParseSigningKey/no_colon (0.00s)2757 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2758 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2759=== PAUSE TestExternalSignerErrors/null2760=== RUN TestExternalSignerErrors/missing_signatures2761=== PAUSE TestExternalSignerErrors/missing_signatures2762=== RUN TestExternalSignerErrors/null_signatures2763=== PAUSE TestExternalSignerErrors/null_signatures2764=== RUN TestExternalSignerErrors/wrong_signatures_shape2765=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2766=== RUN TestExternalSignerErrors/too_few_signatures2767=== PAUSE TestExternalSignerErrors/too_few_signatures2768=== RUN TestExternalSignerErrors/wrong_signature_name2769=== PAUSE TestExternalSignerErrors/wrong_signature_name2770=== RUN TestExternalSignerErrors/invalid_signature_base642771=== PAUSE TestExternalSignerErrors/invalid_signature_base642772=== RUN TestExternalSignerErrors/wrong_shape2773=== PAUSE TestExternalSignerErrors/wrong_shape2774=== RUN TestExternalSignerErrors/wrong_id2775=== PAUSE TestExternalSignerErrors/wrong_id2776=== CONT TestExternalSignerErrors/unrequested_key2777=== CONT TestExternalSignerErrors/wrong_signature_name2778=== CONT TestExternalSignerErrors/invalid_JSON2779=== CONT TestExternalSignerErrors/wrong_shape2780=== CONT TestExternalSignerErrors/program_error2781=== CONT TestExternalSignerErrors/invalid_signature_base642782=== CONT TestExternalSignerErrors/missing_signatures2783=== CONT TestExternalSignerErrors/too_few_signatures2784=== CONT TestExternalSignerErrors/null_signatures2785=== CONT TestExternalSignerErrors/wrong_id2786=== CONT TestExternalSignerErrors/wrong_signature_length2787=== CONT TestExternalSignerErrors/wrong_signatures_shape2788=== CONT TestExternalSignerErrors/exit_at_startup2789=== CONT TestExternalSignerErrors/exit_on_request2790=== CONT TestExternalSignerErrors/missing_signature_name2791=== CONT TestExternalSignerErrors/null2792--- PASS: TestSignBatch (0.00s)2793--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2794--- PASS: TestExternalSignerClose (0.00s)2795--- PASS: TestExternalSignerWrongPublicKey (0.01s)2796--- PASS: TestExternalSigner (0.01s)2797--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2798--- PASS: TestExternalSignerErrors (0.00s)2799 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.00s)2800 --- PASS: TestExternalSignerErrors/too_few_signatures (0.00s)2801 --- PASS: TestExternalSignerErrors/unrequested_key (0.00s)2802 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.00s)2803 --- PASS: TestExternalSignerErrors/program_error (0.00s)2804 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2805 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2806 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2807 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2808 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2809 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2810 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2811 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2812 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)2813 --- PASS: TestExternalSignerErrors/null (0.00s)2814 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2815--- PASS: TestExternalSignerCancellation (0.02s)2816PASS2817Running OpenBao signer tests...2818=== RUN TestSign2819=== PAUSE TestSign2820=== RUN TestSignErrors2821=== PAUSE TestSignErrors2822=== RUN TestServe2823=== PAUSE TestServe2824=== RUN TestServeRejectsGarbage2825=== PAUSE TestServeRejectsGarbage2826=== CONT TestSign2827=== CONT TestServe2828=== CONT TestServeRejectsGarbage2829=== CONT TestSignErrors2830=== RUN TestSignErrors/invalid_json2831--- PASS: TestServeRejectsGarbage (0.00s)2832=== PAUSE TestSignErrors/invalid_json2833=== RUN TestSignErrors/no_prefix2834=== PAUSE TestSignErrors/no_prefix2835=== RUN TestSignErrors/invalid_base642836=== PAUSE TestSignErrors/invalid_base642837=== RUN TestSignErrors/http_error2838=== PAUSE TestSignErrors/http_error2839=== CONT TestSignErrors/invalid_json2840=== CONT TestSignErrors/invalid_base642841=== CONT TestSignErrors/http_error2842=== CONT TestSignErrors/no_prefix2843--- PASS: TestServe (0.00s)2844--- PASS: TestSign (0.00s)2845--- PASS: TestSignErrors (0.00s)2846 --- PASS: TestSignErrors/no_prefix (0.00s)2847 --- PASS: TestSignErrors/invalid_json (0.00s)2848 --- PASS: TestSignErrors/http_error (0.00s)2849 --- PASS: TestSignErrors/invalid_base64 (0.00s)2850PASS