niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #453
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestUploadMultipart_PartsInParallel18=== PAUSE TestUploadMultipart_PartsInParallel19=== RUN TestUploadMultipart_FailedPartBufferNotReused20=== PAUSE TestUploadMultipart_FailedPartBufferNotReused21=== RUN TestPartSizeForNAR22=== PAUSE TestPartSizeForNAR23=== RUN TestUploadMultipart_SupersededByPeer24=== PAUSE TestUploadMultipart_SupersededByPeer25=== RUN TestDumpPathCaseHackMatchesNix26--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)27=== RUN TestDumpPathCaseHackCollision28--- PASS: TestDumpPathCaseHackCollision (0.00s)29=== RUN TestSupersededNARStillUploadsListing30=== PAUSE TestSupersededNARStillUploadsListing31=== RUN TestDumpPathMatchesNix32=== PAUSE TestDumpPathMatchesNix33=== RUN TestDumpPathSingleFile34=== PAUSE TestDumpPathSingleFile35=== RUN TestDumpPathWriterError36=== PAUSE TestDumpPathWriterError37=== RUN TestEncodeNixBase3238=== PAUSE TestEncodeNixBase3239=== RUN TestEncodeNixBase32WithRealHash40=== PAUSE TestEncodeNixBase32WithRealHash41=== RUN TestConvertHashToNix3242=== PAUSE TestConvertHashToNix3243=== RUN TestGetStorePathHash44=== PAUSE TestGetStorePathHash45=== RUN TestPathInfoHashCompatibility46=== PAUSE TestPathInfoHashCompatibility47=== RUN TestParsePathInfoJSON48=== PAUSE TestParsePathInfoJSON49=== RUN TestParsePathInfoJSONMultiplePaths50=== PAUSE TestParsePathInfoJSONMultiplePaths51=== RUN TestPathInfoCACompatibility52=== PAUSE TestPathInfoCACompatibility53=== RUN TestRateLimiterFeedback54=== PAUSE TestRateLimiterFeedback55=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess56=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess57=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer58=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer59=== RUN TestResolveStorePath60=== PAUSE TestResolveStorePath61=== RUN TestDoWithRetry_BodyReplayedViaGetBody62=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody63=== RUN TestRetryTimeoutOutlastsMaxRetries64=== PAUSE TestRetryTimeoutOutlastsMaxRetries65=== RUN TestDoWithRetry_FinalResponseBodyReadable66=== PAUSE TestDoWithRetry_FinalResponseBodyReadable67=== RUN TestShellSplit68=== PAUSE TestShellSplit69=== RUN TestShellSplitErrors70=== PAUSE TestShellSplitErrors71=== RUN TestStreamPushReportsEveryPath72=== PAUSE TestStreamPushReportsEveryPath73=== RUN TestStreamPushBatchesUnderLoad74=== PAUSE TestStreamPushBatchesUnderLoad75=== RUN TestStreamPushIsolatesFailures76=== PAUSE TestStreamPushIsolatesFailures77=== RUN TestStreamPushGivesUpOnDeadServer78=== PAUSE TestStreamPushGivesUpOnDeadServer79=== RUN TestStreamPushRequestLine80=== PAUSE TestStreamPushRequestLine81=== RUN TestStreamPushReportsSignatures82=== PAUSE TestStreamPushReportsSignatures83=== RUN TestStreamPushReportsSkippedPaths84=== PAUSE TestStreamPushReportsSkippedPaths85=== RUN TestClientSignaturesByStorePath86=== PAUSE TestClientSignaturesByStorePath87=== RUN TestStreamPushStopsWhenCanceled88=== PAUSE TestStreamPushStopsWhenCanceled89=== RUN TestSetClientTLS90=== PAUSE TestSetClientTLS91=== RUN TestSetClientTLSDoesNotMutateDefaultTransport92=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport93=== RUN TestSetClientTLSErrors94=== PAUSE TestSetClientTLSErrors95=== RUN TestStaticToken96=== PAUSE TestStaticToken97=== RUN TestFileTokenReadsAndCaches98=== PAUSE TestFileTokenReadsAndCaches99=== RUN TestFileTokenMissing100=== PAUSE TestFileTokenMissing101=== RUN TestFileTokenEmpty102=== PAUSE TestFileTokenEmpty103=== RUN TestScriptTokenNoExpiryRerunsEveryCall104=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall105=== RUN TestScriptTokenCachesUntilRefresh106=== PAUSE TestScriptTokenCachesUntilRefresh107=== RUN TestScriptTokenEmptyToken108=== PAUSE TestScriptTokenEmptyToken109=== RUN TestScriptTokenBadJSON110=== PAUSE TestScriptTokenBadJSON111=== RUN TestScriptTokenScriptFails112=== PAUSE TestScriptTokenScriptFails113=== RUN TestScriptTokenEmptyCommand114=== PAUSE TestScriptTokenEmptyCommand115=== CONT TestDoServerRequestAttachesToken116=== CONT TestDoWithRetry_BodyReplayedViaGetBody117=== CONT TestSetClientTLS118=== CONT TestScriptTokenEmptyCommand119--- PASS: TestScriptTokenEmptyCommand (0.00s)120=== CONT TestDumpPathSingleFile121=== CONT TestScriptTokenScriptFails122=== CONT TestScriptTokenBadJSON123=== CONT TestScriptTokenEmptyToken124=== CONT TestScriptTokenCachesUntilRefresh125=== CONT TestScriptTokenNoExpiryRerunsEveryCall126=== CONT TestFileTokenEmpty127=== CONT TestFileTokenMissing128=== CONT TestFileTokenReadsAndCaches129=== CONT TestStaticToken130=== CONT TestSupersededNARStillUploadsListing131=== CONT TestSetClientTLSErrors132=== CONT TestSetClientTLSDoesNotMutateDefaultTransport133=== CONT TestConvertHashToNix32134=== CONT TestParsePathInfoJSONMultiplePaths135=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths136=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths137=== CONT TestResolveStorePath138=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer139=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess140=== CONT TestRateLimiterFeedback141=== CONT TestPathInfoCACompatibility142=== CONT TestDumpPathWriterError143=== CONT TestUploadMultipart_PartsInParallel144=== CONT TestParsePathInfoJSON145--- PASS: TestScriptTokenScriptFails (0.01s)146=== CONT TestPathInfoHashCompatibility147=== CONT TestDumpPathMatchesNix148=== CONT TestGetStorePathHash149=== RUN TestSupersededNARStillUploadsListing/small_NAR150=== RUN TestConvertHashToNix32/SRI_format_to_Nix32151=== CONT TestUploadMultipart_SupersededByPeer152=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths153=== RUN TestRateLimiterFeedback/429_enables_limiter154--- PASS: TestFileTokenMissing (0.00s)155=== RUN TestGetStorePathHash/valid_store_path156--- PASS: TestFileTokenEmpty (0.00s)157--- PASS: TestStaticToken (0.00s)158--- PASS: TestScriptTokenBadJSON (0.01s)159--- PASS: TestScriptTokenEmptyToken (0.01s)160=== RUN TestParsePathInfoJSON/Nix_format161=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)162=== RUN TestPathInfoCACompatibility/null_ca_field163=== CONT TestEncodeNixBase32WithRealHash164--- PASS: TestEncodeNixBase32WithRealHash (0.00s)165=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32166--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)167--- PASS: TestFileTokenReadsAndCaches (0.00s)1682026/11/01 17:33:36 WARN Rate limiter enabled after throttle name=server-test rate=5169=== PAUSE TestParsePathInfoJSON/Nix_format170=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)171=== PAUSE TestPathInfoCACompatibility/null_ca_field172=== CONT TestPartSizeForNAR173=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon174=== RUN TestPartSizeForNAR/zero_stays_at_minimum175=== RUN TestPathInfoCACompatibility/old_string_format_-_text176=== CONT TestEncodeNixBase32177=== PAUSE TestRateLimiterFeedback/429_enables_limiter178=== RUN TestRateLimiterFeedback/503_enables_limiter179=== PAUSE TestRateLimiterFeedback/503_enables_limiter180=== RUN TestEncodeNixBase32/test_string_hash181=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter182=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter183=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum184=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter185--- PASS: TestDoServerRequestAttachesToken (0.02s)1862026/11/01 17:33:36 WARN Rate limiter enabled after throttle name=server-test rate=5187=== RUN TestConvertHashToNix32/already_Nix32_format188=== PAUSE TestConvertHashToNix32/already_Nix32_format1892026/11/01 17:33:36 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:39295190=== PAUSE TestSupersededNARStillUploadsListing/small_NAR191=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon192=== RUN TestSupersededNARStillUploadsListing/dump_cut_short193=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short194=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI195=== RUN TestUploadMultipart_SupersededByPeer/exists196=== PAUSE TestUploadMultipart_SupersededByPeer/exists197=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths1982026/11/01 17:33:36 WARN Rate limiter backed off name=server-test rate=5199=== PAUSE TestGetStorePathHash/valid_store_path2002026/11/01 17:33:36 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:39295201=== PAUSE TestEncodeNixBase32/test_string_hash202=== RUN TestParsePathInfoJSON/Lix_format203=== CONT TestUploadMultipart_FailedPartBufferNotReused204=== RUN TestSetClientTLS/rejects_connection_without_client_cert205--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)206=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun207--- PASS: TestResolveStorePath (0.01s)208=== RUN TestPartSizeForNAR/small_stays_at_minimum209=== PAUSE TestPartSizeForNAR/small_stays_at_minimum210=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter211=== RUN TestConvertHashToNix32/invalid_format212=== PAUSE TestConvertHashToNix32/invalid_format213=== RUN TestSetClientTLSErrors/missing_cert_file214=== PAUSE TestSetClientTLSErrors/missing_cert_file215=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica216=== CONT TestShellSplitErrors217=== CONT TestRegisterUploadedObjectReusesConnections218=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text219=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails220=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI221=== RUN TestUploadMultipart_SupersededByPeer/missing222=== CONT TestFilterOversizedClosures223=== RUN TestGetStorePathHash/basename_without_hyphen_should_error224=== RUN TestEncodeNixBase32/empty_input225=== PAUSE TestParsePathInfoJSON/Lix_format226=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert227=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum228=== CONT TestCaseHackSuffix229--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.05s)230=== CONT TestStreamPushIsolatesFailures231--- PASS: TestScriptTokenCachesUntilRefresh (0.06s)232--- PASS: TestShellSplitErrors (0.00s)233=== RUN TestSetClientTLSErrors/missing_key_file234=== PAUSE TestSetClientTLSErrors/missing_key_file235=== RUN TestSetClientTLSErrors/missing_ca_file236=== CONT TestStreamPushStopsWhenCanceled237--- PASS: TestDumpPathSingleFile (0.06s)238=== CONT TestClientSignaturesByStorePath239--- PASS: TestClientSignaturesByStorePath (0.00s)240=== CONT TestStreamPushBatchesUnderLoad241=== PAUSE TestEncodeNixBase32/empty_input242=== CONT TestStreamPushReportsSkippedPaths243=== PAUSE TestUploadMultipart_SupersededByPeer/missing244=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512245=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512246--- PASS: TestStreamPushReportsSkippedPaths (0.00s)247=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry2482026/11/01 17:33:36 INFO Garbage collection started249=== RUN TestParsePathInfoJSON/empty_input250=== PAUSE TestParsePathInfoJSON/empty_input251=== RUN TestParsePathInfoJSON/whitespace_only252=== PAUSE TestParsePathInfoJSON/whitespace_only253=== RUN TestParsePathInfoJSON/invalid_JSON254=== PAUSE TestParsePathInfoJSON/invalid_JSON255=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error256=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error257=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error258=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error259=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error260=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA261=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA262=== RUN TestSetClientTLS/preserves_debug_logging_transport263=== PAUSE TestSetClientTLS/preserves_debug_logging_transport264=== CONT TestStreamPushReportsSignatures265=== CONT TestDoWithRetry_FinalResponseBodyReadable266--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.04s)267=== CONT TestRetryTimeoutOutlastsMaxRetries2682026/11/01 17:33:36 INFO Garbage collection started269=== RUN TestFilterOversizedClosures/no_limit_keeps_everything270=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything271=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped272=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped273=== RUN TestFilterOversizedClosures/all_closures_skipped274=== PAUSE TestFilterOversizedClosures/all_closures_skipped275=== CONT TestStreamPushGivesUpOnDeadServer276=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive277=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive278=== RUN TestPathInfoCACompatibility/new_structured_format_-_text279=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text280=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method281=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method282=== CONT TestShellSplit283--- PASS: TestShellSplit (0.00s)284=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2852026/11/01 17:33:36 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:42323286=== CONT TestRateLimiterFeedback/429_enables_limiter287=== CONT TestStreamPushRequestLine288=== CONT TestStreamPushReportsEveryPath2892026/11/01 17:33:36 ERROR Upload failed error="connection refused" count=202902026/11/01 17:33:36 ERROR Server seems unavailable, giving up on batch untried=17291=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails292=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false293=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum294=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts295=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts2962026/11/01 17:33:36 ERROR Upload failed error=boom count=1297=== RUN TestPartSizeForNAR/1_TiB298=== PAUSE TestPartSizeForNAR/1_TiB299=== RUN TestPartSizeForNAR/5_TiB_S3_max_object3002026/11/01 17:33:36 WARN Rate limiter enabled after throttle name=server-test rate=5301=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object302=== RUN TestPartSizeForNAR/capped_at_5_GiB3032026/11/01 17:33:36 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:46163304=== PAUSE TestPartSizeForNAR/capped_at_5_GiB305=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter306=== CONT TestConvertHashToNix32/invalid_format307=== CONT TestConvertHashToNix32/already_Nix32_format308=== CONT TestEncodeNixBase32/test_string_hash309=== CONT TestEncodeNixBase32/empty_input3102026/11/01 17:33:36 WARN Rate limiter backed off name=server-test rate=5311=== CONT TestUploadMultipart_SupersededByPeer/exists312=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)313=== CONT TestUploadMultipart_SupersededByPeer/missing3142026/11/01 17:33:36 WARN Rate limiter enabled after throttle name=server-test rate=53152026/11/01 17:33:36 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:393833162026/11/01 17:33:36 WARN Rate limiter enabled after throttle name=s3-test rate=53172026/11/01 17:33:36 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:40137318=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha5123192026/11/01 17:33:36 WARN Rate limiter backed off name=server-test rate=5320=== CONT TestParsePathInfoJSON/Nix_format3212026/11/01 17:33:36 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:42323322=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI323=== CONT TestGetStorePathHash/valid_store_path324=== CONT TestSetClientTLS/rejects_connection_without_client_cert325=== CONT TestParsePathInfoJSON/invalid_JSON326=== CONT TestConvertHashToNix32/SRI_format_to_Nix32327=== CONT TestRateLimiterFeedback/503_enables_limiter328=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false329=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter330=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths331--- PASS: TestStreamPushReportsEveryPath (0.00s)332--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)333--- PASS: TestStreamPushReportsSignatures (0.00s)334=== CONT TestParsePathInfoJSON/whitespace_only335=== CONT TestParsePathInfoJSON/empty_input336=== CONT TestParsePathInfoJSON/Lix_format337=== CONT TestFilterOversizedClosures/no_limit_keeps_everything338=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error339=== CONT TestGetStorePathHash/basename_without_hyphen_should_error340=== CONT TestPathInfoCACompatibility/null_ca_field341=== CONT TestFilterOversizedClosures/all_closures_skipped3422026/11/01 17:33:36 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50343=== CONT TestSetClientTLS/preserves_debug_logging_transport3442026/11/01 17:33:36 ERROR Upload failed error=boom count=1345=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA3462026/11/01 17:33:36 INFO Garbage collection progress phase=running_on_another_replica failed_uploads_deleted=0 old_closures_deleted=0 objects_marked=0 objects_deleted=0 objects_failed=0347=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3482026/11/01 17:33:36 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000349=== CONT TestSupersededNARStillUploadsListing/small_NAR3502026/11/01 17:33:36 ERROR Upload failed error="bad path" count=3351=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon3522026/11/01 17:33:36 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:42323353=== CONT TestPathInfoCACompatibility/old_string_format_-_text3542026/11/01 17:33:36 INFO Uploading abc-hello (1.0GB)355=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method356=== CONT TestPartSizeForNAR/zero_stays_at_minimum357=== CONT TestPartSizeForNAR/capped_at_5_GiB358=== CONT TestPartSizeForNAR/1_TiB359=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts360=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum361=== CONT TestPartSizeForNAR/small_stays_at_minimum362=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails3632026/11/01 17:33:36 WARN Rate limiter enabled after throttle name=server-test rate=5364=== CONT TestPartSizeForNAR/5_TiB_S3_max_object3652026/11/01 17:33:36 WARN Garbage collection finished on another replica. Its statistics are not available here366=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive367=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error368=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true369=== CONT TestPathInfoCACompatibility/new_structured_format_-_text3702026/11/01 17:33:36 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:39713371=== PAUSE TestSetClientTLSErrors/missing_ca_file372--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.01s)3732026/11/01 17:33:36 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:42323374=== CONT TestSupersededNARStillUploadsListing/dump_cut_short3752026/11/01 17:33:36 WARN Rate limiter backed off name=server-test rate=5376=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true3772026/11/01 17:33:36 INFO Uploading abc-hello (1.0GB)378=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false379--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.00s)380=== RUN TestSetClientTLSErrors/invalid_ca_file381=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true382--- PASS: TestStreamPushStopsWhenCanceled (0.00s)383--- PASS: TestStreamPushIsolatesFailures (0.04s)3842026/11/01 17:33:36 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:42323385--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.05s)386--- PASS: TestPartSizeForNAR (0.08s)387 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)388 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)389 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)390 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)391 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)392 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)393 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)394--- PASS: TestParsePathInfoJSON (0.23s)395 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)396 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)397 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)398 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)399 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)400--- PASS: TestConvertHashToNix32 (0.19s)401 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)402 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)403 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)4042026/11/01 17:33:36 http: TLS handshake error from 127.0.0.1:41462: remote error: tls: bad certificate405--- PASS: TestFilterOversizedClosures (0.15s)406 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)407 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)408 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)409--- PASS: TestEncodeNixBase32 (0.23s)410 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)411 --- PASS: TestEncodeNixBase32/empty_input (0.00s)412=== PAUSE TestSetClientTLSErrors/invalid_ca_file413=== CONT TestSetClientTLSErrors/missing_cert_file414=== CONT TestSetClientTLSErrors/invalid_ca_file415--- PASS: TestParsePathInfoJSONMultiplePaths (0.19s)416 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)417 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)418--- PASS: TestPathInfoHashCompatibility (0.23s)419 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)420 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)421 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)422 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)423=== CONT TestSetClientTLSErrors/missing_ca_file424=== CONT TestSetClientTLSErrors/missing_key_file425--- PASS: TestStreamPushBatchesUnderLoad (0.02s)426 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.15s)427 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)428--- PASS: TestRateLimiterFeedback (0.04s)429 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)430 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)431 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)432 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)433--- PASS: TestGetStorePathHash (0.08s)434 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)435 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)436 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)437 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)438--- PASS: TestPathInfoCACompatibility (0.08s)439 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)440 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)441 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)442 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)443 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)444--- PASS: TestUploadMultipart_SupersededByPeer (0.08s)445 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)446 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.16s)447--- PASS: TestCaseHackSuffix (0.17s)448--- PASS: TestSetClientTLSErrors (0.26s)449 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)450 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)451 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)452 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)453--- PASS: TestSetClientTLS (0.10s)454 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.16s)455 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.16s)456 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.17s)4572026/11/01 17:33:36 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:423234582026/11/01 17:33:36 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:42323459--- PASS: TestStreamPushRequestLine (0.18s)4602026/11/01 17:33:36 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:423234612026/11/01 17:33:36 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:42323462--- PASS: TestRegisterUploadedObjectReusesConnections (0.18s)4632026/11/01 17:33:36 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:423234642026/11/01 17:33:36 WARN Rate limiter enabled after throttle name=s3-test rate=54652026/11/01 17:33:36 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:423234662026/11/01 17:33:36 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:423234672026/11/01 17:33:36 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:423234682026/11/01 17:33:36 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:42323469--- PASS: TestDumpPathWriterError (0.27s)4702026/11/01 17:33:36 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:423234712026/11/01 17:33:36 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:423234722026/11/01 17:33:36 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:423234732026/11/01 17:33:36 INFO Uploading abc-hello (1.0GB)4742026/11/01 17:33:36 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:423234752026/11/01 17:33:36 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:42323476--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.20s)4772026/11/01 17:33:36 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:42179/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:42179/part/2478--- PASS: TestDumpPathMatchesNix (0.32s)4792026/11/01 17:33:36 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:42179/part/3\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:42179/part/34802026/11/01 17:33:36 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:42179/part/4\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:42179/part/44812026/11/01 17:33:36 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:42179/part/5\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:42179/part/54822026/11/01 17:33:36 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:42179/part/6\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:42179/part/64832026/11/01 17:33:36 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"484--- PASS: TestSupersededNARStillUploadsListing (0.09s)485 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.16s)486 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.16s)487 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.71s)488--- PASS: TestUploadMultipart_FailedPartBufferNotReused (0.78s)489--- PASS: TestUploadMultipart_PartsInParallel (0.83s)4902026/11/01 17:33:37 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:46347/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:46347/api/uploads/complete4912026/11/01 17:33:37 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4922026/11/01 17:33:37 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:46347/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:46347/api/uploads/complete4932026/11/01 17:33:37 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4942026/11/01 17:33:37 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:46347/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:46347/api/uploads/complete4952026/11/01 17:33:37 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"496--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.01s)497--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.01s)498PASS499Running server tests...500The files belonging to this database system will be owned by user "nixbld".501This user must also own the server process.502503The database cluster will be initialized with locale "C".504The default database encoding has accordingly been set to "SQL_ASCII".505The default text search configuration will be set to "english".506507Data page checksums are enabled.508509creating directory /build/postgres2528121664/data ... ok510creating subdirectories ... ok511selecting dynamic shared memory implementation ... posix512selecting default "max_connections" ... 100513selecting default "shared_buffers" ... 128MB514selecting default time zone ... UTC515creating configuration files ... ok516running bootstrap script ... ok517performing post-bootstrap initialization ... ok518syncing data to disk ... ok519520initdb: warning: enabling "trust" authentication for local connections521initdb: 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.522523Success. You can now start the database server using:524525 pg_ctl -D /build/postgres2528121664/data -l logfile start526527/build/postgres2528121664:5432 - no response5282026-11-01 17:33:38.428 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit5292026-11-01 17:33:38.430 UTC [129] LOG: listening on Unix socket "/build/postgres2528121664/.s.PGSQL.5432"5302026-11-01 17:33:38.438 UTC [136] LOG: database system was shut down at 2026-11-01 17:33:38 UTC5312026-11-01 17:33:38.444 UTC [129] LOG: database system is ready to accept connections532/build/postgres2528121664:5432 - accepting connections533{"timestamp":"2026-11-01T17:33:38.841531152Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"8fc8741c-ea54-4541-99ae-3d158d2687f1","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(144)"}534=== RUN TestService_AuthMiddleware535=== PAUSE TestService_AuthMiddleware536=== RUN TestService_AuthMiddleware_MTLSProxyHeader537=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader538=== RUN TestService_AuthMiddleware_MTLSBoundSubjects539=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects540=== RUN TestService_ReadAuthMiddleware541=== PAUSE TestService_ReadAuthMiddleware542=== RUN TestService_AuthMiddleware_OIDC543=== PAUSE TestService_AuthMiddleware_OIDC544=== RUN TestService_RequireScope_OIDC545=== PAUSE TestService_RequireScope_OIDC546=== RUN TestService_ReadScope_PublicByDefault547=== PAUSE TestService_ReadScope_PublicByDefault548=== RUN TestCacheConfigHandler549=== PAUSE TestCacheConfigHandler550=== RUN TestCacheStatsHandler551=== PAUSE TestCacheStatsHandler552=== RUN TestClientCADerivations553=== PAUSE TestClientCADerivations554=== RUN TestClientErrorHandling555=== PAUSE TestClientErrorHandling556=== RUN TestClientIntegration557=== PAUSE TestClientIntegration558=== RUN TestClientMultipleUploads559=== PAUSE TestClientMultipleUploads560=== RUN TestClientWithDependencies561=== PAUSE TestClientWithDependencies562=== RUN TestClientSharedPathCommittedMidPush563=== PAUSE TestClientSharedPathCommittedMidPush564=== RUN TestPinProtectsFromGC565=== PAUSE TestPinProtectsFromGC566=== RUN TestClientPushesUseOnePush567=== PAUSE TestClientPushesUseOnePush568=== RUN TestClientFallsBackToClosures569=== PAUSE TestClientFallsBackToClosures570=== RUN TestDeleteClosuresRacingPins571=== PAUSE TestDeleteClosuresRacingPins572=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock573=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock574=== RUN TestResolveDBConnectionString575=== PAUSE TestResolveDBConnectionString576=== RUN TestConnectWaitsForAPeerMigration577=== PAUSE TestConnectWaitsForAPeerMigration578=== RUN TestLeadElectsOneAndHandsOver579=== PAUSE TestLeadElectsOneAndHandsOver580=== RUN TestLeadIncumbentWinsAfterRestart5812026/11/01 17:33:39 INFO lead: acquired remote=192.0.2.1:12345822026/11/01 17:33:39 INFO lead: released remote=192.0.2.1:12345832026/11/01 17:33:39 INFO lead: acquired remote=192.0.2.1:12345842026/11/01 17:33:40 INFO lead: released remote=192.0.2.1:1234585--- PASS: TestLeadIncumbentWinsAfterRestart (1.92s)586=== RUN TestLeadIncumbentAnnouncesAtOnce587=== PAUSE TestLeadIncumbentAnnouncesAtOnce588=== RUN TestLeadEndsOnShutdown589=== PAUSE TestLeadEndsOnShutdown590=== RUN TestLeadEndsWhenItsConnectionHangs5912026/11/01 17:33:41 INFO lead: acquired remote=192.0.2.1:12345922026-11-01 17:33:42.434 UTC [322] FATAL: terminating connection due to administrator command5932026/11/01 17:33:42 INFO lead: acquired remote=192.0.2.1:12345942026/11/01 17:33:43 WARN lead: lock connection lost error="timeout: context deadline exceeded"5952026/11/01 17:33:43 INFO lead: released remote=192.0.2.1:12345962026/11/01 17:33:44 INFO lead: released remote=192.0.2.1:1234597--- PASS: TestLeadEndsWhenItsConnectionHangs (3.17s)598=== RUN TestGCAdvisoryLockBlocksConcurrentRun599=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun600=== RUN TestGCBugBareHashReferences601=== PAUSE TestGCBugBareHashReferences602=== RUN TestGCMetrics603=== PAUSE TestGCMetrics604=== RUN TestPushDedupSurvivesConcurrentGC605=== PAUSE TestPushDedupSurvivesConcurrentGC606=== RUN TestDeduplicatedObjectsRecordedAsPending607=== PAUSE TestDeduplicatedObjectsRecordedAsPending608=== RUN TestGCSweepSkipsPendingObjects609=== PAUSE TestGCSweepSkipsPendingObjects610=== RUN TestTombstonedObjectOfferedWithoutWaiting611=== PAUSE TestTombstonedObjectOfferedWithoutWaiting612=== RUN TestGCSweepDeliversEachKeyOnce613=== PAUSE TestGCSweepDeliversEachKeyOnce614=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection615=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection616=== RUN TestForceGCDuringPushOffersSweptObject617=== PAUSE TestForceGCDuringPushOffersSweptObject618=== RUN TestFailedS3DeleteKeepsTombstone619=== PAUSE TestFailedS3DeleteKeepsTombstone620=== RUN TestSweepSkipsRowsLockedByPush621=== PAUSE TestSweepSkipsRowsLockedByPush622=== RUN TestRegisterCompletedObjectNeedsPendingRow623=== PAUSE TestRegisterCompletedObjectNeedsPendingRow624=== RUN TestGetExistingObjectsLocksRows625=== PAUSE TestGetExistingObjectsLocksRows626=== RUN TestSweepRechecksPendingAfterLocking627=== PAUSE TestSweepRechecksPendingAfterLocking628=== RUN TestPushWaitsForSweepHoldingRow629=== PAUSE TestPushWaitsForSweepHoldingRow630=== RUN TestCommitRacingPendingCleanupKeepsObjects631=== PAUSE TestCommitRacingPendingCleanupKeepsObjects632=== RUN TestGCEndsOnShutdown633=== PAUSE TestGCEndsOnShutdown634=== RUN TestGCTaskStore_StartNew635=== PAUSE TestGCTaskStore_StartNew636=== RUN TestGCTaskStore_DeduplicateSameParams637=== PAUSE TestGCTaskStore_DeduplicateSameParams638=== RUN TestGCTaskStore_ConflictDifferentParams639=== PAUSE TestGCTaskStore_ConflictDifferentParams640=== RUN TestGCTaskStore_GetEmpty641=== PAUSE TestGCTaskStore_GetEmpty642=== RUN TestGCTaskStore_GetReturnsLatest643=== PAUSE TestGCTaskStore_GetReturnsLatest644=== RUN TestGCTaskStore_CompletedAllowsNewTask645=== PAUSE TestGCTaskStore_CompletedAllowsNewTask646=== RUN TestGCTaskStore_PhaseUpdates647=== PAUSE TestGCTaskStore_PhaseUpdates648=== RUN TestGCTaskStore_Fail649=== PAUSE TestGCTaskStore_Fail650=== RUN TestGracefulShutdownDrainsInflight651=== PAUSE TestGracefulShutdownDrainsInflight652=== RUN TestService_healthCheckHandler653=== PAUSE TestService_healthCheckHandler654=== RUN TestService_readinessHandler655=== PAUSE TestService_readinessHandler656=== RUN TestGenerateLandingPage657=== PAUSE TestGenerateLandingPage658=== RUN TestCacheConfigHandlerMaxNarSize659=== PAUSE TestCacheConfigHandlerMaxNarSize660=== RUN TestCreatePendingClosureRejectsOversizedNAR661=== PAUSE TestCreatePendingClosureRejectsOversizedNAR662=== RUN TestNARDeduplicationMetadataUploadBug663=== PAUSE TestNARDeduplicationMetadataUploadBug664=== RUN TestMetricsInventory665=== PAUSE TestMetricsInventory666=== RUN TestMetricsCommit667=== PAUSE TestMetricsCommit668=== RUN TestService_NativeMTLS669=== PAUSE TestService_NativeMTLS670=== RUN TestServerTLSConfig671=== PAUSE TestServerTLSConfig672=== RUN TestMultipartCleanup673=== PAUSE TestMultipartCleanup674=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded675=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded676=== RUN TestPendingCleanupUsesOneCutoff677=== PAUSE TestPendingCleanupUsesOneCutoff678=== RUN TestObjectStatsTrigger679=== PAUSE TestObjectStatsTrigger680=== RUN TestObjectStatsUpdatedOncePerCommit681=== PAUSE TestObjectStatsUpdatedOncePerCommit682=== RUN TestOrphanedObjectsGC683=== PAUSE TestOrphanedObjectsGC684=== RUN TestOrphanedObjectsGCStressTest685=== PAUSE TestOrphanedObjectsGCStressTest686=== RUN TestCreatePin_ReservedPins687=== PAUSE TestCreatePin_ReservedPins688=== RUN TestPresentReportsOnlyClosureRoots689=== PAUSE TestPresentReportsOnlyClosureRoots690=== RUN TestPresentRefreshesOnlyStaleClosures691=== PAUSE TestPresentRefreshesOnlyStaleClosures692=== RUN TestPresentNotReportedWhileGCDeletesClosure693=== PAUSE TestPresentNotReportedWhileGCDeletesClosure694=== RUN TestParseSingleRange695=== PAUSE TestParseSingleRange696=== RUN TestProxyHeadersOnlyTrustedOnSocket6972026/11/01 17:33:44 INFO Starting HTTP server address=proxy.sock6982026/11/01 17:33:44 INFO Starting HTTP server address=127.0.0.1:421936992026/11/01 17:33:44 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7002026/11/01 17:33:44 INFO Shutdown signal received, draining in-flight requests timeout=10s701--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.24s)702=== RUN TestIsValidCachePath703=== PAUSE TestIsValidCachePath704=== RUN TestReadProxyNarinfo705=== PAUSE TestReadProxyNarinfo706=== RUN TestReadProxyNarinfoAlreadyDecompressed707=== PAUSE TestReadProxyNarinfoAlreadyDecompressed708=== RUN TestReadProxyContentNegotiation709=== PAUSE TestReadProxyContentNegotiation710=== RUN TestReadProxyNarStreaming711=== PAUSE TestReadProxyNarStreaming712=== RUN TestReadProxy404713=== PAUSE TestReadProxy404714=== RUN TestReadProxyInvalidPath715=== PAUSE TestReadProxyInvalidPath716=== RUN TestReadProxyHead717=== PAUSE TestReadProxyHead718=== RUN TestReadProxyOutlastsServerWriteTimeout719=== PAUSE TestReadProxyOutlastsServerWriteTimeout720=== RUN TestReadProxyConditionalGet721=== PAUSE TestReadProxyConditionalGet722=== RUN TestReadProxyRootRedirectsToIndexHTML723=== PAUSE TestReadProxyRootRedirectsToIndexHTML724=== RUN TestReadProxyDisabled725=== PAUSE TestReadProxyDisabled726=== RUN TestReadRedirectNar727=== PAUSE TestReadRedirectNar728=== RUN TestReadRedirectKeepsNarinfoProxied729=== PAUSE TestReadRedirectKeepsNarinfoProxied730=== RUN TestReadProxyRangeRequest731=== PAUSE TestReadProxyRangeRequest732=== RUN TestReadRedirectUsesPublicS3URL733=== PAUSE TestReadRedirectUsesPublicS3URL734=== RUN TestPush_OverlappingRootsStoreOneRowPerKey735=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey736=== RUN TestPush_CompleteCommitsEveryRoot737=== PAUSE TestPush_CompleteCommitsEveryRoot738=== RUN TestPush_RepeatedRootCommitsOnce739=== PAUSE TestPush_RepeatedRootCommitsOnce740=== RUN TestPush_CompleteWaitsForCleanupOfThePush741=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush742=== RUN TestPush_RootsAreLockedInByteOrder743=== PAUSE TestPush_RootsAreLockedInByteOrder744=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit745=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit746=== RUN TestPush_RejectsBadRequests747=== PAUSE TestPush_RejectsBadRequests748=== RUN TestPush_SignsNarinfosOfItsPendingObjects749=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects750=== RUN TestRedundantMultipartUpload751=== PAUSE TestRedundantMultipartUpload752=== RUN TestCompleteMultipartUpload_ErrorButObjectExists753=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists754=== RUN TestCompletedNarNotReofferedAcrossClosures755=== PAUSE TestCompletedNarNotReofferedAcrossClosures756=== RUN TestPresignedUploadRegisteredBeforeCommit757=== PAUSE TestPresignedUploadRegisteredBeforeCommit758=== RUN TestService_Rustfstest759=== PAUSE TestService_Rustfstest760=== RUN TestParseSize761=== PAUSE TestParseSize762=== RUN TestSkippedUploadsHandler763=== PAUSE TestSkippedUploadsHandler764=== RUN TestSystemdListenerNotActivated765--- PASS: TestSystemdListenerNotActivated (0.00s)766=== RUN TestWatchdogBeatsWhenHealthy767--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)768=== RUN TestWatchdogSkipsWhenUnhealthy7692026/11/01 17:33:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7702026/11/01 17:33:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7712026/11/01 17:33:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7722026/11/01 17:33:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7732026/11/01 17:33:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7742026/11/01 17:33:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7752026/11/01 17:33:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7762026/11/01 17:33:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7772026/11/01 17:33:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7782026/11/01 17:33:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"779--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)780=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle781=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle782=== RUN TestProxyWriteTimeout783=== PAUSE TestProxyWriteTimeout784=== RUN TestPendingClosureWriteTimeout785=== PAUSE TestPendingClosureWriteTimeout786=== RUN TestIsValidUploadKey787=== PAUSE TestIsValidUploadKey788=== RUN TestUploadHandlersRejectInvalidKeys789=== PAUSE TestUploadHandlersRejectInvalidKeys790=== RUN TestUploadHandlersRejectOversizedBody791=== PAUSE TestUploadHandlersRejectOversizedBody792=== RUN TestService_cleanupPendingClosuresHandler793=== PAUSE TestService_cleanupPendingClosuresHandler794=== RUN TestService_createPendingClosureHandler795=== PAUSE TestService_createPendingClosureHandler796=== RUN TestService_verifyS3Integrity797=== PAUSE TestService_verifyS3Integrity798=== RUN TestCompleteMultipartUnregistered799=== PAUSE TestCompleteMultipartUnregistered800=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT801=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT802=== CONT TestService_AuthMiddleware803=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT804=== CONT TestParseSingleRange805=== CONT TestReadRedirectKeepsNarinfoProxied806=== CONT TestReadRedirectNar807=== CONT TestReadProxyDisabled808=== CONT TestReadProxyRootRedirectsToIndexHTML809=== CONT TestReadProxyConditionalGet810=== CONT TestReadProxyOutlastsServerWriteTimeout811=== CONT TestReadProxyHead812=== CONT TestReadProxyInvalidPath813=== CONT TestReadProxy404814=== CONT TestReadProxyNarStreaming815=== CONT TestReadProxyNarinfoAlreadyDecompressed816=== CONT TestReadProxyNarinfo817=== CONT TestIsValidCachePath818=== RUN TestIsValidCachePath/narinfo819=== PAUSE TestIsValidCachePath/narinfo820=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars821=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars822=== RUN TestIsValidCachePath/nar_zst823=== PAUSE TestIsValidCachePath/nar_zst824=== RUN TestIsValidCachePath/nar_xz825=== CONT TestService_Rustfstest826=== CONT TestCompleteMultipartUnregistered827=== CONT TestService_verifyS3Integrity828=== CONT TestService_createPendingClosureHandler829=== CONT TestService_cleanupPendingClosuresHandler830=== CONT TestUploadHandlersRejectOversizedBody831=== CONT TestUploadHandlersRejectInvalidKeys832=== CONT TestReadProxyRangeRequest833=== RUN TestParseSingleRange/none834=== PAUSE TestIsValidCachePath/nar_xz835=== RUN TestIsValidCachePath/nar_bz2836=== PAUSE TestIsValidCachePath/nar_bz2837=== RUN TestIsValidCachePath/nar_uncompressed838=== PAUSE TestIsValidCachePath/nar_uncompressed839=== RUN TestIsValidCachePath/ls840=== PAUSE TestIsValidCachePath/ls841=== RUN TestIsValidCachePath/log842=== PAUSE TestIsValidCachePath/log843=== RUN TestIsValidCachePath/realisation844=== PAUSE TestIsValidCachePath/realisation845=== RUN TestIsValidCachePath/nix-cache-info846=== PAUSE TestIsValidCachePath/nix-cache-info847=== RUN TestIsValidCachePath/index.html848=== PAUSE TestIsValidCachePath/index.html849=== RUN TestIsValidCachePath/traversal_parent850=== PAUSE TestIsValidCachePath/traversal_parent851=== RUN TestIsValidCachePath/traversal_in_middle852=== PAUSE TestIsValidCachePath/traversal_in_middle853=== RUN TestIsValidCachePath/invalid_char_e854=== PAUSE TestIsValidCachePath/invalid_char_e855=== RUN TestIsValidCachePath/invalid_char_u856=== PAUSE TestIsValidCachePath/invalid_char_u857=== RUN TestIsValidCachePath/random_path858=== PAUSE TestIsValidCachePath/random_path859=== RUN TestIsValidCachePath/empty860=== PAUSE TestIsValidCachePath/empty861=== RUN TestIsValidCachePath/leading_slash862=== PAUSE TestIsValidCachePath/leading_slash863=== RUN TestIsValidCachePath/wrong_extension864=== PAUSE TestIsValidCachePath/wrong_extension865=== RUN TestIsValidCachePath/short_hash866=== PAUSE TestIsValidCachePath/short_hash867=== CONT TestIsValidUploadKey868=== RUN TestIsValidUploadKey/narinfo869=== PAUSE TestIsValidUploadKey/narinfo870=== RUN TestIsValidUploadKey/nar_zst871=== PAUSE TestIsValidUploadKey/nar_zst872=== RUN TestIsValidUploadKey/nar_xz873=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info874=== PAUSE TestIsValidUploadKey/nar_xz875=== RUN TestIsValidUploadKey/nar_plain876=== PAUSE TestParseSingleRange/none877=== RUN TestParseSingleRange/unknown_unit878=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info879=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal880=== PAUSE TestIsValidUploadKey/nar_plain881=== RUN TestIsValidUploadKey/listing882=== PAUSE TestIsValidUploadKey/listing883=== RUN TestIsValidUploadKey/build_log884=== PAUSE TestIsValidUploadKey/build_log885=== RUN TestIsValidUploadKey/build_log_home-manager_file886=== PAUSE TestIsValidUploadKey/build_log_home-manager_file887=== RUN TestIsValidUploadKey/build_log_plus_in_name888=== PAUSE TestIsValidUploadKey/build_log_plus_in_name889=== RUN TestIsValidUploadKey/build_log_question_mark890=== PAUSE TestIsValidUploadKey/build_log_question_mark891=== RUN TestIsValidUploadKey/build_log_equals892=== PAUSE TestIsValidUploadKey/build_log_equals893=== RUN TestIsValidUploadKey/realisation894=== PAUSE TestIsValidUploadKey/realisation895=== RUN TestIsValidUploadKey/realisation_plus_in_output896=== PAUSE TestIsValidUploadKey/realisation_plus_in_output897=== RUN TestIsValidUploadKey/nix-cache-info898=== PAUSE TestIsValidUploadKey/nix-cache-info899=== RUN TestIsValidUploadKey/index.html900=== PAUSE TestIsValidUploadKey/index.html901=== RUN TestIsValidUploadKey/narinfo_key,_nar_type902=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type903=== RUN TestIsValidUploadKey/nar_key,_narinfo_type904=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type905=== RUN TestIsValidUploadKey/listing_key,_narinfo_type906=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type907=== RUN TestIsValidUploadKey/traversal908=== PAUSE TestIsValidUploadKey/traversal909=== RUN TestIsValidUploadKey/traversal_nar910=== PAUSE TestIsValidUploadKey/traversal_nar911=== RUN TestIsValidUploadKey/absolute912=== PAUSE TestIsValidUploadKey/absolute913=== RUN TestIsValidUploadKey/empty_key914=== PAUSE TestIsValidUploadKey/empty_key915=== RUN TestIsValidUploadKey/unknown_type916=== PAUSE TestIsValidUploadKey/unknown_type917=== PAUSE TestParseSingleRange/unknown_unit918=== RUN TestParseSingleRange/multi-range_ignored919=== PAUSE TestParseSingleRange/multi-range_ignored920=== RUN TestParseSingleRange/malformed_no_dash921=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal922=== PAUSE TestParseSingleRange/malformed_no_dash923=== RUN TestParseSingleRange/malformed_both_empty924=== PAUSE TestParseSingleRange/malformed_both_empty925=== RUN TestParseSingleRange/malformed_end_before_start926=== PAUSE TestParseSingleRange/malformed_end_before_start927=== RUN TestParseSingleRange/closed928=== PAUSE TestParseSingleRange/closed929=== RUN TestParseSingleRange/open-ended930=== PAUSE TestParseSingleRange/open-ended931=== RUN TestParseSingleRange/end_clamped_to_size932=== PAUSE TestParseSingleRange/end_clamped_to_size933=== RUN TestParseSingleRange/suffix934=== PAUSE TestParseSingleRange/suffix935=== RUN TestParseSingleRange/suffix_exceeds_size936=== PAUSE TestParseSingleRange/suffix_exceeds_size937=== RUN TestParseSingleRange/single_byte938=== PAUSE TestParseSingleRange/single_byte939=== RUN TestParseSingleRange/start_past_EOF940=== PAUSE TestParseSingleRange/start_past_EOF941=== RUN TestParseSingleRange/start_far_past_EOF942=== PAUSE TestParseSingleRange/start_far_past_EOF943=== CONT TestPendingClosureWriteTimeout944=== RUN TestPendingClosureWriteTimeout/empty945=== PAUSE TestPendingClosureWriteTimeout/empty946=== RUN TestPendingClosureWriteTimeout/400_objects947=== PAUSE TestPendingClosureWriteTimeout/400_objects948=== RUN TestPendingClosureWriteTimeout/670k_objects949=== PAUSE TestPendingClosureWriteTimeout/670k_objects950=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline951=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline952=== CONT TestProxyWriteTimeout953=== RUN TestProxyWriteTimeout/narinfo954=== PAUSE TestProxyWriteTimeout/narinfo955=== RUN TestProxyWriteTimeout/1_GiB_nar956=== PAUSE TestProxyWriteTimeout/1_GiB_nar957=== RUN TestProxyWriteTimeout/10_GiB_nar958=== PAUSE TestProxyWriteTimeout/10_GiB_nar959=== RUN TestProxyWriteTimeout/unknown_size960=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key961=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure962=== PAUSE TestProxyWriteTimeout/unknown_size963=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle964=== CONT TestReadProxyContentNegotiation965=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key966=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key967=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key968=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure969=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart970=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart971=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts972=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts973=== CONT TestSkippedUploadsHandler9742026/11/01 17:33:45 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000975=== CONT TestParseSize976--- PASS: TestParseSize (0.00s)977=== CONT TestDeduplicatedObjectsRecordedAsPending978--- PASS: TestSkippedUploadsHandler (0.01s)979=== CONT TestMetricsInventory980--- PASS: TestReadProxyHead (2.03s)981=== CONT TestCreatePendingClosureRejectsOversizedNAR9822026/11/01 17:33:46 INFO Received uploads request method=POST path=/api/pending_closures983--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)984=== CONT TestCacheConfigHandlerMaxNarSize985--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)986=== CONT TestGenerateLandingPage987--- PASS: TestGenerateLandingPage (0.01s)988=== CONT TestService_readinessHandler989--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.10s)990=== CONT TestService_healthCheckHandler991--- PASS: TestReadRedirectKeepsNarinfoProxied (2.18s)992=== CONT TestGracefulShutdownDrainsInflight9932026/11/01 17:33:46 INFO Starting HTTP server address=127.0.0.1:367899942026/11/01 17:33:46 INFO Shutdown signal received, draining in-flight requests timeout=10s995--- PASS: TestGracefulShutdownDrainsInflight (0.07s)996=== CONT TestGCTaskStore_Fail997--- PASS: TestGCTaskStore_Fail (0.00s)998=== CONT TestGCTaskStore_PhaseUpdates999--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1000=== CONT TestGCTaskStore_CompletedAllowsNewTask1001--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1002=== CONT TestGCTaskStore_GetReturnsLatest1003--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1004=== CONT TestGCTaskStore_GetEmpty1005--- PASS: TestGCTaskStore_GetEmpty (0.00s)1006=== CONT TestGCTaskStore_ConflictDifferentParams1007--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1008=== CONT TestGCTaskStore_DeduplicateSameParams1009--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1010=== CONT TestGCTaskStore_StartNew1011--- PASS: TestGCTaskStore_StartNew (0.00s)1012=== CONT TestGCEndsOnShutdown1013=== RUN TestGCEndsOnShutdown/before_the_run1014=== PAUSE TestGCEndsOnShutdown/before_the_run1015=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1016=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1017=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1018=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1019=== CONT TestCommitRacingPendingCleanupKeepsObjects1020--- PASS: TestReadRedirectNar (2.26s)1021=== CONT TestPushWaitsForSweepHoldingRow10222026/11/01 17:33:46 INFO Received cleanup request method=DELETE path=/api/pending_closures10232026/11/01 17:33:46 INFO Aborted multipart uploads count=0 kept=010242026/11/01 17:33:46 INFO Received uploads request method=POST path=/api/pending_closures10252026/11/01 17:33:46 INFO Received uploads request method=POST path=/api/pending_closures10262026/11/01 17:33:46 INFO Received cleanup request method=DELETE path=/api/pending_closures1027--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (2.40s)1028=== CONT TestSweepRechecksPendingAfterLocking10292026/11/01 17:33:46 INFO Aborted multipart uploads count=1 kept=010302026/11/01 17:33:46 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1031--- PASS: TestService_AuthMiddleware (2.41s)1032=== CONT TestGetExistingObjectsLocksRows10332026/11/01 17:33:46 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10342026-11-01 17:33:46.941 UTC [404] ERROR: Closure does not exist: id=110352026-11-01 17:33:46.941 UTC [404] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE10362026-11-01 17:33:46.941 UTC [404] STATEMENT: -- name: CommitPendingClosure :one1037 SELECT commit_pending_closure($1::bigint)::bigint1038 1039--- PASS: TestService_cleanupPendingClosuresHandler (2.39s)1040=== CONT TestRegisterCompletedObjectNeedsPendingRow1041--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.55s)1042=== CONT TestGCSweepSkipsPendingObjects1043--- PASS: TestService_Rustfstest (2.61s)1044=== CONT TestSweepSkipsRowsLockedByPush1045--- PASS: TestReadProxy404 (2.66s)1046=== CONT TestFailedS3DeleteKeepsTombstone1047--- PASS: TestReadProxyDisabled (2.72s)1048=== CONT TestForceGCDuringPushOffersSweptObject1049=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1050=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1051=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1052=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1053=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10542026/11/01 17:33:47 INFO Received uploads request method=POST path=/api/pending_closures10552026/11/01 17:33:47 INFO Received uploads request method=POST path=/api/pending_closures10562026/11/01 17:33:47 INFO Received uploads request method=POST path=/api/pending_closures10572026/11/01 17:33:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10582026/11/01 17:33:47 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1059--- PASS: TestCompleteMultipartUnregistered (2.97s)1060=== CONT TestGCSweepDeliversEachKeyOnce10612026/11/01 17:33:47 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1062--- PASS: TestReadProxyNarinfo (3.02s)1063=== CONT TestTombstonedObjectOfferedWithoutWaiting1064--- PASS: TestReadProxyRangeRequest (3.07s)1065=== CONT TestObjectStatsUpdatedOncePerCommit1066--- PASS: TestReadProxyConditionalGet (3.17s)1067=== CONT TestPresentNotReportedWhileGCDeletesClosure1068=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1069=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1070=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1071=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1072=== CONT TestPresentRefreshesOnlyStaleClosures10732026/11/01 17:33:47 INFO Received uploads request method=POST path=/api/pending_closures10742026/11/01 17:33:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10752026/11/01 17:33:47 INFO Received uploads request method=POST path=/api/pending_closures1076--- PASS: TestReadProxyContentNegotiation (2.97s)1077=== CONT TestPresentReportsOnlyClosureRoots10782026/11/01 17:33:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1079--- PASS: TestReadProxyNarStreaming (3.53s)1080=== CONT TestCreatePin_ReservedPins1081--- PASS: TestReadProxyInvalidPath (3.57s)1082=== CONT TestOrphanedObjectsGCStressTest10832026/11/01 17:33:48 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NTQyYjFhNzgtM2FkZC00YTM2LWIyNzItNTA5MWNlMmFiNWUzLmRhZTAyOGZmLWQ2N2ItNGEzNy1hMzM1LTVjYWJmYjZjZmU1ZXgxNzkzNTU0NDI3MzM2MTIwMTE4 parts=1010842026/11/01 17:33:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10852026/11/01 17:33:48 INFO Completed upload id=1 objects=2 duration=5.669391ms10862026/11/01 17:33:48 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010872026/11/01 17:33:48 INFO Received uploads request method=POST path=/api/pending_closures10882026/11/01 17:33:48 INFO Starting cleanup of old closures method=DELETE path=/api/closures10892026/11/01 17:33:48 INFO Aborted multipart uploads count=0 kept=010902026/11/01 17:33:48 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=010912026/11/01 17:33:48 INFO Vacuumed table table=pending_closures10922026/11/01 17:33:48 INFO Vacuumed table table=pending_objects10932026/11/01 17:33:48 INFO Vacuumed table table=multipart_uploads10942026/11/01 17:33:48 INFO Vacuumed table table=closures1095--- PASS: TestMetricsInventory (3.20s)1096=== CONT TestOrphanedObjectsGC10972026/11/01 17:33:48 INFO Vacuumed table table=objects10982026/11/01 17:33:48 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001099--- PASS: TestService_createPendingClosureHandler (3.69s)1100=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit11012026/11/01 17:33:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38509/oidc11022026/11/01 17:33:48 INFO Received uploads request method=POST path=/api/pending_closures1103--- PASS: TestDeduplicatedObjectsRecordedAsPending (3.29s)1104=== CONT TestPresignedUploadRegisteredBeforeCommit11052026/11/01 17:33:48 WARN readiness check failed error="closed pool"1106--- PASS: TestService_readinessHandler (1.77s)1107=== CONT TestCompletedNarNotReofferedAcrossClosures1108--- PASS: TestService_healthCheckHandler (1.79s)1109=== CONT TestCompleteMultipartUpload_ErrorButObjectExists11102026/11/01 17:33:48 INFO Received uploads request method=POST path=/api/pending_closures11112026/11/01 17:33:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11122026/11/01 17:33:48 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NTQyYjFhNzgtM2FkZC00YTM2LWIyNzItNTA5MWNlMmFiNWUzLmU1ZGJlOWRmLWVmMTgtNGRhZC1iY2E4LTVmNWZkM2VmYzM0MHgxNzkzNTU0NDI3OTc5MDQ5MDM0 parts=1011132026/11/01 17:33:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11142026/11/01 17:33:48 INFO Completed upload id=1 objects=2 duration=5.214651ms11152026/11/01 17:33:48 INFO Received uploads request method=POST path=/api/pending_closures11162026/11/01 17:33:48 INFO Received uploads request method=POST path=/api/pending_closures11172026/11/01 17:33:48 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo11182026/11/01 17:33:48 WARN Found objects in DB but missing from S3, will re-upload count=11119--- PASS: TestService_verifyS3Integrity (4.21s)1120=== CONT TestRedundantMultipartUpload11212026/11/01 17:33:48 INFO Aborted multipart uploads count=0 kept=011222026/11/01 17:33:48 WARN Force mode enabled - objects will be deleted immediately without grace period11232026/11/01 17:33:48 INFO Aborted multipart uploads count=0 kept=011242026/11/01 17:33:48 WARN Force mode enabled - objects will be deleted immediately without grace period1125--- PASS: TestGetExistingObjectsLocksRows (1.89s)1126=== CONT TestPush_SignsNarinfosOfItsPendingObjects11272026/11/01 17:33:48 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=011282026/11/01 17:33:48 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=011292026/11/01 17:33:48 INFO Vacuumed table table=pending_closures11302026/11/01 17:33:48 INFO Vacuumed table table=pending_objects11312026/11/01 17:33:48 INFO Vacuumed table table=pending_closures11322026/11/01 17:33:48 INFO Vacuumed table table=multipart_uploads11332026/11/01 17:33:48 INFO Vacuumed table table=closures11342026/11/01 17:33:48 INFO Vacuumed table table=objects11352026/11/01 17:33:48 INFO Vacuumed table table=pending_objects11362026/11/01 17:33:48 INFO Vacuumed table table=multipart_uploads11372026/11/01 17:33:48 INFO Vacuumed table table=closures11382026/11/01 17:33:48 INFO Vacuumed table table=objects1139--- PASS: TestSweepRechecksPendingAfterLocking (1.96s)1140=== CONT TestPush_RejectsBadRequests1141--- PASS: TestRegisterCompletedObjectNeedsPendingRow (1.95s)1142=== CONT TestPush_RepeatedRootCommitsOnce1143--- PASS: TestCommitRacingPendingCleanupKeepsObjects (2.12s)1144=== CONT TestPush_RootsAreLockedInByteOrder11452026/11/01 17:33:48 INFO Received uploads request method=POST path=/api/pending_closures11462026/11/01 17:33:49 INFO Aborted multipart uploads count=0 kept=011472026/11/01 17:33:49 INFO Aborted multipart uploads count=0 kept=011482026/11/01 17:33:49 INFO Received uploads request method=POST path=/api/pending_closures11492026/11/01 17:33:49 WARN Force mode enabled - objects will be deleted immediately without grace period11502026/11/01 17:33:49 WARN Force mode enabled - objects will be deleted immediately without grace period11512026/11/01 17:33:49 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/11/01 17:33:49 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=011532026/11/01 17:33:49 INFO Vacuumed table table=pending_closures11542026/11/01 17:33:49 INFO Vacuumed table table=pending_objects11552026/11/01 17:33:49 INFO Vacuumed table table=multipart_uploads11562026/11/01 17:33:49 INFO Vacuumed table table=closures11572026/11/01 17:33:49 INFO Vacuumed table table=pending_closures11582026/11/01 17:33:49 INFO Vacuumed table table=objects1159--- PASS: TestPushWaitsForSweepHoldingRow (2.32s)1160=== CONT TestPush_CompleteWaitsForCleanupOfThePush11612026/11/01 17:33:49 INFO Vacuumed table table=pending_objects11622026/11/01 17:33:49 INFO Vacuumed table table=multipart_uploads11632026/11/01 17:33:49 INFO Vacuumed table table=closures11642026/11/01 17:33:49 INFO Aborted multipart uploads count=0 kept=011652026/11/01 17:33:49 INFO Vacuumed table table=objects11662026/11/01 17:33:49 WARN Force mode enabled - objects will be deleted immediately without grace period1167--- PASS: TestGCSweepSkipsPendingObjects (2.06s)1168=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded11692026/11/01 17:33:49 INFO Received uploads request method=POST path=/api/pending_closures11702026/11/01 17:33:49 INFO Aborted multipart uploads count=0 kept=011712026/11/01 17:33:49 WARN Force mode enabled - objects will be deleted immediately without grace period11722026/11/01 17:33:49 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/11/01 17:33:49 INFO Vacuumed table table=pending_closures11742026/11/01 17:33:49 INFO Vacuumed table table=pending_objects11752026/11/01 17:33:49 INFO Vacuumed table table=multipart_uploads11762026/11/01 17:33:49 INFO Vacuumed table table=closures11772026/11/01 17:33:49 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."11782026/11/01 17:33:49 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."11792026/11/01 17:33:49 INFO Vacuumed table table=objects1180--- PASS: TestSweepSkipsRowsLockedByPush (2.14s)1181--- PASS: TestFailedS3DeleteKeepsTombstone (2.09s)1182=== CONT TestNARDeduplicationMetadataUploadBug1183=== CONT TestObjectStatsTrigger11842026/11/01 17:33:49 INFO Received uploads request method=POST path=/api/pending_closures1185--- PASS: TestTombstonedObjectOfferedWithoutWaiting (1.75s)1186=== CONT TestPendingCleanupUsesOneCutoff11872026/11/01 17:33:49 INFO Aborted multipart uploads count=0 kept=011882026/11/01 17:33:49 WARN Force mode enabled - objects will be deleted immediately without grace period1189--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (2.13s)1190=== CONT TestPinProtectsFromGC1191--- PASS: TestPresentRefreshesOnlyStaleClosures (1.70s)1192=== CONT TestPushDedupSurvivesConcurrentGC1193--- PASS: TestObjectStatsUpdatedOncePerCommit (1.87s)1194=== CONT TestGCMetrics11952026/11/01 17:33:49 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=011962026/11/01 17:33:49 INFO Vacuumed table table=pending_closures11972026/11/01 17:33:49 INFO Vacuumed table table=pending_objects11982026/11/01 17:33:49 INFO Vacuumed table table=multipart_uploads11992026/11/01 17:33:49 INFO Vacuumed table table=closures12002026/11/01 17:33:49 INFO Vacuumed table table=objects1201--- PASS: TestGCSweepDeliversEachKeyOnce (2.03s)1202=== CONT TestGCBugBareHashReferences1203--- PASS: TestPresentReportsOnlyClosureRoots (1.61s)1204=== CONT TestGCAdvisoryLockBlocksConcurrentRun12052026/11/01 17:33:49 INFO Received push request method=POST path=/api/pushes12062026/11/01 17:33:49 INFO Received uploads request method=POST path=/api/pending_closures12072026/11/01 17:33:49 INFO Received complete push request method=POST path=/api/pushes/1/complete12082026/11/01 17:33:49 INFO Completed push id=1 objects=4 duration=36.887728ms12092026/11/01 17:33:49 INFO Received push request method=POST path=/api/pushes12102026/11/01 17:33:49 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst12112026/11/01 17:33:49 INFO Received uploads request method=POST path=/api/pending_closures12122026/11/01 17:33:49 INFO Received uploads request method=POST path=/api/pending_closures1213--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.52s)1214=== CONT TestLeadEndsOnShutdown12152026/11/01 17:33:49 INFO Aborted multipart uploads count=0 kept=012162026/11/01 17:33:49 WARN Force mode enabled - objects will be deleted immediately without grace period12172026/11/01 17:33:49 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12182026/11/01 17:33:49 WARN Refused reserved pin name=worker-x86_64-linux12192026/11/01 17:33:49 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12202026/11/01 17:33:49 INFO Received create pin request method=POST path=/api/pins/my-app12212026/11/01 17:33:49 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1222--- PASS: TestCreatePin_ReservedPins (1.85s)1223=== CONT TestLeadIncumbentAnnouncesAtOnce12242026/11/01 17:33:49 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=012252026/11/01 17:33:49 INFO Vacuumed table table=pending_closures12262026/11/01 17:33:49 INFO Vacuumed table table=pending_objects12272026/11/01 17:33:49 INFO Vacuumed table table=multipart_uploads12282026/11/01 17:33:49 INFO Vacuumed table table=closures12292026/11/01 17:33:49 INFO Vacuumed table table=objects12302026/11/01 17:33:49 INFO Received uploads request method=POST path=/api/pending_closures12312026/11/01 17:33:49 INFO Received complete push request method=POST path=/api/pushes/2/complete12322026/11/01 17:33:49 INFO Completed push id=2 objects=4 duration=9.521832ms1233--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (1.73s)1234=== CONT TestLeadElectsOneAndHandsOver12352026/11/01 17:33:50 INFO Received uploads request method=POST path=/api/pending_closures12362026/11/01 17:33:50 INFO Received uploads request method=POST path=/api/pending_closures12372026/11/01 17:33:50 INFO Received push request method=POST path=/api/pushes12382026/11/01 17:33:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12392026/11/01 17:33:50 INFO Signed narinfos id=1 count=112402026/11/01 17:33:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12412026/11/01 17:33:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12422026/11/01 17:33:50 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"12432026/11/01 17:33:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12442026/11/01 17:33:50 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"12452026/11/01 17:33:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12462026/11/01 17:33:50 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=112472026/11/01 17:33:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12482026/11/01 17:33:50 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1249--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (1.29s)1250=== CONT TestConnectWaitsForAPeerMigration12512026/11/01 17:33:50 INFO Received push request method=POST path=/api/pushes1252=== RUN TestPush_RejectsBadRequests/no_roots1253=== PAUSE TestPush_RejectsBadRequests/no_roots1254=== RUN TestPush_RejectsBadRequests/no_objects1255=== PAUSE TestPush_RejectsBadRequests/no_objects1256=== RUN TestPush_RejectsBadRequests/bad_root1257=== PAUSE TestPush_RejectsBadRequests/bad_root1258=== RUN TestPush_RejectsBadRequests/root_not_in_objects1259=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1260=== CONT TestResolveDBConnectionString1261=== RUN TestResolveDBConnectionString/flag_wins1262=== PAUSE TestResolveDBConnectionString/flag_wins1263=== RUN TestResolveDBConnectionString/file_when_flag_empty1264=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1265=== RUN TestResolveDBConnectionString/missing_file_is_an_error1266=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1267=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1268=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1269=== RUN TestResolveDBConnectionString/nothing_configured1270=== PAUSE TestResolveDBConnectionString/nothing_configured1271=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock12722026-11-01 17:33:50.222 UTC [584] ERROR: could not obtain lock on row in relation "closures"12732026-11-01 17:33:50.222 UTC [584] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12742026-11-01 17:33:50.223 UTC [584] ERROR: could not obtain lock on row in relation "closures"12752026-11-01 17:33:50.223 UTC [584] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12762026-11-01 17:33:50.224 UTC [584] ERROR: could not obtain lock on row in relation "closures"12772026-11-01 17:33:50.224 UTC [584] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12782026-11-01 17:33:50.224 UTC [584] ERROR: could not obtain lock on row in relation "closures"12792026-11-01 17:33:50.224 UTC [584] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12802026-11-01 17:33:50.226 UTC [584] ERROR: could not obtain lock on row in relation "closures"12812026-11-01 17:33:50.226 UTC [584] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1282--- PASS: TestPush_RootsAreLockedInByteOrder (1.34s)1283=== CONT TestDeleteClosuresRacingPins12842026/11/01 17:33:50 INFO Received push request method=POST path=/api/pushes1285=== NAME TestOrphanedObjectsGC1286 orphaned_objects_gc_test.go:287: GC Test Summary:1287 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1288 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1289 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1290 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1291 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1292--- PASS: TestOrphanedObjectsGC (2.07s)1293=== CONT TestClientFallsBackToClosures12942026/11/01 17:33:50 INFO Received complete push request method=POST path=/api/pushes/1/complete12952026/11/01 17:33:50 INFO Received push request method=POST path=/api/pushes12962026/11/01 17:33:50 INFO Completed push id=1 objects=4 duration=42.924369ms1297--- PASS: TestPush_RepeatedRootCommitsOnce (1.46s)1298=== CONT TestClientPushesUseOnePush12992026/11/01 17:33:50 INFO Received uploads request method=POST path=/api/pending_closures13002026/11/01 17:33:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13012026/11/01 17:33:50 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NTQyYjFhNzgtM2FkZC00YTM2LWIyNzItNTA5MWNlMmFiNWUzLjFlMTNhOTIzLTMwOWEtNDA1Ny1iODUzLWE4ODhkMmVlODA1NngxNzkzNTU0NDI5OTY4NjEzNzA01302--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (1.29s)1303=== CONT TestCacheStatsHandler13042026/11/01 17:33:50 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NTQyYjFhNzgtM2FkZC00YTM2LWIyNzItNTA5MWNlMmFiNWUzLjFlMTNhOTIzLTMwOWEtNDA1Ny1iODUzLWE4ODhkMmVlODA1NngxNzkzNTU0NDI5OTY4NjEzNzA0 parts=11305--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.05s)1306=== CONT TestClientSharedPathCommittedMidPush13072026/11/01 17:33:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1308--- PASS: TestObjectStatsTrigger (1.25s)1309=== CONT TestClientWithDependencies13102026/11/01 17:33:50 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NTQyYjFhNzgtM2FkZC00YTM2LWIyNzItNTA5MWNlMmFiNWUzLmUzN2FjMGRmLTI2NzctNDI3Yi1hNDkwLWQyNTJiZTNhMzQyZXgxNzkzNTU0NDI5ODM5OTAzNTQ2 parts=1213112026/11/01 17:33:50 INFO Received uploads request method=POST path=/api/pending_closures1312--- PASS: TestCompletedNarNotReofferedAcrossClosures (2.21s)1313=== CONT TestClientMultipleUploads13142026/11/01 17:33:50 INFO Received uploads request method=POST path=/api/pending_closures1315=== NAME TestNARDeduplicationMetadataUploadBug1316 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2599799516/001/store/8fx7azqq351c6b5in2s1cax5vgcjw5hq-file1.txt13172026/11/01 17:33:50 INFO Received uploads request method=POST path=/api/pending_closures13182026/11/01 17:33:50 INFO Received cleanup request method=DELETE path=/api/pending_closures13192026-11-01 17:33:50.674 UTC [608] ERROR: Push does not exist: id=113202026-11-01 17:33:50.674 UTC [608] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE13212026-11-01 17:33:50.674 UTC [608] STATEMENT: SELECT commit_push($1)1322--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.57s)1323=== CONT TestClientIntegration13242026/11/01 17:33:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13252026/11/01 17:33:50 INFO Received push request method=POST path=/api/pushes13262026/11/01 17:33:50 INFO Received uploads request method=POST path=/api/pending_closures13272026/11/01 17:33:50 INFO Aborted multipart uploads count=0 kept=013282026/11/01 17:33:50 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13292026/11/01 17:33:50 INFO Uploading 8fx7azqq351c6b5in2s1cax5vgcjw5hq-file1.txt (160B)13302026/11/01 17:33:50 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NTQyYjFhNzgtM2FkZC00YTM2LWIyNzItNTA5MWNlMmFiNWUzLjk1NGQ5ZTRjLTAxNDUtNDBhOC04MGViLThhMGJlYmY2ZGIwM3gxNzkzNTU0NDMwMDQxODk0NDE5 parts=1213312026/11/01 17:33:50 INFO Received uploads request method=POST path=/api/pending_closures13322026/11/01 17:33:50 WARN Force mode enabled - objects will be deleted immediately without grace period13332026/11/01 17:33:50 WARN Failed to register uploaded object key=8fx7azqq351c6b5in2s1cax5vgcjw5hq.ls error="server returned 404: 404 page not found\n"13342026/11/01 17:33:50 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=01335=== NAME TestPinProtectsFromGC1336 client_integration_test.go:778: Pinned store path: /build/TestPinProtectsFromGC3813179481/001/store/f8sqba2iqivyx8hcxigr6bkargbr654w-pinned-file.txt1337 client_integration_test.go:779: Unpinned store path: /build/TestPinProtectsFromGC3813179481/001/store/r3ildla4vwdggssva5lgxxdhyzcx0763-unpinned-file.txt13382026/11/01 17:33:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13392026/11/01 17:33:50 INFO Vacuumed table table=pending_closures13402026/11/01 17:33:50 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"13412026/11/01 17:33:50 INFO Signed narinfos id=1 count=113422026/11/01 17:33:50 INFO Vacuumed table table=pending_objects13432026/11/01 17:33:50 INFO Uploading 1 narinfos13442026/11/01 17:33:50 INFO Received uploads request method=POST path=/api/pending_closures13452026/11/01 17:33:50 INFO Vacuumed table table=multipart_uploads13462026/11/01 17:33:50 INFO Vacuumed table table=closures13472026/11/01 17:33:50 INFO Vacuumed table table=objects1348--- PASS: TestGCMetrics (1.27s)1349=== CONT TestClientErrorHandling1350=== RUN TestClientErrorHandling/InvalidStorePath1351=== PAUSE TestClientErrorHandling/InvalidStorePath1352=== RUN TestClientErrorHandling/InvalidAuthToken1353=== PAUSE TestClientErrorHandling/InvalidAuthToken1354=== RUN TestClientErrorHandling/ServerNotAvailable1355=== PAUSE TestClientErrorHandling/ServerNotAvailable1356=== CONT TestClientCADerivations13572026/11/01 17:33:50 INFO Received complete push request method=POST path=/api/pushes/1/complete13582026/11/01 17:33:50 WARN Failed to register uploaded object key=8fx7azqq351c6b5in2s1cax5vgcjw5hq.narinfo error="server returned 404: 404 page not found\n"13592026/11/01 17:33:50 INFO Completed push id=1 objects=3 duration=13.262603ms13602026/11/01 17:33:50 INFO Upload complete. (123ms)1361=== NAME TestNARDeduplicationMetadataUploadBug1362 metadata_upload_test.go:54: Retrieved narinfo from S3:1363 StorePath: /build/TestNARDeduplicationMetadataUploadBug2599799516/001/store/8fx7azqq351c6b5in2s1cax5vgcjw5hq-file1.txt1364 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1365 Compression: zstd1366 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1367 NarSize: 1601368 References: 1369 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1370 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1371 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1372 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}13732026/11/01 17:33:50 INFO Aborted multipart uploads count=0 kept=013742026/11/01 17:33:50 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"1375--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (1.26s)1376=== CONT TestPush_OverlappingRootsStoreOneRowPerKey13772026/11/01 17:33:50 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013782026/11/01 17:33:50 INFO Vacuumed table table=pending_closures1379=== NAME TestNARDeduplicationMetadataUploadBug1380 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2599799516/001/store/i6a6mxmsrixsjcxfx42kafqlbz52mcw5-file2.txt13812026/11/01 17:33:50 INFO Vacuumed table table=pending_objects13822026/11/01 17:33:50 INFO Vacuumed table table=multipart_uploads13832026/11/01 17:33:50 INFO Received push request method=POST path=/api/pushes13842026/11/01 17:33:50 INFO Vacuumed table table=closures13852026/11/01 17:33:50 INFO lead: acquired remote=192.0.2.1:123413862026/11/01 17:33:50 INFO Vacuumed table table=objects13872026/11/01 17:33:50 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13882026/11/01 17:33:50 INFO Uploading f8sqba2iqivyx8hcxigr6bkargbr654w-pinned-file.txt (128B)13892026/11/01 17:33:50 INFO Aborted multipart uploads count=0 kept=013902026/11/01 17:33:50 WARN Force mode enabled - objects will be deleted immediately without grace period13912026/11/01 17:33:50 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=013922026/11/01 17:33:50 WARN Failed to register uploaded object key=f8sqba2iqivyx8hcxigr6bkargbr654w.ls error="server returned 404: 404 page not found\n"13932026/11/01 17:33:50 INFO Vacuumed table table=pending_closures13942026/11/01 17:33:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13952026/11/01 17:33:50 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"13962026/11/01 17:33:50 INFO Signed narinfos id=1 count=113972026/11/01 17:33:50 INFO Vacuumed table table=pending_objects13982026/11/01 17:33:50 INFO Uploading 1 narinfos13992026/11/01 17:33:50 INFO Vacuumed table table=multipart_uploads14002026/11/01 17:33:50 INFO Vacuumed table table=closures14012026/11/01 17:33:50 INFO Vacuumed table table=objects1402--- PASS: TestPushDedupSurvivesConcurrentGC (1.52s)1403=== CONT TestPush_CompleteCommitsEveryRoot14042026/11/01 17:33:50 WARN Failed to register uploaded object key=f8sqba2iqivyx8hcxigr6bkargbr654w.narinfo error="server returned 404: 404 page not found\n"14052026/11/01 17:33:50 INFO Received complete push request method=POST path=/api/pushes/1/complete14062026/11/01 17:33:50 INFO lead: acquired remote=192.0.2.1:123414072026/11/01 17:33:50 INFO Completed push id=1 objects=3 duration=13.040733ms14082026/11/01 17:33:50 INFO lead: released remote=192.0.2.1:12341409--- PASS: TestLeadIncumbentAnnouncesAtOnce (1.02s)14102026/11/01 17:33:50 INFO Upload complete. (121ms)1411=== CONT TestReadRedirectUsesPublicS3URL14122026/11/01 17:33:50 INFO Received push request method=POST path=/api/pushes14132026/11/01 17:33:50 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)14142026/11/01 17:33:50 INFO lead: acquired remote=192.0.2.1:123414152026/11/01 17:33:50 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14162026/11/01 17:33:50 WARN Failed to register uploaded object key=i6a6mxmsrixsjcxfx42kafqlbz52mcw5.ls error="server returned 404: 404 page not found\n"14172026/11/01 17:33:50 INFO Signed narinfos id=2 count=114182026/11/01 17:33:50 INFO Uploading 1 narinfos14192026/11/01 17:33:50 INFO Received complete push request method=POST path=/api/pushes/2/complete14202026/11/01 17:33:51 WARN Failed to register uploaded object key=i6a6mxmsrixsjcxfx42kafqlbz52mcw5.narinfo error="server returned 404: 404 page not found\n"14212026/11/01 17:33:51 INFO Completed push id=2 objects=3 duration=5.680761ms14222026/11/01 17:33:51 INFO Upload complete. (99ms)1423=== NAME TestNARDeduplicationMetadataUploadBug1424 metadata_upload_test.go:76: Retrieved narinfo from S3:1425 StorePath: /build/TestNARDeduplicationMetadataUploadBug2599799516/001/store/i6a6mxmsrixsjcxfx42kafqlbz52mcw5-file2.txt1426 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1427 Compression: zstd1428 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1429 NarSize: 1601430 References: 1431 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1432 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1433 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1434 {"version":1,"root":{"type":"regular","size":44}}1435--- PASS: TestNARDeduplicationMetadataUploadBug (1.74s)1436=== CONT TestService_AuthMiddleware_OIDC14372026/11/01 17:33:51 INFO Received push request method=POST path=/api/pushes1438--- PASS: TestGCBugBareHashReferences (1.47s)1439=== CONT TestCacheConfigHandler1440=== RUN TestCacheConfigHandler/full_config,_no_issuer1441=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1442=== RUN TestCacheConfigHandler/no_cache_url_configured1443=== PAUSE TestCacheConfigHandler/no_cache_url_configured1444=== RUN TestCacheConfigHandler/no_signing_keys1445=== PAUSE TestCacheConfigHandler/no_signing_keys1446=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1447=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1448=== CONT TestService_ReadScope_PublicByDefault14492026/11/01 17:33:51 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14502026/11/01 17:33:51 INFO Uploading r3ildla4vwdggssva5lgxxdhyzcx0763-unpinned-file.txt (128B)14512026/11/01 17:33:51 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14522026/11/01 17:33:51 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"14532026/11/01 17:33:51 WARN Failed to register uploaded object key=r3ildla4vwdggssva5lgxxdhyzcx0763.ls error="server returned 404: 404 page not found\n"14542026/11/01 17:33:51 INFO Signed narinfos id=2 count=114552026/11/01 17:33:51 INFO Uploading 1 narinfos14562026/11/01 17:33:51 INFO Received complete push request method=POST path=/api/pushes/2/complete14572026/11/01 17:33:51 WARN Failed to register uploaded object key=r3ildla4vwdggssva5lgxxdhyzcx0763.narinfo error="server returned 404: 404 page not found\n"14582026/11/01 17:33:51 INFO Completed push id=2 objects=3 duration=6.345481ms14592026/11/01 17:33:51 INFO Upload complete. (101ms)14602026/11/01 17:33:51 INFO Starting cleanup of old closures method=DELETE path=/api/closures14612026/11/01 17:33:51 INFO Garbage collection started14622026/11/01 17:33:51 INFO Aborted multipart uploads count=0 kept=014632026/11/01 17:33:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42679/oidc14642026/11/01 17:33:51 WARN Force mode enabled - objects will be deleted immediately without grace period14652026/11/01 17:33:51 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=014662026/11/01 17:33:51 INFO Vacuumed table table=pending_closures14672026/11/01 17:33:51 INFO Vacuumed table table=pending_objects14682026/11/01 17:33:51 INFO Vacuumed table table=multipart_uploads14692026/11/01 17:33:51 INFO Vacuumed table table=closures14702026/11/01 17:33:51 INFO Vacuumed table table=objects14712026/11/01 17:33:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1472--- PASS: TestCacheStatsHandler (0.95s)1473=== CONT TestService_RequireScope_OIDC14742026/11/01 17:33:51 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NTQyYjFhNzgtM2FkZC00YTM2LWIyNzItNTA5MWNlMmFiNWUzLjRkMzYzNDgyLTMzMTktNDZjMS1iYzY2LTg1OWYyNTI4ZmVjNHgxNzkzNTU0NDMwNzYyNTg4MzYx error="Get \"http://127.0.0.1:1/bucket51/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"14752026/11/01 17:33:51 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NTQyYjFhNzgtM2FkZC00YTM2LWIyNzItNTA5MWNlMmFiNWUzLmE0OTc2OWQ4LTVhM2EtNDhjYS1iODgyLTRlNzhjYmYwZjE4OXgxNzkzNTU0NDMwNzQ0ODc5MjQ3 parts=1214762026/11/01 17:33:51 INFO Received cleanup request method=DELETE path=/api/pending_closures14772026/11/01 17:33:51 INFO Aborted multipart uploads count=1 kept=01478--- PASS: TestRedundantMultipartUpload (2.73s)1479=== CONT TestServerTLSConfig1480=== RUN TestServerTLSConfig/no_client_CA1481=== PAUSE TestServerTLSConfig/no_client_CA1482=== RUN TestServerTLSConfig/missing_CA_file1483=== PAUSE TestServerTLSConfig/missing_CA_file1484=== RUN TestServerTLSConfig/not_a_PEM_file1485=== PAUSE TestServerTLSConfig/not_a_PEM_file1486=== CONT TestMultipartCleanup1487--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.30s)1488=== CONT TestService_NativeMTLS14892026/11/01 17:33:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33133/oidc14902026/11/01 17:33:51 INFO Received uploads request method=POST path=/api/pending_closures14912026/11/01 17:33:51 INFO Received uploads request method=POST path=/api/pending_closures14922026/11/01 17:33:51 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14932026/11/01 17:33:51 INFO Uploading xlgjyjjxl3kz42z65f3iisr5iksz6kka-shared-dep (136B)14942026/11/01 17:33:51 INFO Uploading x62qbbxjg8a75vsg98c6ss3lrg760px3-b (216B)14952026/11/01 17:33:51 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14962026/11/01 17:33:51 WARN Failed to register uploaded object key=nar/0ajffjrwx4l52l1gpz4anziaf8imy3y8405rb4f146q08b0si8l5.nar.zst error="server returned 404: 404 page not found\n"14972026/11/01 17:33:51 WARN Failed to register uploaded object key=avapz8qp74h1bnvc9cpsk9mivg06f1dv.ls error="server returned 404: 404 page not found\n"14982026/11/01 17:33:51 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14992026/11/01 17:33:51 WARN Failed to register uploaded object key=x62qbbxjg8a75vsg98c6ss3lrg760px3.ls error="server returned 404: 404 page not found\n"15002026/11/01 17:33:51 INFO Signed narinfos id=2 count=215012026/11/01 17:33:51 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15022026/11/01 17:33:51 INFO Signed narinfos id=1 count=215032026/11/01 17:33:51 INFO Uploading 4 narinfos15042026/11/01 17:33:51 WARN Failed to register uploaded object key=xlgjyjjxl3kz42z65f3iisr5iksz6kka.ls error="server returned 404: 404 page not found\n"15052026/11/01 17:33:51 WARN Failed to register uploaded object key=avapz8qp74h1bnvc9cpsk9mivg06f1dv.narinfo error="server returned 404: 404 page not found\n"15062026/11/01 17:33:51 WARN Failed to register uploaded object key=x62qbbxjg8a75vsg98c6ss3lrg760px3.narinfo error="server returned 404: 404 page not found\n"15072026/11/01 17:33:51 WARN Failed to register uploaded object key=xlgjyjjxl3kz42z65f3iisr5iksz6kka.narinfo error="server returned 404: 404 page not found\n"15082026/11/01 17:33:51 INFO Received push request method=POST path=/api/pushes15092026/11/01 17:33:51 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15102026/11/01 17:33:51 WARN Failed to register uploaded object key=xlgjyjjxl3kz42z65f3iisr5iksz6kka.narinfo error="server returned 404: 404 page not found\n"15112026/11/01 17:33:51 INFO Completed upload id=1 objects=6 duration=10.697012ms15122026/11/01 17:33:51 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1513=== NAME TestClientMultipleUploads1514 client_integration_test.go:405: Created store path 0: /build/TestClientMultipleUploads1027699160/001/store/4bk5yj80z21l6qa79c91l8a8pahzl8l5-test-file-0.txt15152026/11/01 17:33:51 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15162026/11/01 17:33:51 INFO Uploading cw3qm3dn7wfj3zqgb80likgcvcipk9g6-shared-dep (136B)15172026/11/01 17:33:51 INFO Uploading g5cwnmp3v828cdd3cahx64qjm6phj51c-a (216B)15182026/11/01 17:33:51 INFO Completed upload id=2 objects=6 duration=7.117012ms15192026/11/01 17:33:51 INFO Upload complete. (174ms)1520=== NAME TestClientWithDependencies1521 client_integration_test.go:660: Built derivation: /build/TestClientWithDependencies2752209901/001/store/mzrkfc2pgc92nzrisqlkcr3dmbv71c1h-test-script1522=== NAME TestClientFallsBackToClosures1523 client_pushes_test.go:112: Retrieved narinfo from S3:1524 StorePath: /build/TestClientFallsBackToClosures146932635/001/store/xlgjyjjxl3kz42z65f3iisr5iksz6kka-shared-dep1525 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1526 Compression: zstd1527 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821528 NarSize: 1361529 References: 1530 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n15312026/11/01 17:33:51 WARN Failed to register uploaded object key=cb598f5w98snzyal3v77hhi6cbdip7p5.ls error="server returned 404: 404 page not found\n"15322026/11/01 17:33:51 WARN Failed to register uploaded object key=g5cwnmp3v828cdd3cahx64qjm6phj51c.ls error="server returned 404: 404 page not found\n"1533 client_pushes_test.go:112: Retrieved narinfo from S3:15342026/11/01 17:33:51 WARN Failed to register uploaded object key=cw3qm3dn7wfj3zqgb80likgcvcipk9g6.ls error="server returned 404: 404 page not found\n"15352026/11/01 17:33:51 WARN Failed to register uploaded object key=nar/0vnhgjywmbvd2hlgd9xhzmwb2v3mb1yc0kn1ac33073kdkqph8dd.nar.zst error="server returned 404: 404 page not found\n"15362026/11/01 17:33:51 INFO Received push request method=POST path=/api/pushes15372026/11/01 17:33:51 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1538 StorePath: /build/TestClientFallsBackToClosures146932635/001/store/avapz8qp74h1bnvc9cpsk9mivg06f1dv-a1539 URL: nar/0ajffjrwx4l52l1gpz4anziaf8imy3y8405rb4f146q08b0si8l5.nar.zst1540 Compression: zstd1541 NarHash: sha256:0ajffjrwx4l52l1gpz4anziaf8imy3y8405rb4f146q08b0si8l51542 NarSize: 2161543 References: /build/TestClientFallsBackToClosures146932635/001/store/xlgjyjjxl3kz42z65f3iisr5iksz6kka-shared-dep1544 CA: text:sha256:0d3c0szazjlql4sj8dcx1jspf8ah6q16rf7iqrp9dyrylrjjlz5415452026/11/01 17:33:51 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15462026/11/01 17:33:51 INFO Signed narinfos id=1 count=315472026/11/01 17:33:51 INFO Uploading 3 narinfos1548 client_pushes_test.go:112: Retrieved narinfo from S3:1549 StorePath: /build/TestClientFallsBackToClosures146932635/001/store/x62qbbxjg8a75vsg98c6ss3lrg760px3-b1550 URL: nar/0ajffjrwx4l52l1gpz4anziaf8imy3y8405rb4f146q08b0si8l5.nar.zst1551 Compression: zstd1552 NarHash: sha256:0ajffjrwx4l52l1gpz4anziaf8imy3y8405rb4f146q08b0si8l51553 NarSize: 2161554 References: /build/TestClientFallsBackToClosures146932635/001/store/xlgjyjjxl3kz42z65f3iisr5iksz6kka-shared-dep1555 CA: text:sha256:0d3c0szazjlql4sj8dcx1jspf8ah6q16rf7iqrp9dyrylrjjlz5415562026/11/01 17:33:51 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)15572026/11/01 17:33:51 INFO Uploading gf3msy1k9nvi3afzw7q2h9i50v96irpi-shared-dep (136B)15582026/11/01 17:33:51 INFO Uploading m3qm25civ8zppxc9sk1zch9pkzxmbzx5-top (224B)1559--- PASS: TestClientFallsBackToClosures (1.43s)1560=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15612026/11/01 17:33:51 WARN Failed to register uploaded object key=cb598f5w98snzyal3v77hhi6cbdip7p5.narinfo error="server returned 404: 404 page not found\n"15622026/11/01 17:33:51 WARN Failed to register uploaded object key=cw3qm3dn7wfj3zqgb80likgcvcipk9g6.narinfo error="server returned 404: 404 page not found\n"1563=== NAME TestClientMultipleUploads1564 client_integration_test.go:405: Created store path 1: /build/TestClientMultipleUploads1027699160/001/store/mg5gqzf479017njimpxcn32bqkpbi86h-test-file-1.txt15652026/11/01 17:33:51 INFO Received complete push request method=POST path=/api/pushes/1/complete1566=== NAME TestClientIntegration15672026/11/01 17:33:51 WARN Failed to register uploaded object key=g5cwnmp3v828cdd3cahx64qjm6phj51c.narinfo error="server returned 404: 404 page not found\n"1568 client_integration_test.go:291: Created store path: /build/TestClientIntegration2150930372/002/store/rkjyxx2zq3q7a3q5w4g58aax84lwczbj-test-file.txt15692026/11/01 17:33:51 WARN Failed to register uploaded object key=gf3msy1k9nvi3afzw7q2h9i50v96irpi.ls error="server returned 404: 404 page not found\n"15702026/11/01 17:33:51 WARN Failed to register uploaded object key=nar/1qk8sjw9r44scjprx1552sgqk5xaikpzd470zl43mmxhybn4dnkv.nar.zst error="server returned 404: 404 page not found\n"15712026/11/01 17:33:51 WARN Failed to register uploaded object key=m3qm25civ8zppxc9sk1zch9pkzxmbzx5.ls error="server returned 404: 404 page not found\n"15722026/11/01 17:33:51 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15732026/11/01 17:33:51 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15742026/11/01 17:33:51 INFO Signed narinfos id=1 count=215752026/11/01 17:33:51 INFO Uploading 2 narinfos1576=== NAME TestClientWithDependencies1577 client_integration_test.go:662: Found 1 dependencies (including self)15782026/11/01 17:33:51 WARN Failed to register uploaded object key=m3qm25civ8zppxc9sk1zch9pkzxmbzx5.narinfo error="server returned 404: 404 page not found\n"15792026/11/01 17:33:51 INFO Completed push id=1 objects=8 duration=26.972545ms15802026/11/01 17:33:51 INFO Received complete push request method=POST path=/api/pushes/1/complete15812026/11/01 17:33:51 INFO Upload complete. (171ms)15822026/11/01 17:33:51 WARN Failed to register uploaded object key=gf3msy1k9nvi3afzw7q2h9i50v96irpi.narinfo error="server returned 404: 404 page not found\n"1583=== NAME TestClientPushesUseOnePush1584 client_pushes_test.go:97: Retrieved narinfo from S3:1585 StorePath: /build/TestClientPushesUseOnePush3019156910/001/store/cw3qm3dn7wfj3zqgb80likgcvcipk9g6-shared-dep1586 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1587 Compression: zstd1588 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821589 NarSize: 1361590 References: 1591 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1592 client_pushes_test.go:97: Retrieved narinfo from S3:1593 StorePath: /build/TestClientPushesUseOnePush3019156910/001/store/g5cwnmp3v828cdd3cahx64qjm6phj51c-a1594 URL: nar/0vnhgjywmbvd2hlgd9xhzmwb2v3mb1yc0kn1ac33073kdkqph8dd.nar.zst1595 Compression: zstd1596 NarHash: sha256:0vnhgjywmbvd2hlgd9xhzmwb2v3mb1yc0kn1ac33073kdkqph8dd1597 NarSize: 2161598 References: /build/TestClientPushesUseOnePush3019156910/001/store/cw3qm3dn7wfj3zqgb80likgcvcipk9g6-shared-dep1599 CA: text:sha256:1d0gbsc7fx7s7v1nyycq3y2xvykvjs2irp4v6zkfmksdah4n39ib16002026/11/01 17:33:51 INFO Received push request method=POST path=/api/pushes1601 client_pushes_test.go:97: Retrieved narinfo from S3:1602 StorePath: /build/TestClientPushesUseOnePush3019156910/001/store/cb598f5w98snzyal3v77hhi6cbdip7p5-b1603 URL: nar/0vnhgjywmbvd2hlgd9xhzmwb2v3mb1yc0kn1ac33073kdkqph8dd.nar.zst1604 Compression: zstd1605 NarHash: sha256:0vnhgjywmbvd2hlgd9xhzmwb2v3mb1yc0kn1ac33073kdkqph8dd1606 NarSize: 2161607 References: /build/TestClientPushesUseOnePush3019156910/001/store/cw3qm3dn7wfj3zqgb80likgcvcipk9g6-shared-dep1608 CA: text:sha256:1d0gbsc7fx7s7v1nyycq3y2xvykvjs2irp4v6zkfmksdah4n39ib1609=== NAME TestClientMultipleUploads1610 client_integration_test.go:405: Created store path 2: /build/TestClientMultipleUploads1027699160/001/store/zjbph5garsczcza8hf1mvfzilnb90bzx-test-file-2.txt1611--- PASS: TestClientPushesUseOnePush (1.45s)1612=== CONT TestService_ReadAuthMiddleware16132026/11/01 17:33:51 INFO Completed push id=1 objects=6 duration=49.279531ms16142026/11/01 17:33:51 INFO Upload complete. (181ms)1615=== NAME TestClientSharedPathCommittedMidPush1616 client_integration_test.go:727: Retrieved narinfo from S3:1617 StorePath: /build/TestClientSharedPathCommittedMidPush261039111/001/store/gf3msy1k9nvi3afzw7q2h9i50v96irpi-shared-dep1618 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1619 Compression: zstd1620 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821621 NarSize: 1361622 References: 1623 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1624 client_integration_test.go:727: Retrieved narinfo from S3:1625 StorePath: /build/TestClientSharedPathCommittedMidPush261039111/001/store/m3qm25civ8zppxc9sk1zch9pkzxmbzx5-top1626 URL: nar/1qk8sjw9r44scjprx1552sgqk5xaikpzd470zl43mmxhybn4dnkv.nar.zst1627 Compression: zstd1628 NarHash: sha256:1qk8sjw9r44scjprx1552sgqk5xaikpzd470zl43mmxhybn4dnkv1629 NarSize: 2241630 References: /build/TestClientSharedPathCommittedMidPush261039111/001/store/gf3msy1k9nvi3afzw7q2h9i50v96irpi-shared-dep1631 CA: text:sha256:10ibm4x8l8myl7i2wan6gl6qcfbvibicr43mll5xs6sxi2xj5gz41632--- PASS: TestClientSharedPathCommittedMidPush (1.37s)1633=== CONT TestService_AuthMiddleware_MTLSProxyHeader16342026/11/01 17:33:51 INFO Received push request method=POST path=/api/pushes1635--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (1.01s)1636=== CONT TestMetricsCommit16372026/11/01 17:33:51 INFO Received push request method=POST path=/api/pushes16382026/11/01 17:33:51 INFO Received push request method=POST path=/api/pushes16392026/11/01 17:33:51 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16402026/11/01 17:33:51 INFO Uploading rkjyxx2zq3q7a3q5w4g58aax84lwczbj-test-file.txt (152B)16412026/11/01 17:33:51 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16422026/11/01 17:33:51 INFO Uploading mzrkfc2pgc92nzrisqlkcr3dmbv71c1h-test-script (136B)16432026/11/01 17:33:51 INFO Received complete push request method=POST path=/api/pushes/1/complete1644=== NAME TestClientCADerivations1645 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1584559183/001/store/jjz1y6w03xsnrsszhi5xjz8y18mrmaqw-ca-test16462026/11/01 17:33:51 WARN Failed to register uploaded object key=rkjyxx2zq3q7a3q5w4g58aax84lwczbj.ls error="server returned 404: 404 page not found\n"16472026/11/01 17:33:51 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"16482026/11/01 17:33:51 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16492026/11/01 17:33:51 WARN Failed to register uploaded object key=log/n0i8lk23vlm4axwjxwph2y4rvl5h7w8q-test-script.drv error="server returned 404: 404 page not found\n"16502026/11/01 17:33:51 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"16512026/11/01 17:33:51 INFO Completed push id=1 objects=6 duration=15.802363ms16522026/11/01 17:33:51 INFO Signed narinfos id=1 count=116532026/11/01 17:33:51 INFO Uploading 1 narinfos1654--- PASS: TestPush_CompleteCommitsEveryRoot (1.01s)1655=== CONT TestIsValidCachePath/narinfo1656=== CONT TestIsValidCachePath/short_hash1657=== CONT TestIsValidCachePath/wrong_extension1658=== CONT TestIsValidCachePath/leading_slash1659=== CONT TestIsValidCachePath/empty1660=== CONT TestIsValidCachePath/random_path1661=== CONT TestIsValidCachePath/invalid_char_u1662=== CONT TestIsValidCachePath/invalid_char_e1663=== CONT TestIsValidCachePath/traversal_in_middle1664=== CONT TestIsValidCachePath/traversal_parent1665=== CONT TestIsValidCachePath/index.html1666=== CONT TestIsValidCachePath/nix-cache-info1667=== CONT TestIsValidCachePath/realisation1668=== CONT TestIsValidCachePath/log1669=== CONT TestIsValidCachePath/ls1670=== CONT TestIsValidCachePath/nar_uncompressed1671=== CONT TestIsValidCachePath/nar_bz21672=== CONT TestIsValidCachePath/nar_xz1673=== CONT TestIsValidCachePath/nar_zst1674=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1675--- PASS: TestIsValidCachePath (0.00s)1676 --- PASS: TestIsValidCachePath/narinfo (0.00s)1677 --- PASS: TestIsValidCachePath/short_hash (0.00s)1678 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1679 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1680 --- PASS: TestIsValidCachePath/empty (0.00s)1681 --- PASS: TestIsValidCachePath/random_path (0.00s)1682 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1683 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1684 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1685 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1686 --- PASS: TestIsValidCachePath/index.html (0.00s)1687 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1688 --- PASS: TestIsValidCachePath/realisation (0.00s)1689 --- PASS: TestIsValidCachePath/log (0.00s)1690 --- PASS: TestIsValidCachePath/ls (0.00s)1691 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1692 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1693 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1694 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1695 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1696=== CONT TestIsValidUploadKey/narinfo1697=== CONT TestIsValidUploadKey/nix-cache-info1698=== CONT TestIsValidUploadKey/unknown_type1699=== CONT TestIsValidUploadKey/empty_key1700=== CONT TestIsValidUploadKey/absolute1701=== CONT TestIsValidUploadKey/traversal_nar1702=== CONT TestIsValidUploadKey/traversal1703=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1704=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1705=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1706=== CONT TestIsValidUploadKey/index.html1707=== CONT TestIsValidUploadKey/build_log_home-manager_file1708=== CONT TestIsValidUploadKey/realisation_plus_in_output1709=== CONT TestIsValidUploadKey/realisation1710=== CONT TestIsValidUploadKey/build_log_equals1711=== CONT TestIsValidUploadKey/build_log_question_mark1712=== CONT TestIsValidUploadKey/build_log_plus_in_name1713=== CONT TestIsValidUploadKey/nar_plain17142026/11/01 17:33:51 WARN Failed to register uploaded object key=mzrkfc2pgc92nzrisqlkcr3dmbv71c1h.ls error="server returned 404: 404 page not found\n"1715=== CONT TestIsValidUploadKey/build_log17162026/11/01 17:33:51 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1717=== CONT TestIsValidUploadKey/listing1718=== CONT TestIsValidUploadKey/nar_xz1719=== CONT TestIsValidUploadKey/nar_zst1720--- PASS: TestIsValidUploadKey (0.14s)1721 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1722 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1723 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1724 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1725 --- PASS: TestIsValidUploadKey/absolute (0.00s)1726 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1727 --- PASS: TestIsValidUploadKey/traversal (0.00s)1728 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1729 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1730 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1731 --- PASS: TestIsValidUploadKey/index.html (0.00s)1732 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1733 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1734 --- PASS: TestIsValidUploadKey/realisation (0.00s)1735 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1736 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1737 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1738 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1739 --- PASS: TestIsValidUploadKey/build_log (0.00s)1740 --- PASS: TestIsValidUploadKey/listing (0.00s)1741 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1742 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1743=== CONT TestParseSingleRange/none1744=== CONT TestParseSingleRange/start_far_past_EOF1745=== CONT TestParseSingleRange/start_past_EOF1746=== CONT TestParseSingleRange/single_byte1747=== CONT TestParseSingleRange/suffix_exceeds_size1748=== CONT TestParseSingleRange/suffix1749=== CONT TestParseSingleRange/end_clamped_to_size1750=== CONT TestParseSingleRange/open-ended1751=== CONT TestParseSingleRange/closed17522026/11/01 17:33:51 INFO Signed narinfos id=1 count=11753=== CONT TestParseSingleRange/malformed_end_before_start17542026/11/01 17:33:51 INFO Uploading 1 narinfos1755=== CONT TestParseSingleRange/malformed_both_empty1756=== CONT TestParseSingleRange/malformed_no_dash1757=== CONT TestParseSingleRange/multi-range_ignored1758=== CONT TestParseSingleRange/unknown_unit1759--- PASS: TestParseSingleRange (0.25s)1760 --- PASS: TestParseSingleRange/none (0.00s)1761 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1762 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1763 --- PASS: TestParseSingleRange/single_byte (0.00s)1764 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1765 --- PASS: TestParseSingleRange/suffix (0.00s)1766 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1767 --- PASS: TestParseSingleRange/open-ended (0.00s)1768 --- PASS: TestParseSingleRange/closed (0.00s)1769 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1770 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1771 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1772 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1773 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1774=== CONT TestPendingClosureWriteTimeout/empty1775=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline17762026/11/01 17:33:51 INFO lead: released remote=192.0.2.1:12341777--- PASS: TestLeadEndsOnShutdown (2.11s)1778=== CONT TestPendingClosureWriteTimeout/670k_objects1779=== CONT TestPendingClosureWriteTimeout/400_objects1780=== CONT TestProxyWriteTimeout/narinfo1781=== CONT TestProxyWriteTimeout/1_GiB_nar1782=== CONT TestProxyWriteTimeout/unknown_size1783=== CONT TestProxyWriteTimeout/10_GiB_nar1784--- PASS: TestProxyWriteTimeout (0.00s)1785 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1786 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1787 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1788 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1789=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17902026/11/01 17:33:51 INFO Received uploads request method=POST path=/1791=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17922026/11/01 17:33:51 INFO Received uploads request method=POST path=/17932026/11/01 17:33:51 INFO Received complete push request method=POST path=/api/pushes/1/complete17942026/11/01 17:33:51 WARN Failed to register uploaded object key=rkjyxx2zq3q7a3q5w4g58aax84lwczbj.narinfo error="server returned 404: 404 page not found\n"17952026/11/01 17:33:51 INFO Received complete push request method=POST path=/api/pushes/1/complete17962026/11/01 17:33:51 WARN Failed to register uploaded object key=mzrkfc2pgc92nzrisqlkcr3dmbv71c1h.narinfo error="server returned 404: 404 page not found\n"17972026/11/01 17:33:51 INFO Completed push id=1 objects=3 duration=12.743933ms17982026/11/01 17:33:51 INFO Upload complete. (166ms)1799=== NAME TestClientCADerivations1800 client_ca_test.go:139: Found 1 dependencies (including self)18012026/11/01 17:33:51 INFO Completed push id=1 objects=4 duration=15.151143ms1802--- PASS: TestReadRedirectUsesPublicS3URL (1.03s)18032026/11/01 17:33:51 INFO Upload complete. (154ms)1804=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18052026/11/01 17:33:51 INFO Received complete multipart upload request method=POST path=/1806=== NAME TestClientWithDependencies1807 client_integration_test.go:664: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2752209901/001/store) requires matching store prefix1808--- PASS: TestClientWithDependencies (1.45s)1809=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18102026/11/01 17:33:51 INFO Received request for more parts method=POST path=/18112026/11/01 17:33:51 INFO Received push request method=POST path=/api/pushes1812--- PASS: TestService_ReadScope_PublicByDefault (0.97s)1813=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18142026/11/01 17:33:51 INFO Received complete multipart upload request method=POST path=/1815=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18162026/11/01 17:33:51 INFO Received request for more parts method=POST path=/1817=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18182026/11/01 17:33:51 INFO Received uploads request method=POST path=/1819--- PASS: TestUploadHandlersRejectInvalidKeys (0.46s)1820 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1821 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1822 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1823 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1824=== CONT TestGCEndsOnShutdown/before_the_run18252026/11/01 17:33:52 INFO All 1 paths already cached1826=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1827=== NAME TestClientIntegration1828 client_integration_test.go:317: Retrieved narinfo from S3:1829 StorePath: /build/TestClientIntegration2150930372/002/store/rkjyxx2zq3q7a3q5w4g58aax84lwczbj-test-file.txt1830 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1831 Compression: zstd1832 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11833 NarSize: 1521834 References: 1835 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11836=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete18372026/11/01 17:33:52 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)18382026/11/01 17:33:52 INFO Uploading zjbph5garsczcza8hf1mvfzilnb90bzx-test-file-2.txt (160B)18392026/11/01 17:33:52 INFO Uploading 4bk5yj80z21l6qa79c91l8a8pahzl8l5-test-file-0.txt (160B)18402026/11/01 17:33:52 INFO Uploading mg5gqzf479017njimpxcn32bqkpbi86h-test-file-1.txt (160B)1841=== NAME TestClientIntegration1842 client_integration_test.go:318: Retrieved .ls file from S3 (compressed size: 77 bytes)1843 client_integration_test.go:318: Decompressed .ls content (64 bytes):1844 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}18452026/11/01 17:33:52 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"18462026/11/01 17:33:52 WARN Failed to register uploaded object key=mg5gqzf479017njimpxcn32bqkpbi86h.ls error="server returned 404: 404 page not found\n"18472026/11/01 17:33:52 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"18482026/11/01 17:33:52 WARN Failed to register uploaded object key=zjbph5garsczcza8hf1mvfzilnb90bzx.ls error="server returned 404: 404 page not found\n"18492026/11/01 17:33:52 WARN Failed to register uploaded object key=4bk5yj80z21l6qa79c91l8a8pahzl8l5.ls error="server returned 404: 404 page not found\n"18502026/11/01 17:33:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18512026/11/01 17:33:52 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"18522026/11/01 17:33:52 INFO Signed narinfos id=1 count=318532026/11/01 17:33:52 INFO Uploading 3 narinfos1854=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1855=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1856=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1857=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1858=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1859=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1860=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1861=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1862=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows18632026/11/01 17:33:52 WARN Failed to register uploaded object key=mg5gqzf479017njimpxcn32bqkpbi86h.narinfo error="server returned 404: 404 page not found\n"18642026/11/01 17:33:52 WARN Failed to register uploaded object key=4bk5yj80z21l6qa79c91l8a8pahzl8l5.narinfo error="server returned 404: 404 page not found\n"18652026/11/01 17:33:52 INFO Received complete push request method=POST path=/api/pushes/1/complete18662026/11/01 17:33:52 WARN Failed to register uploaded object key=zjbph5garsczcza8hf1mvfzilnb90bzx.narinfo error="server returned 404: 404 page not found\n"18672026/11/01 17:33:52 INFO Completed push id=1 objects=9 duration=23.103925ms18682026/11/01 17:33:52 INFO Upload complete. (275ms)1869=== NAME TestClientMultipleUploads1870 client_integration_test.go:416: Uploaded 3 paths in 337.730161ms1871--- PASS: TestReadProxyOutlastsServerWriteTimeout (7.62s)1872=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check18732026/11/01 17:33:52 INFO Received uploads request method=POST path=/api/pending_closures1874--- PASS: TestClientMultipleUploads (1.60s)1875=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh18762026/11/01 17:33:52 INFO Received push request method=POST path=/api/pushes18772026/11/01 17:33:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18782026/11/01 17:33:52 INFO Uploading jjz1y6w03xsnrsszhi5xjz8y18mrmaqw-ca-test (144B)18792026/11/01 17:33:52 WARN Failed to register uploaded object key=jjz1y6w03xsnrsszhi5xjz8y18mrmaqw.ls error="server returned 404: 404 page not found\n"18802026/11/01 17:33:52 WARN Failed to register uploaded object key=log/lqr41gmkfmgyxafxad9ig1vkhfw2ww4g-ca-test.drv error="server returned 404: 404 page not found\n"18812026/11/01 17:33:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18822026/11/01 17:33:52 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"18832026/11/01 17:33:52 INFO Signed narinfos id=1 count=118842026/11/01 17:33:52 INFO Uploading 1 narinfos18852026/11/01 17:33:52 INFO Received complete push request method=POST path=/api/pushes/1/complete18862026/11/01 17:33:52 WARN Failed to register uploaded object key=jjz1y6w03xsnrsszhi5xjz8y18mrmaqw.narinfo error="server returned 404: 404 page not found\n"1887=== RUN TestService_RequireScope_OIDC/builder_may_write1888=== PAUSE TestService_RequireScope_OIDC/builder_may_write1889=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1890=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1891=== RUN TestService_RequireScope_OIDC/ops_may_admin1892=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1893=== RUN TestService_RequireScope_OIDC/ops_may_not_write1894=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1895=== RUN TestService_RequireScope_OIDC/reader_may_not_write1896=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1897=== RUN TestService_RequireScope_OIDC/static_token_may_admin1898=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1899=== RUN TestService_RequireScope_OIDC/static_token_may_write1900=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1901=== RUN TestService_RequireScope_OIDC/reader_may_read1902=== PAUSE TestService_RequireScope_OIDC/reader_may_read1903=== RUN TestService_RequireScope_OIDC/writer_implies_read1904=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1905=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1906=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1907=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1908=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1909=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1910=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1911=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1912=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1913=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1914=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1915=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale19162026/11/01 17:33:52 INFO lead: released remote=192.0.2.1:123419172026/11/01 17:33:52 INFO Completed push id=1 objects=4 duration=46.66516ms19182026/11/01 17:33:52 INFO Upload complete. (232ms)19192026/11/01 17:33:52 INFO lead: acquired remote=192.0.2.1:123419202026/11/01 17:33:52 INFO Received push request method=POST path=/api/pushes1921=== NAME TestClientCADerivations1922 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1584559183/001/store/jjz1y6w03xsnrsszhi5xjz8y18mrmaqw-ca-test1923 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1924 Compression: zstd1925 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1926 NarSize: 1441927 References: 1928 Deriver: /build/TestClientCADerivations1584559183/001/store/lqr41gmkfmgyxafxad9ig1vkhfw2ww4g-ca-test.drv1929 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1930 client_ca_test.go:185: Checking for realisation files in S3...1931 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1932 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache19332026/11/01 17:33:52 WARN mTLS auth: subject not in bound subjects subject="CN=reader"19342026/11/01 17:33:52 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1935--- PASS: TestService_NativeMTLS (0.82s)1936=== CONT TestPush_RejectsBadRequests/no_roots19372026/11/01 17:33:52 INFO Received push request method=POST path=/api/pushes1938=== CONT TestPush_RejectsBadRequests/root_not_in_objects19392026/11/01 17:33:52 INFO Received push request method=POST path=/api/pushes1940=== CONT TestResolveDBConnectionString/flag_wins1941=== CONT TestPush_RejectsBadRequests/bad_root19422026/11/01 17:33:52 INFO Received push request method=POST path=/api/pushes1943=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1944=== CONT TestResolveDBConnectionString/nothing_configured1945=== CONT TestResolveDBConnectionString/missing_file_is_an_error1946=== CONT TestResolveDBConnectionString/file_when_flag_empty1947=== CONT TestPush_RejectsBadRequests/no_objects19482026/11/01 17:33:52 INFO Received push request method=POST path=/api/pushes1949--- PASS: TestResolveDBConnectionString (0.00s)1950 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1951 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1952 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1953 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1954 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1955--- PASS: TestPush_RejectsBadRequests (1.32s)1956 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1957 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1958 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1959 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)19602026/11/01 17:33:52 INFO Received cleanup request method=DELETE path=/api/pending_closures1961=== CONT TestClientErrorHandling/InvalidStorePath19622026/11/01 17:33:52 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket84/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""19632026/11/01 17:33:52 INFO Aborted multipart uploads count=0 kept=119642026/11/01 17:33:52 INFO Object in database but missing from S3 key=rkjyxx2zq3q7a3q5w4g58aax84lwczbj.ls19652026/11/01 17:33:52 WARN Found objects in DB but missing from S3, will re-upload count=119662026/11/01 17:33:52 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19672026/11/01 17:33:52 INFO Received cleanup request method=DELETE path=/api/pending_closures19682026/11/01 17:33:52 INFO Aborted multipart uploads count=1 kept=01969--- PASS: TestMultipartCleanup (0.89s)1970=== CONT TestClientErrorHandling/ServerNotAvailable19712026/11/01 17:33:52 INFO Received complete push request method=POST path=/api/pushes/2/complete19722026/11/01 17:33:52 WARN Failed to register uploaded object key=rkjyxx2zq3q7a3q5w4g58aax84lwczbj.ls error="server returned 404: 404 page not found\n"19732026/11/01 17:33:52 INFO Completed push id=2 objects=3 duration=12.640492ms19742026/11/01 17:33:52 INFO Upload complete. (194ms)1975=== NAME TestClientIntegration1976 client_integration_test.go:335: Retrieved .ls file from S3 (compressed size: 62 bytes)1977 client_integration_test.go:335: Decompressed .ls content (49 bytes):1978 {"version":1,"root":{"type":"regular","size":39}}19792026/11/01 17:33:52 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"19802026/11/01 17:33:52 WARN mTLS auth: bound subjects configured but subject DN unavailable19812026/11/01 17:33:52 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1982--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.70s)1983=== CONT TestClientErrorHandling/InvalidAuthToken1984--- PASS: TestService_ReadAuthMiddleware (0.70s)1985=== CONT TestCacheConfigHandler/full_config,_no_issuer1986=== CONT TestCacheConfigHandler/no_signing_keys1987=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1988=== CONT TestCacheConfigHandler/no_cache_url_configured1989--- PASS: TestCacheConfigHandler (0.00s)1990 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1991 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1992 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1993 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1994=== CONT TestServerTLSConfig/no_client_CA1995=== CONT TestServerTLSConfig/not_a_PEM_file1996=== CONT TestServerTLSConfig/missing_CA_file1997--- PASS: TestServerTLSConfig (0.00s)1998 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1999 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2000 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2001=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2002=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20032026/11/01 17:33:52 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]2004=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2005=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20062026/11/01 17:33:52 WARN Authentication failed token_preview=eyJhbGciOi...Adc1nWUuZQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2007=== CONT TestService_RequireScope_OIDC/builder_may_write2008--- PASS: TestService_AuthMiddleware_OIDC (1.08s)2009 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2010 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2011 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2012 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2013=== CONT TestService_RequireScope_OIDC/reader_may_read20142026/11/01 17:33:52 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/present2015=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2016=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read20172026/11/01 17:33:52 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]2018=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2019=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2020=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2021=== CONT TestService_RequireScope_OIDC/writer_implies_read2022=== CONT TestService_RequireScope_OIDC/reader_may_not_write2023=== CONT TestService_RequireScope_OIDC/static_token_may_write2024=== CONT TestService_RequireScope_OIDC/static_token_may_admin2025=== CONT TestService_RequireScope_OIDC/ops_may_admin2026=== CONT TestService_RequireScope_OIDC/ops_may_not_write2027=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2028--- PASS: TestService_RequireScope_OIDC (0.84s)2029 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2030 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2031 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2032 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2033 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2034 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2035 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2036 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2037 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2038 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2039 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2040 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2041 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2042 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2043=== NAME TestClientCADerivations2044 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2045 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2046 error: binary cache 's3://bucket78?endpoint=http://localhost:33445®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1584559183/001/store'2047 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12048--- PASS: TestClientCADerivations (1.77s)2049--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.74s)20502026/11/01 17:33:52 INFO Received uploads request method=POST path=/api/pending_closures20512026/11/01 17:33:52 WARN Request failed, retrying attempt=2 backoff=208.261495ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20522026/11/01 17:33:52 INFO Received push request method=POST path=/api/pushes20532026/11/01 17:33:52 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)20542026/11/01 17:33:52 INFO Received complete push request method=POST path=/api/pushes/3/complete20552026/11/01 17:33:52 WARN Failed to register uploaded object key=rkjyxx2zq3q7a3q5w4g58aax84lwczbj.ls error="server returned 404: 404 page not found\n"20562026/11/01 17:33:52 INFO Completed push id=3 objects=3 duration=4.131121ms20572026/11/01 17:33:52 INFO Upload complete. (74ms)2058=== NAME TestClientIntegration2059 client_integration_test.go:352: Retrieved .ls file from S3 (compressed size: 62 bytes)2060 client_integration_test.go:352: Decompressed .ls content (49 bytes):2061 {"version":1,"root":{"type":"regular","size":39}}2062 client_integration_test.go:363: Testing garbage collection...20632026/11/01 17:33:52 INFO Received push request method=POST path=/api/pushes20642026/11/01 17:33:52 INFO Received complete push request method=POST path=/api/pushes/1/complete20652026/11/01 17:33:52 INFO Completed push id=1 objects=4 duration=9.089382ms20662026/11/01 17:33:52 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete20672026/11/01 17:33:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures20682026/11/01 17:33:52 INFO Completed upload id=2 objects=2 duration=5.879071ms20692026/11/01 17:33:52 INFO Garbage collection started2070--- PASS: TestUploadHandlersRejectOversizedBody (0.45s)2071 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)2072 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)2073 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.96s)20742026/11/01 17:33:52 WARN Request failed, retrying attempt=3 backoff=389.657766ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20752026/11/01 17:33:52 WARN Rate limiter enabled after throttle name=s3-test rate=520762026/11/01 17:33:52 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2077=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2078 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102079 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002080--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (7.89s)2081--- PASS: TestMetricsCommit (1.05s)2082--- PASS: TestDeleteClosuresRacingPins (2.67s)20832026/11/01 17:33:52 INFO Aborted multipart uploads count=0 kept=020842026/11/01 17:33:52 WARN Force mode enabled - objects will be deleted immediately without grace period20852026/11/01 17:33:52 INFO Aborted multipart uploads count=0 kept=020862026/11/01 17:33:52 WARN Force mode enabled - objects will be deleted immediately without grace period20872026/11/01 17:33:52 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:33445/bucket93/?delete=\": context canceled"20882026/11/01 17:33:52 INFO Aborted multipart uploads count=0 kept=020892026/11/01 17:33:52 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=020902026/11/01 17:33:52 INFO Vacuumed table table=pending_closures20912026/11/01 17:33:52 WARN Force mode enabled - objects will be deleted immediately without grace period20922026/11/01 17:33:52 INFO Vacuumed table table=pending_objects20932026/11/01 17:33:52 INFO Vacuumed table table=multipart_uploads20942026/11/01 17:33:52 INFO Vacuumed table table=closures20952026/11/01 17:33:52 INFO Vacuumed table table=objects20962026/11/01 17:33:53 INFO Received uploads request method=POST path=/api/pending_closures2097--- PASS: TestGCEndsOnShutdown (0.00s)2098 --- PASS: TestGCEndsOnShutdown/before_the_run (0.90s)2099 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.91s)2100 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.99s)21012026/11/01 17:33:53 INFO Aborted multipart uploads count=0 kept=021022026/11/01 17:33:53 WARN Force mode enabled - objects will be deleted immediately without grace period21032026/11/01 17:33:53 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=021042026/11/01 17:33:53 INFO Vacuumed table table=pending_closures21052026/11/01 17:33:53 INFO Vacuumed table table=pending_objects21062026/11/01 17:33:53 INFO Vacuumed table table=multipart_uploads21072026/11/01 17:33:53 INFO Vacuumed table table=closures21082026/11/01 17:33:53 INFO Vacuumed table table=objects21092026/11/01 17:33:53 INFO Received uploads request method=POST path=/api/pending_closures21102026/11/01 17:33:53 INFO Aborted multipart uploads count=0 kept=021112026/11/01 17:33:53 WARN Force mode enabled - objects will be deleted immediately without grace period21122026/11/01 17:33:53 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=021132026/11/01 17:33:53 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=021142026/11/01 17:33:53 INFO Vacuumed table table=pending_closures21152026/11/01 17:33:53 INFO Received create pin request method=POST path=/api/pins/myapp21162026/11/01 17:33:53 INFO Vacuumed table table=pending_objects21172026/11/01 17:33:53 INFO Vacuumed table table=multipart_uploads21182026/11/01 17:33:53 INFO Vacuumed table table=closures21192026/11/01 17:33:53 INFO Vacuumed table table=objects21202026/11/01 17:33:53 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3813179481/001/store/f8sqba2iqivyx8hcxigr6bkargbr654w-pinned-file.txt narinfo_key=f8sqba2iqivyx8hcxigr6bkargbr654w.narinfo21212026/11/01 17:33:53 INFO Starting cleanup of old closures method=DELETE path=/api/closures21222026/11/01 17:33:53 INFO Garbage collection started21232026/11/01 17:33:53 INFO Aborted multipart uploads count=0 kept=02124--- PASS: TestForceGCDuringPushOffersSweptObject (0.01s)2125 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (1.01s)2126 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (1.03s)21272026/11/01 17:33:53 WARN Force mode enabled - objects will be deleted immediately without grace period21282026/11/01 17:33:53 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=021292026/11/01 17:33:53 INFO Vacuumed table table=pending_closures21302026/11/01 17:33:53 INFO Vacuumed table table=pending_objects21312026/11/01 17:33:53 INFO Vacuumed table table=multipart_uploads21322026/11/01 17:33:53 INFO Vacuumed table table=closures21332026/11/01 17:33:53 INFO Vacuumed table table=objects21342026/11/01 17:33:53 WARN Request failed, retrying attempt=4 backoff=805.986004ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21352026/11/01 17:33:53 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21362026/11/01 17:33:53 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21372026/11/01 17:33:53 INFO lead: released remote=192.0.2.1:12342138--- PASS: TestLeadElectsOneAndHandsOver (3.44s)2139--- PASS: TestPendingClosureWriteTimeout (0.23s)2140 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2141 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2142 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2143 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.50s)2144--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2145 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (1.39s)2146 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (1.34s)2147=== NAME TestOrphanedObjectsGCStressTest2148 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2149 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion21502026/11/01 17:33:54 WARN Request failed, retrying attempt=5 backoff=1.695940742s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21512026/11/01 17:33:54 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02152=== NAME TestClientIntegration2153 client_integration_test.go:370: Objects in database after GC:2154 client_integration_test.go:370: Successfully deleted all objects with GC --force2155--- PASS: TestClientIntegration (4.23s)2156=== NAME TestPinProtectsFromGC2157 client_integration_test.go:887: Pin successfully protected closure from garbage collection2158--- PASS: TestPinProtectsFromGC (5.80s)2159=== NAME TestOrphanedObjectsGCStressTest2160 orphaned_objects_gc_test.go:503: Stress test completed successfully:2161 orphaned_objects_gc_test.go:504: - Active objects preserved: 202162 orphaned_objects_gc_test.go:505: - Objects deleted: 2102163 orphaned_objects_gc_test.go:506: - Total GC'd: 2102164--- PASS: TestOrphanedObjectsGCStressTest (7.22s)2165--- PASS: TestConnectWaitsForAPeerMigration (5.24s)21662026/11/01 17:33:55 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-config21672026/11/01 17:33:55 WARN Request failed, retrying attempt=2 backoff=204.636776ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21682026/11/01 17:33:56 WARN Request failed, retrying attempt=3 backoff=399.582686ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21692026/11/01 17:33:56 WARN Request failed, retrying attempt=4 backoff=768.369826ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21702026/11/01 17:33:56 INFO Aborted multipart uploads count=1 kept=021712026/11/01 17:33:56 INFO Received cleanup request method=DELETE path=/api/pending_closures21722026/11/01 17:33:56 INFO Aborted multipart uploads count=1 kept=02173--- PASS: TestPendingCleanupUsesOneCutoff (7.35s)21742026/11/01 17:33:57 WARN Request failed, retrying attempt=5 backoff=1.4430823s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21752026/11/01 17:33:58 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"21762026/11/01 17:33:58 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-config21772026/11/01 17:33:58 WARN Request failed, retrying attempt=2 backoff=204.754294ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21782026/11/01 17:33:59 WARN Request failed, retrying attempt=3 backoff=377.536895ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21792026/11/01 17:33:59 WARN Request failed, retrying attempt=4 backoff=792.488654ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21802026/11/01 17:34:00 WARN Request failed, retrying attempt=5 backoff=1.446310645s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21812026/11/01 17:34:01 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_closures21822026/11/01 17:34:01 WARN Request failed, retrying attempt=2 backoff=212.39759ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21832026/11/01 17:34:02 WARN Request failed, retrying attempt=3 backoff=406.77241ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21842026/11/01 17:34:02 WARN Request failed, retrying attempt=4 backoff=747.136497ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21852026/11/01 17:34:03 WARN Request failed, retrying attempt=5 backoff=1.697978553s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2186--- PASS: TestClientErrorHandling (0.00s)2187 --- PASS: TestClientErrorHandling/InvalidStorePath (0.87s)2188 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.97s)2189 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.53s)2190PASS21912026-11-01 17:34:05.218 UTC [129] LOG: received smart shutdown request21922026-11-01 17:34:05.221 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 121932026-11-01 17:34:05.230 UTC [134] LOG: shutting down21942026-11-01 17:34:05.232 UTC [134] LOG: checkpoint starting: shutdown immediate21952026-11-01 17:34:07.288 UTC [134] LOG: checkpoint complete: wrote 11352 buffers (69.3%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 30 recycled; write=0.521 s, sync=1.472 s, total=2.058 s; sync files=34045, longest=0.002 s, average=0.001 s; distance=493961 kB, estimate=493961 kB; lsn=0/1F9C8458, redo lsn=0/1F9C845821962026-11-01 17:34:07.354 UTC [129] LOG: database system is shut down2197Running OIDC tests...2198=== RUN TestAudienceForIssuer2199=== PAUSE TestAudienceForIssuer2200=== RUN TestGlobMatch2201=== PAUSE TestGlobMatch2202=== RUN TestValidateToken_ValidToken2203=== PAUSE TestValidateToken_ValidToken2204=== RUN TestValidateToken_WrongAudience2205=== PAUSE TestValidateToken_WrongAudience2206=== RUN TestValidateToken_Expired2207=== PAUSE TestValidateToken_Expired2208=== RUN TestValidateToken_BoundClaimsMismatch2209=== PAUSE TestValidateToken_BoundClaimsMismatch2210=== RUN TestValidateToken_BoundSubjectMismatch2211=== PAUSE TestValidateToken_BoundSubjectMismatch2212=== RUN TestValidateToken_MultipleProviders2213=== PAUSE TestValidateToken_MultipleProviders2214=== RUN TestValidateToken_NoMatchingProvider2215=== PAUSE TestValidateToken_NoMatchingProvider2216=== RUN TestValidateToken_KubernetesServiceAccount2217=== PAUSE TestValidateToken_KubernetesServiceAccount2218=== RUN TestNewValidator_KubernetesRequiresCA2219=== PAUSE TestNewValidator_KubernetesRequiresCA2220=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2221=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2222=== RUN TestPins_ReservedForMatchingRule2223=== PAUSE TestPins_ReservedForMatchingRule2224=== RUN TestPins_TopLevelShorthand2225=== PAUSE TestPins_TopLevelShorthand2226=== RUN TestPins_ConfigValidation2227=== PAUSE TestPins_ConfigValidation2228=== RUN TestScopes_LegacyProviderDefaultsToWrite2229=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2230=== RUN TestScopes_Rules2231=== PAUSE TestScopes_Rules2232=== RUN TestScopes_ConfigValidation2233=== PAUSE TestScopes_ConfigValidation2234=== CONT TestAudienceForIssuer2235=== CONT TestValidateToken_BoundClaimsMismatch2236=== CONT TestValidateToken_WrongAudience2237=== CONT TestValidateToken_KubernetesServiceAccount2238=== CONT TestScopes_ConfigValidation2239=== CONT TestScopes_Rules2240=== CONT TestScopes_LegacyProviderDefaultsToWrite2241=== CONT TestPins_ConfigValidation2242=== CONT TestPins_TopLevelShorthand2243=== CONT TestPins_ReservedForMatchingRule2244=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2245=== CONT TestNewValidator_KubernetesRequiresCA2246=== CONT TestValidateToken_Expired2247=== CONT TestValidateToken_ValidToken2248=== CONT TestGlobMatch2249=== RUN TestGlobMatch/foo_foo2250=== PAUSE TestGlobMatch/foo_foo2251=== RUN TestGlobMatch/foo_bar2252=== PAUSE TestGlobMatch/foo_bar2253=== RUN TestGlobMatch/*_2254=== PAUSE TestGlobMatch/*_2255=== RUN TestGlobMatch/*_anything2256=== PAUSE TestGlobMatch/*_anything2257=== RUN TestGlobMatch/foo*_foo2258=== PAUSE TestGlobMatch/foo*_foo2259=== RUN TestGlobMatch/foo*_foobar2260=== PAUSE TestGlobMatch/foo*_foobar2261=== RUN TestGlobMatch/foo*_bar2262=== PAUSE TestGlobMatch/foo*_bar2263=== RUN TestGlobMatch/*bar_bar2264=== PAUSE TestGlobMatch/*bar_bar2265=== RUN TestGlobMatch/*bar_foobar2266=== PAUSE TestGlobMatch/*bar_foobar2267=== RUN TestGlobMatch/*bar_foo2268=== PAUSE TestGlobMatch/*bar_foo2269=== RUN TestGlobMatch/foo*bar_foobar2270=== PAUSE TestGlobMatch/foo*bar_foobar2271=== RUN TestGlobMatch/foo*bar_foo123bar2272=== PAUSE TestGlobMatch/foo*bar_foo123bar2273=== RUN TestGlobMatch/foo*bar_foobarbaz2274=== PAUSE TestGlobMatch/foo*bar_foobarbaz2275=== RUN TestGlobMatch/*/*_foo/bar2276=== PAUSE TestGlobMatch/*/*_foo/bar2277=== RUN TestGlobMatch/*/*_foo2278=== PAUSE TestGlobMatch/*/*_foo2279=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2280=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2281=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02282=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02283=== RUN TestGlobMatch/refs/*/main_refs/heads/main2284=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2285=== CONT TestValidateToken_MultipleProviders2286=== CONT TestValidateToken_NoMatchingProvider2287=== CONT TestValidateToken_BoundSubjectMismatch2288--- PASS: TestAudienceForIssuer (0.00s)2289=== RUN TestGlobMatch/fo?_foo2290=== PAUSE TestGlobMatch/fo?_foo2291=== RUN TestGlobMatch/fo?_fo2292=== PAUSE TestGlobMatch/fo?_fo2293=== RUN TestGlobMatch/fo?_fooo2294=== PAUSE TestGlobMatch/fo?_fooo2295=== RUN TestGlobMatch/?oo_foo2296--- PASS: TestPins_ConfigValidation (0.00s)2297=== PAUSE TestGlobMatch/?oo_foo2298=== RUN TestGlobMatch/?oo_boo2299--- PASS: TestScopes_ConfigValidation (0.01s)2300=== PAUSE TestGlobMatch/?oo_boo2301=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2302=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2303=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2304=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2305=== CONT TestGlobMatch/foo_foo2306=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2307=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2308=== CONT TestGlobMatch/?oo_boo2309=== CONT TestGlobMatch/?oo_foo2310=== CONT TestGlobMatch/fo?_fooo2311=== CONT TestGlobMatch/*bar_foo2312=== CONT TestGlobMatch/*bar_foobar2313=== CONT TestGlobMatch/foo*bar_foo123bar2314=== CONT TestGlobMatch/foo*_foo2315=== CONT TestGlobMatch/*bar_bar2316=== CONT TestGlobMatch/foo*_bar2317=== CONT TestGlobMatch/foo*_foobar2318=== CONT TestGlobMatch/*_2319=== CONT TestGlobMatch/foo_bar2320=== CONT TestGlobMatch/foo*bar_foobar2321=== CONT TestGlobMatch/*/*_foo2322=== CONT TestGlobMatch/*/*_foo/bar2323=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2324=== CONT TestGlobMatch/foo*bar_foobarbaz2325=== CONT TestGlobMatch/fo?_fo2326=== CONT TestGlobMatch/fo?_foo2327=== CONT TestGlobMatch/refs/*/main_refs/heads/main2328=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02329=== CONT TestGlobMatch/*_anything2330--- PASS: TestGlobMatch (0.01s)2331 --- PASS: TestGlobMatch/foo_foo (0.00s)2332 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2333 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2334 --- PASS: TestGlobMatch/?oo_boo (0.00s)2335 --- PASS: TestGlobMatch/?oo_foo (0.00s)2336 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2337 --- PASS: TestGlobMatch/*bar_foo (0.00s)2338 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2339 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2340 --- PASS: TestGlobMatch/foo*_foo (0.00s)2341 --- PASS: TestGlobMatch/*bar_bar (0.00s)2342 --- PASS: TestGlobMatch/foo*_bar (0.00s)2343 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2344 --- PASS: TestGlobMatch/*_ (0.00s)2345 --- PASS: TestGlobMatch/foo_bar (0.00s)2346 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2347 --- PASS: TestGlobMatch/*/*_foo (0.00s)2348 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2349 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2350 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2351 --- PASS: TestGlobMatch/fo?_fo (0.00s)2352 --- PASS: TestGlobMatch/fo?_foo (0.00s)2353 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2354 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2355 --- PASS: TestGlobMatch/*_anything (0.00s)23562026/11/01 17:34:10 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232357--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.04s)23582026/11/01 17:34:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37639/oidc23592026/11/01 17:34:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42431/oidc2360--- PASS: TestScopes_Rules (0.07s)23612026/11/01 17:34:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36671/oidc23622026/11/01 17:34:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37443/oidc2363--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.07s)2364--- PASS: TestValidateToken_BoundClaimsMismatch (0.07s)2365--- PASS: TestValidateToken_WrongAudience (0.07s)23662026/11/01 17:34:10 http: TLS handshake error from 127.0.0.1:35588: remote error: tls: bad certificate2367--- PASS: TestNewValidator_KubernetesRequiresCA (0.08s)23682026/11/01 17:34:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45139/oidc2369--- PASS: TestPins_TopLevelShorthand (0.10s)23702026/11/01 17:34:10 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:34771/oidc23712026/11/01 17:34:10 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:37877/oidc23722026/11/01 17:34:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38597/oidc2373--- PASS: TestValidateToken_MultipleProviders (0.10s)2374--- PASS: TestPins_ReservedForMatchingRule (0.11s)23752026/11/01 17:34:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41609/oidc2376--- PASS: TestValidateToken_ValidToken (0.12s)23772026/11/01 17:34:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41743/oidc2378--- PASS: TestValidateToken_Expired (0.15s)23792026/11/01 17:34:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36681/oidc2380--- PASS: TestValidateToken_BoundSubjectMismatch (0.16s)23812026/11/01 17:34:11 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:456852382--- PASS: TestValidateToken_KubernetesServiceAccount (0.23s)23832026/11/01 17:34:11 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:46313/oidc2384--- PASS: TestValidateToken_NoMatchingProvider (0.22s)2385PASS2386Running hook tests...2387=== RUN TestSendPathsEmpty2388=== PAUSE TestSendPathsEmpty2389=== RUN TestQueueEnqueueAndFetch2390=== PAUSE TestQueueEnqueueAndFetch2391=== RUN TestQueueDeduplication2392=== PAUSE TestQueueDeduplication2393=== RUN TestQueueRemove2394=== PAUSE TestQueueRemove2395=== RUN TestQueueFetchBatchLimit2396=== PAUSE TestQueueFetchBatchLimit2397=== RUN TestQueueRetryMovesToBack2398=== PAUSE TestQueueRetryMovesToBack2399=== RUN TestQueueFetchRemoveLifecycle2400=== PAUSE TestQueueFetchRemoveLifecycle2401=== RUN TestQueueConcurrentWriters2402=== PAUSE TestQueueConcurrentWriters2403=== RUN TestQueueRemoveLargeClosure2404=== PAUSE TestQueueRemoveLargeClosure2405=== RUN TestServerClientIntegration2406--- PASS: TestServerClientIntegration (0.00s)2407=== RUN TestServerQueueError24082026/11/01 17:34:11 ERROR Failed to queue paths error="permission denied" count=12409--- PASS: TestServerQueueError (0.00s)2410=== RUN TestGetListenerSocketActivation2411 server_test.go:218: === RUN TestGetListenerSocketActivation2412 --- PASS: TestGetListenerSocketActivation (0.00s)2413 PASS2414 2415--- PASS: TestGetListenerSocketActivation (0.01s)2416=== RUN TestServerStalledClientDoesNotBlockShutdown2417=== PAUSE TestServerStalledClientDoesNotBlockShutdown2418=== RUN TestServerBacksOffOnAcceptErrors2419=== PAUSE TestServerBacksOffOnAcceptErrors2420=== RUN TestDrainIsolatesPoisonPath2421=== PAUSE TestDrainIsolatesPoisonPath2422=== RUN TestRunNotBlockedByPoisonHead2423=== PAUSE TestRunNotBlockedByPoisonHead2424=== RUN TestDrainGivesUpWhenServerDown2425=== PAUSE TestDrainGivesUpWhenServerDown2426=== RUN TestFailedPathPrunedByLaterClosure2427=== PAUSE TestFailedPathPrunedByLaterClosure2428=== RUN TestWorkerUploadsAndRemoves2429=== PAUSE TestWorkerUploadsAndRemoves2430=== RUN TestWorkerSkipsGCdPaths2431=== PAUSE TestWorkerSkipsGCdPaths2432=== RUN TestWorkerPrunesClosureDeps2433=== PAUSE TestWorkerPrunesClosureDeps2434=== RUN TestDrainTimeout2435=== PAUSE TestDrainTimeout2436=== RUN TestWorkerRemoveFailureIsNotProgress2437=== PAUSE TestWorkerRemoveFailureIsNotProgress2438=== RUN TestWorkerKeepsPathItCannotStat2439=== PAUSE TestWorkerKeepsPathItCannotStat2440=== CONT TestSendPathsEmpty2441=== CONT TestQueueConcurrentWriters2442=== CONT TestRunNotBlockedByPoisonHead2443=== CONT TestWorkerKeepsPathItCannotStat2444=== CONT TestWorkerRemoveFailureIsNotProgress2445=== CONT TestDrainTimeout2446=== CONT TestWorkerPrunesClosureDeps2447=== CONT TestWorkerSkipsGCdPaths2448=== CONT TestWorkerUploadsAndRemoves2449=== CONT TestFailedPathPrunedByLaterClosure2450=== CONT TestDrainGivesUpWhenServerDown2451=== CONT TestQueueFetchRemoveLifecycle2452=== CONT TestDrainIsolatesPoisonPath2453=== CONT TestServerBacksOffOnAcceptErrors2454=== CONT TestServerStalledClientDoesNotBlockShutdown24552026/11/01 17:34:11 ERROR Accept failed error="too many open files"2456=== CONT TestQueueRemoveLargeClosure2457--- PASS: TestSendPathsEmpty (0.00s)2458=== CONT TestQueueDeduplication2459=== CONT TestQueueRemove2460=== CONT TestQueueEnqueueAndFetch2461=== CONT TestQueueRetryMovesToBack2462=== CONT TestQueueFetchBatchLimit24632026/11/01 17:34:11 ERROR Accept failed error="too many open files"24642026/11/01 17:34:11 INFO Upload queue status pending=324652026/11/01 17:34:11 INFO Uploading batch count=124662026/11/01 17:34:11 ERROR Upload failed error="upload failed" count=124672026/11/01 17:34:11 INFO Uploading batch count=224682026/11/01 17:34:11 INFO Upload queue status pending=224692026/11/01 17:34:11 INFO Uploading batch count=124702026/11/01 17:34:11 INFO Uploading batch count=224712026/11/01 17:34:11 ERROR Upload failed error="upload failed" count=224722026/11/01 17:34:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1714933023/002/a24732026/11/01 17:34:11 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3193889579/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat3193889579/002/locked/aaa: permission denied"24742026/11/01 17:34:11 INFO Upload queue status pending=224752026/11/01 17:34:11 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress2075863185/002/nonexistent24762026/11/01 17:34:11 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3390272793/002/nonexistent24772026/11/01 17:34:11 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=124782026/11/01 17:34:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1714933023/002/b24792026/11/01 17:34:11 ERROR Accept failed error="too many open files"24802026/11/01 17:34:11 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3193889579/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat3193889579/002/locked/aaa: permission denied"24812026/11/01 17:34:11 INFO Upload queue status pending=224822026/11/01 17:34:11 INFO Uploading batch count=42483--- PASS: TestQueueFetchBatchLimit (0.02s)24842026/11/01 17:34:11 ERROR Upload failed error="upload failed" count=424852026/11/01 17:34:11 INFO Uploading batch count=124862026/11/01 17:34:11 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress2075863185/002/nonexistent24872026/11/01 17:34:11 ERROR Upload failed error="upload failed" count=124882026/11/01 17:34:11 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=124892026/11/01 17:34:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath1511757684/002/bbb24902026/11/01 17:34:11 INFO Uploading batch count=124912026/11/01 17:34:11 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3193889579/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat3193889579/002/locked/aaa: permission denied"24922026/11/01 17:34:11 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress2075863185/002/nonexistent24932026/11/01 17:34:11 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=124942026/11/01 17:34:11 ERROR Drain finished with paths left in queue remaining=124952026/11/01 17:34:11 INFO Uploading batch count=224962026/11/01 17:34:11 ERROR Upload failed error="upload failed" count=224972026/11/01 17:34:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1714933023/002/c2498--- PASS: TestQueueRetryMovesToBack (0.02s)2499--- PASS: TestQueueDeduplication (0.02s)2500--- PASS: TestQueueRemove (0.02s)25012026/11/01 17:34:11 INFO Uploading batch count=22502--- PASS: TestQueueEnqueueAndFetch (0.02s)25032026/11/01 17:34:11 ERROR Drain finished with paths left in queue remaining=12504--- PASS: TestQueueFetchRemoveLifecycle (0.02s)25052026/11/01 17:34:11 INFO Uploading batch count=12506--- PASS: TestWorkerRemoveFailureIsNotProgress (0.02s)25072026/11/01 17:34:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1714933023/002/d25082026/11/01 17:34:11 INFO Uploading batch count=125092026/11/01 17:34:11 ERROR Upload failed error="upload failed" count=125102026/11/01 17:34:11 INFO Uploading batch count=125112026/11/01 17:34:11 INFO Uploading batch count=225122026/11/01 17:34:11 ERROR Upload failed error="upload failed" count=225132026/11/01 17:34:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1714933023/002/e25142026/11/01 17:34:11 INFO Uploading batch count=125152026/11/01 17:34:11 ERROR Upload failed error="upload failed" count=125162026/11/01 17:34:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1714933023/002/f25172026/11/01 17:34:11 INFO Uploading batch count=12518--- PASS: TestWorkerKeepsPathItCannotStat (0.03s)25192026/11/01 17:34:11 ERROR Upload failed error="upload failed" count=125202026/11/01 17:34:11 ERROR Drain finished with paths left in queue remaining=102521--- PASS: TestFailedPathPrunedByLaterClosure (0.03s)25222026/11/01 17:34:11 ERROR Drain finished with paths left in queue remaining=12523--- PASS: TestDrainIsolatesPoisonPath (0.03s)2524--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2525--- PASS: TestWorkerPrunesClosureDeps (0.04s)2526--- PASS: TestWorkerSkipsGCdPaths (0.04s)25272026/11/01 17:34:11 ERROR Accept failed error="too many open files"2528--- PASS: TestWorkerUploadsAndRemoves (0.04s)2529--- PASS: TestQueueRemoveLargeClosure (0.07s)25302026/11/01 17:34:11 ERROR Accept failed error="too many open files"25312026/11/01 17:34:11 ERROR Accept failed error="too many open files"25322026/11/01 17:34:11 ERROR Failed to decode request error="read unix /build/hook1027734329/test.sock->@: i/o timeout"25332026/11/01 17:34:11 ERROR Failed to write response error="write unix /build/hook1027734329/test.sock->@: i/o timeout"2534--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)25352026/11/01 17:34:11 ERROR Upload failed error="context deadline exceeded" count=225362026/11/01 17:34:11 ERROR Drain finished with paths left in queue remaining=42537--- PASS: TestDrainTimeout (0.22s)2538--- PASS: TestQueueConcurrentWriters (0.24s)25392026/11/01 17:34:11 ERROR Accept failed error="too many open files"25402026/11/01 17:34:11 ERROR Accept failed error="too many open files"2541--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)25422026/11/01 17:34:12 INFO Uploading batch count=125432026/11/01 17:34:12 INFO Uploading batch count=125442026/11/01 17:34:12 INFO Uploading batch count=125452026/11/01 17:34:12 ERROR Upload failed error="upload failed" count=125462026/11/01 17:34:12 INFO Uploading batch count=125472026/11/01 17:34:12 ERROR Upload failed error="upload failed" count=125482026/11/01 17:34:12 INFO Uploading batch count=125492026/11/01 17:34:12 ERROR Upload failed error="upload failed" count=125502026/11/01 17:34:12 INFO Uploading batch count=125512026/11/01 17:34:12 ERROR Upload failed error="upload failed" count=125522026/11/01 17:34:12 ERROR Drain finished with paths left in queue remaining=12553--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2554PASS2555Running signing tests...2556=== RUN TestExternalSigner2557=== PAUSE TestExternalSigner2558=== RUN TestExternalSignerWrongPublicKey2559=== PAUSE TestExternalSignerWrongPublicKey2560=== RUN TestExternalSignerErrors2561=== PAUSE TestExternalSignerErrors2562=== RUN TestExternalSignerRestartsAfterCrash2563=== PAUSE TestExternalSignerRestartsAfterCrash2564=== RUN TestExternalSignerProgramErrorKeepsProcess2565=== PAUSE TestExternalSignerProgramErrorKeepsProcess2566=== RUN TestExternalSignerClose2567=== PAUSE TestExternalSignerClose2568=== RUN TestExternalSignerRejectsInvalidPublicKey2569=== PAUSE TestExternalSignerRejectsInvalidPublicKey2570=== RUN TestExternalSignerCancellation2571=== PAUSE TestExternalSignerCancellation2572=== RUN TestGenerateFingerprint2573=== PAUSE TestGenerateFingerprint2574=== RUN TestParseSigningKey2575=== PAUSE TestParseSigningKey2576=== RUN TestSign2577=== PAUSE TestSign2578=== RUN TestSignBatch2579=== PAUSE TestSignBatch2580=== RUN TestNilKeyPublicKey2581=== PAUSE TestNilKeyPublicKey2582=== RUN TestSignErrors2583=== PAUSE TestSignErrors2584=== CONT TestExternalSigner2585=== CONT TestExternalSignerProgramErrorKeepsProcess2586=== CONT TestExternalSignerCancellation2587=== CONT TestSign2588=== CONT TestParseSigningKey2589=== RUN TestParseSigningKey/valid_32-byte_key2590=== CONT TestGenerateFingerprint2591=== RUN TestGenerateFingerprint/basic_with_references2592=== PAUSE TestGenerateFingerprint/basic_with_references2593=== RUN TestGenerateFingerprint/no_references2594=== PAUSE TestGenerateFingerprint/no_references2595=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2596=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2597=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2598=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2599=== RUN TestGenerateFingerprint/invalid_nar_hash_length2600=== CONT TestSignErrors2601=== CONT TestExternalSignerRejectsInvalidPublicKey2602=== RUN TestExternalSignerRejectsInvalidPublicKey/#002603=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002604=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2605=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2606=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2607=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2608=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2609=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2610=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2611=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2612=== CONT TestExternalSignerRejectsInvalidPublicKey/#002613=== CONT TestExternalSignerErrors2614=== RUN TestExternalSignerErrors/wrong_id2615--- PASS: TestSign (0.00s)2616=== PAUSE TestExternalSignerErrors/wrong_id2617=== CONT TestExternalSignerClose2618=== CONT TestExternalSignerWrongPublicKey2619=== CONT TestNilKeyPublicKey2620--- PASS: TestNilKeyPublicKey (0.00s)2621=== CONT TestSignBatch2622=== PAUSE TestParseSigningKey/valid_32-byte_key2623=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2624=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2625=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2626=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2627=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2628=== CONT TestExternalSignerRestartsAfterCrash2629=== RUN TestSignErrors/nil_key2630=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2631=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2632=== PAUSE TestSignErrors/nil_key2633=== RUN TestSignErrors/nil_narinfo2634=== PAUSE TestSignErrors/nil_narinfo2635=== RUN TestSignErrors/invalid_narinfo2636=== PAUSE TestSignErrors/invalid_narinfo2637=== RUN TestSignErrors/canceled2638=== RUN TestExternalSignerErrors/exit_on_request2639--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2640 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2641 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2642 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2643 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2644 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2645--- PASS: TestSignBatch (0.00s)2646=== RUN TestParseSigningKey/no_colon2647=== PAUSE TestParseSigningKey/no_colon2648=== RUN TestParseSigningKey/empty_name2649=== RUN TestGenerateFingerprint/invalid_store_path_prefix2650=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2651=== PAUSE TestSignErrors/canceled2652=== CONT TestSignErrors/nil_key2653=== PAUSE TestExternalSignerErrors/exit_on_request2654=== RUN TestExternalSignerErrors/wrong_shape2655=== PAUSE TestExternalSignerErrors/wrong_shape2656=== CONT TestSignErrors/invalid_narinfo2657=== RUN TestGenerateFingerprint/invalid_reference_prefix2658=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2659=== CONT TestGenerateFingerprint/basic_with_references2660=== CONT TestSignErrors/canceled2661=== CONT TestGenerateFingerprint/invalid_nar_hash_length2662=== CONT TestSignErrors/nil_narinfo2663--- PASS: TestSignErrors (0.00s)2664 --- PASS: TestSignErrors/nil_key (0.00s)2665 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2666 --- PASS: TestSignErrors/canceled (0.00s)2667 --- PASS: TestSignErrors/nil_narinfo (0.00s)2668=== PAUSE TestParseSigningKey/empty_name2669=== RUN TestParseSigningKey/invalid_base642670=== PAUSE TestParseSigningKey/invalid_base642671=== RUN TestParseSigningKey/wrong_length2672=== PAUSE TestParseSigningKey/wrong_length2673--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.01s)2674=== CONT TestGenerateFingerprint/invalid_reference_prefix2675=== CONT TestGenerateFingerprint/invalid_store_path_prefix2676=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2677=== CONT TestGenerateFingerprint/no_references2678=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2679=== RUN TestExternalSignerErrors/missing_signatures2680=== PAUSE TestExternalSignerErrors/missing_signatures2681=== CONT TestParseSigningKey/valid_32-byte_key2682=== CONT TestParseSigningKey/wrong_length2683=== CONT TestParseSigningKey/invalid_base642684=== CONT TestParseSigningKey/empty_name2685=== CONT TestParseSigningKey/no_colon2686=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2687--- PASS: TestGenerateFingerprint (0.00s)2688 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2689 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2690 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2691 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2692 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2693 --- PASS: TestGenerateFingerprint/no_references (0.00s)2694 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2695=== RUN TestExternalSignerErrors/too_few_signatures2696=== PAUSE TestExternalSignerErrors/too_few_signatures2697--- PASS: TestParseSigningKey (0.00s)2698 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2699 --- PASS: TestParseSigningKey/wrong_length (0.00s)2700 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2701 --- PASS: TestParseSigningKey/empty_name (0.00s)2702 --- PASS: TestParseSigningKey/no_colon (0.00s)2703 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2704=== RUN TestExternalSignerErrors/missing_signature_name2705=== PAUSE TestExternalSignerErrors/missing_signature_name2706=== RUN TestExternalSignerErrors/wrong_signature_name2707=== PAUSE TestExternalSignerErrors/wrong_signature_name2708=== RUN TestExternalSignerErrors/invalid_signature_base642709=== PAUSE TestExternalSignerErrors/invalid_signature_base642710=== RUN TestExternalSignerErrors/unrequested_key2711=== PAUSE TestExternalSignerErrors/unrequested_key2712=== RUN TestExternalSignerErrors/wrong_signature_length2713=== PAUSE TestExternalSignerErrors/wrong_signature_length2714=== RUN TestExternalSignerErrors/exit_at_startup2715=== PAUSE TestExternalSignerErrors/exit_at_startup2716=== RUN TestExternalSignerErrors/invalid_JSON2717=== PAUSE TestExternalSignerErrors/invalid_JSON2718=== RUN TestExternalSignerErrors/null2719=== PAUSE TestExternalSignerErrors/null2720=== RUN TestExternalSignerErrors/null_signatures2721=== PAUSE TestExternalSignerErrors/null_signatures2722=== RUN TestExternalSignerErrors/wrong_signatures_shape2723=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2724=== RUN TestExternalSignerErrors/program_error2725=== PAUSE TestExternalSignerErrors/program_error2726=== CONT TestExternalSignerErrors/wrong_id2727=== CONT TestExternalSignerErrors/invalid_JSON2728--- PASS: TestExternalSignerWrongPublicKey (0.00s)2729--- PASS: TestExternalSignerClose (0.00s)2730=== CONT TestExternalSignerErrors/wrong_signature_length2731=== CONT TestExternalSignerErrors/program_error2732=== CONT TestExternalSignerErrors/wrong_signatures_shape2733=== CONT TestExternalSignerErrors/missing_signature_name2734=== CONT TestExternalSignerErrors/unrequested_key2735=== CONT TestExternalSignerErrors/null_signatures2736=== CONT TestExternalSignerErrors/invalid_signature_base642737=== CONT TestExternalSignerErrors/null2738=== CONT TestExternalSignerErrors/wrong_signature_name2739=== CONT TestExternalSignerErrors/missing_signatures2740=== CONT TestExternalSignerErrors/too_few_signatures2741=== CONT TestExternalSignerErrors/wrong_shape2742=== CONT TestExternalSignerErrors/exit_at_startup2743=== CONT TestExternalSignerErrors/exit_on_request2744--- PASS: TestExternalSigner (0.01s)2745--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2746--- PASS: TestExternalSignerCancellation (0.03s)2747--- PASS: TestExternalSignerErrors (0.01s)2748 --- PASS: TestExternalSignerErrors/wrong_id (0.00s)2749 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2750 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2751 --- PASS: TestExternalSignerErrors/program_error (0.01s)2752 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2753 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2754 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2755 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2756 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2757 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2758 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2759 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2760 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2761 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2762 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2763 --- PASS: TestExternalSignerErrors/null (0.01s)2764PASS2765Running OpenBao signer tests...2766=== RUN TestSign2767=== PAUSE TestSign2768=== RUN TestSignErrors2769=== PAUSE TestSignErrors2770=== RUN TestServe2771=== PAUSE TestServe2772=== RUN TestServeRejectsGarbage2773=== PAUSE TestServeRejectsGarbage2774=== CONT TestSign2775=== CONT TestServe2776=== CONT TestServeRejectsGarbage2777=== CONT TestSignErrors2778=== RUN TestSignErrors/invalid_base642779=== PAUSE TestSignErrors/invalid_base642780=== RUN TestSignErrors/http_error2781=== PAUSE TestSignErrors/http_error2782=== RUN TestSignErrors/invalid_json2783=== PAUSE TestSignErrors/invalid_json2784=== RUN TestSignErrors/no_prefix2785=== PAUSE TestSignErrors/no_prefix2786=== CONT TestSignErrors/invalid_base642787--- PASS: TestServe (0.00s)2788--- PASS: TestServeRejectsGarbage (0.00s)2789=== CONT TestSignErrors/invalid_json2790=== CONT TestSignErrors/no_prefix2791=== CONT TestSignErrors/http_error2792--- PASS: TestSign (0.01s)2793--- PASS: TestSignErrors (0.00s)2794 --- PASS: TestSignErrors/http_error (0.00s)2795 --- PASS: TestSignErrors/no_prefix (0.01s)2796 --- PASS: TestSignErrors/invalid_base64 (0.01s)2797 --- PASS: TestSignErrors/invalid_json (0.01s)2798PASS