niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #463
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestUploadMultipart_PartsInParallel18=== PAUSE TestUploadMultipart_PartsInParallel19=== RUN TestUploadMultipart_ReturnsAfterDroppedBody20=== PAUSE TestUploadMultipart_ReturnsAfterDroppedBody21=== RUN TestPartSizeForNAR22=== PAUSE TestPartSizeForNAR23=== RUN TestUploadMultipart_SupersededByPeer24=== PAUSE TestUploadMultipart_SupersededByPeer25=== RUN TestDumpPathCaseHackMatchesNix26--- PASS: TestDumpPathCaseHackMatchesNix (0.17s)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 TestFileTokenReadsAndCaches117=== CONT TestRateLimiterFeedback118=== RUN TestRateLimiterFeedback/429_enables_limiter119=== PAUSE TestRateLimiterFeedback/429_enables_limiter120=== RUN TestRateLimiterFeedback/503_enables_limiter121=== PAUSE TestRateLimiterFeedback/503_enables_limiter122=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter123=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter124=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter125=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter126=== CONT TestRateLimiterFeedback/429_enables_limiter127=== CONT TestStaticToken128--- PASS: TestStaticToken (0.00s)129=== CONT TestSetClientTLSErrors130=== CONT TestScriptTokenEmptyToken131=== CONT TestScriptTokenScriptFails132--- PASS: TestFileTokenReadsAndCaches (0.00s)133=== CONT TestScriptTokenCachesUntilRefresh134=== CONT TestScriptTokenEmptyCommand135--- PASS: TestScriptTokenEmptyCommand (0.00s)136--- PASS: TestScriptTokenScriptFails (0.00s)137=== CONT TestStreamPushReportsEveryPath138=== CONT TestSetClientTLSDoesNotMutateDefaultTransport139=== CONT TestScriptTokenBadJSON140=== RUN TestSetClientTLSErrors/missing_cert_file141=== PAUSE TestSetClientTLSErrors/missing_cert_file142=== RUN TestSetClientTLSErrors/missing_key_file143=== PAUSE TestSetClientTLSErrors/missing_key_file144=== RUN TestSetClientTLSErrors/missing_ca_file145=== PAUSE TestSetClientTLSErrors/missing_ca_file146=== RUN TestSetClientTLSErrors/invalid_ca_file147=== PAUSE TestSetClientTLSErrors/invalid_ca_file148=== CONT TestSetClientTLSErrors/missing_cert_file149=== CONT TestShellSplitErrors150--- PASS: TestShellSplitErrors (0.00s)151=== CONT TestShellSplit152--- PASS: TestShellSplit (0.00s)153=== CONT TestDoWithRetry_FinalResponseBodyReadable154--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)155=== CONT TestSetClientTLS156=== CONT TestPathInfoCACompatibility157=== RUN TestPathInfoCACompatibility/null_ca_field158=== PAUSE TestPathInfoCACompatibility/null_ca_field159=== CONT TestRetryTimeoutOutlastsMaxRetries160=== CONT TestDumpPathWriterError161=== CONT TestDoWithRetry_BodyReplayedViaGetBody162=== CONT TestResolveStorePath163=== CONT TestStreamPushStopsWhenCanceled164--- PASS: TestStreamPushStopsWhenCanceled (0.00s)165=== CONT TestClientSignaturesByStorePath166=== CONT TestStreamPushReportsSkippedPaths167=== CONT TestScriptTokenNoExpiryRerunsEveryCall168=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer169=== RUN TestPathInfoCACompatibility/old_string_format_-_text170=== CONT TestParsePathInfoJSONMultiplePaths171=== CONT TestParsePathInfoJSON172=== CONT TestPathInfoHashCompatibility173=== CONT TestGetStorePathHash174=== CONT TestConvertHashToNix32175=== CONT TestEncodeNixBase32WithRealHash176=== CONT TestEncodeNixBase32177=== RUN TestEncodeNixBase32/test_string_hash178=== PAUSE TestEncodeNixBase32/test_string_hash179=== RUN TestEncodeNixBase32/empty_input180=== PAUSE TestEncodeNixBase32/empty_input181=== RUN TestParsePathInfoJSON/Nix_format182=== PAUSE TestParsePathInfoJSON/Nix_format183=== RUN TestParsePathInfoJSON/Lix_format184=== PAUSE TestParsePathInfoJSON/Lix_format185=== RUN TestParsePathInfoJSON/empty_input186=== PAUSE TestParsePathInfoJSON/empty_input187=== RUN TestParsePathInfoJSON/whitespace_only188=== PAUSE TestParsePathInfoJSON/whitespace_only189=== RUN TestParsePathInfoJSON/invalid_JSON190--- PASS: TestClientSignaturesByStorePath (1.15s)191=== PAUSE TestParsePathInfoJSON/invalid_JSON192=== CONT TestFileTokenEmpty193=== CONT TestStreamPushReportsSignatures194=== CONT TestFileTokenMissing195=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text196=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)197=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)198=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon199=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths200=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon201=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI202=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive203=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive204=== RUN TestPathInfoCACompatibility/new_structured_format_-_text205=== CONT TestStreamPushRequestLine206=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths207=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths208--- PASS: TestFileTokenEmpty (0.00s)209--- PASS: TestFileTokenMissing (0.00s)210=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths211--- PASS: TestEncodeNixBase32WithRealHash (0.00s)212=== CONT TestStreamPushGivesUpOnDeadServer213=== CONT TestStreamPushIsolatesFailures214=== CONT TestStreamPushBatchesUnderLoad215=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false216=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false217=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true218--- PASS: TestScriptTokenEmptyToken (1.17s)219=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess220=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true221--- PASS: TestStreamPushReportsEveryPath (1.16s)222=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter2232026/11/06 07:11:51 ERROR Upload failed error=boom count=12242026/11/06 07:11:51 ERROR Upload failed error="bad path" count=32252026/11/06 07:11:51 ERROR Upload failed error="connection refused" count=20226--- PASS: TestStreamPushReportsSignatures (0.01s)227=== CONT TestRateLimiterFeedback/503_enables_limiter2282026/11/06 07:11:51 ERROR Server seems unavailable, giving up on batch untried=172292026/11/06 07:11:51 WARN Rate limiter enabled after throttle name=server-test rate=52302026/11/06 07:11:51 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:43233231=== CONT TestSetClientTLSErrors/missing_ca_file232--- PASS: TestResolveStorePath (1.16s)233--- PASS: TestStreamPushIsolatesFailures (0.00s)234=== CONT TestSetClientTLSErrors/invalid_ca_file235=== CONT TestSetClientTLSErrors/missing_key_file2362026/11/06 07:11:51 WARN Rate limiter enabled after throttle name=server-test rate=5237=== CONT TestCaseHackSuffix2382026/11/06 07:11:51 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:41379239--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)240=== CONT TestDumpPathSingleFile2412026/11/06 07:11:51 WARN Rate limiter enabled after throttle name=server-test rate=52422026/11/06 07:11:51 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:46615243=== CONT TestDumpPathMatchesNix2442026/11/06 07:11:51 WARN Rate limiter backed off name=server-test rate=5245=== CONT TestUploadMultipart_ReturnsAfterDroppedBody246=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI247=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512248=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512249=== RUN TestGetStorePathHash/valid_store_path250=== PAUSE TestGetStorePathHash/valid_store_path251--- PASS: TestDoServerRequestAttachesToken (1.29s)252--- PASS: TestStreamPushReportsSkippedPaths (1.28s)253=== CONT TestUploadMultipart_SupersededByPeer254=== CONT TestUploadMultipart_PartsInParallel255=== RUN TestGetStorePathHash/basename_without_hyphen_should_error256=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error257=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error258=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error259=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error260=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error2612026/11/06 07:11:51 WARN Rate limiter enabled after throttle name=server-test rate=52622026/11/06 07:11:51 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:45229263=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text264=== CONT TestFilterOversizedClosures265=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter266--- PASS: TestScriptTokenBadJSON (1.29s)267=== CONT TestSupersededNARStillUploadsListing268--- PASS: TestSetClientTLSErrors (0.13s)269 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)270 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)271 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)272 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)273=== CONT TestPartSizeForNAR274=== RUN TestUploadMultipart_SupersededByPeer/exists275=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica276--- PASS: TestScriptTokenCachesUntilRefresh (1.29s)277=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun278=== RUN TestPartSizeForNAR/zero_stays_at_minimum279=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum280=== RUN TestPartSizeForNAR/small_stays_at_minimum281=== PAUSE TestPartSizeForNAR/small_stays_at_minimum282=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum283=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum284=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts285=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts286=== RUN TestPartSizeForNAR/1_TiB287=== PAUSE TestPartSizeForNAR/1_TiB288=== RUN TestPartSizeForNAR/5_TiB_S3_max_object289=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object290=== RUN TestPartSizeForNAR/capped_at_5_GiB291=== PAUSE TestPartSizeForNAR/capped_at_5_GiB292=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method293=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method294=== RUN TestConvertHashToNix32/SRI_format_to_Nix32295=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32296=== RUN TestConvertHashToNix32/already_Nix32_format297=== PAUSE TestConvertHashToNix32/already_Nix32_format298=== RUN TestConvertHashToNix32/invalid_format299=== PAUSE TestConvertHashToNix32/invalid_format300=== RUN TestSupersededNARStillUploadsListing/small_NAR301=== PAUSE TestSupersededNARStillUploadsListing/small_NAR302=== RUN TestSupersededNARStillUploadsListing/dump_cut_short303=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short304=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails305=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails306=== CONT TestRegisterUploadedObjectReusesConnections307=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry308--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (1.29s)309=== CONT TestParsePathInfoJSON/Nix_format310=== PAUSE TestUploadMultipart_SupersededByPeer/exists311=== RUN TestUploadMultipart_SupersededByPeer/missing312=== PAUSE TestUploadMultipart_SupersededByPeer/missing3132026/11/06 07:11:51 WARN Rate limiter enabled after throttle name=server-test rate=53142026/11/06 07:11:51 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:38663315=== CONT TestParsePathInfoJSON/invalid_JSON316=== CONT TestParsePathInfoJSON/empty_input317=== CONT TestParsePathInfoJSON/Lix_format3182026/11/06 07:11:51 WARN Rate limiter backed off name=server-test rate=53192026/11/06 07:11:51 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:38663320=== CONT TestEncodeNixBase32/test_string_hash321--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (1.30s)322=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false3232026/11/06 07:11:51 WARN Rate limiter backed off name=server-test rate=5324=== CONT TestParsePathInfoJSON/whitespace_only3252026/11/06 07:11:51 ERROR Upload failed error=boom count=1326--- PASS: TestDoWithRetry_FinalResponseBodyReadable (1.30s)327--- PASS: TestParsePathInfoJSON (0.00s)328 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)329 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)330 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)331 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)332 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)333=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)334=== RUN TestFilterOversizedClosures/no_limit_keeps_everything335=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything336=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon337=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha5123382026/11/06 07:11:51 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:41379339=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error340=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error341=== CONT TestGetStorePathHash/basename_without_hyphen_should_error342=== CONT TestPartSizeForNAR/zero_stays_at_minimum343=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true344=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI345--- PASS: TestPathInfoHashCompatibility (0.12s)346 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)347 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)348 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)349 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)350=== CONT TestPathInfoCACompatibility/null_ca_field351=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped352=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped353=== RUN TestFilterOversizedClosures/all_closures_skipped354=== PAUSE TestFilterOversizedClosures/all_closures_skipped355=== CONT TestGetStorePathHash/valid_store_path356--- PASS: TestGetStorePathHash (0.12s)357 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)358 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)359 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)360 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)361=== CONT TestConvertHashToNix32/SRI_format_to_Nix32362=== CONT TestSupersededNARStillUploadsListing/small_NAR3632026/11/06 07:11:51 INFO Uploading abc-hello (1.0GB)364=== CONT TestPartSizeForNAR/capped_at_5_GiB365=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts3662026/11/06 07:11:51 WARN Rate limiter enabled after throttle name=s3-test rate=5367=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum3682026/11/06 07:11:51 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:38497369=== CONT TestPartSizeForNAR/small_stays_at_minimum370=== CONT TestPartSizeForNAR/5_TiB_S3_max_object371=== CONT TestPathInfoCACompatibility/new_structured_format_-_text372=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive373=== CONT TestPathInfoCACompatibility/old_string_format_-_text3742026/11/06 07:11:51 WARN Rate limiter backed off name=server-test rate=5375=== CONT TestPartSizeForNAR/1_TiB376--- PASS: TestPartSizeForNAR (0.00s)377 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)378 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)379 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)380 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)381 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)382 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)383 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)384--- PASS: TestRateLimiterFeedback (0.00s)385 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)386 --- PASS: TestRateLimiterFeedback/429_enables_limiter (1.17s)387 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.01s)388 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.14s)389=== CONT TestConvertHashToNix32/invalid_format390=== CONT TestConvertHashToNix32/already_Nix32_format391--- PASS: TestConvertHashToNix32 (0.13s)392 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)393 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)394 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)395=== CONT TestFilterOversizedClosures/no_limit_keeps_everything396=== CONT TestFilterOversizedClosures/all_closures_skipped3972026/11/06 07:11:51 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=50398=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3992026/11/06 07:11:51 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=2000400--- PASS: TestFilterOversizedClosures (0.01s)401 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)402 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)403 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)4042026/11/06 07:11:51 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:41379405=== CONT TestSupersededNARStillUploadsListing/dump_cut_short406=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths407=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths408=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method409=== CONT TestEncodeNixBase32/empty_input410--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)411 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)412 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)413--- PASS: TestPathInfoCACompatibility (1.29s)414 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)415 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)416 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)417 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)418 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)419--- PASS: TestStreamPushBatchesUnderLoad (0.00s)420 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)421 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)422--- PASS: TestEncodeNixBase32 (0.00s)423 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)424 --- PASS: TestEncodeNixBase32/empty_input (0.00s)425=== CONT TestUploadMultipart_SupersededByPeer/exists4262026/11/06 07:11:52 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:35233/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:35233/api/uploads/complete4272026/11/06 07:11:52 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4282026/11/06 07:11:52 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:35233/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:35233/api/uploads/complete4292026/11/06 07:11:52 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4302026/11/06 07:11:52 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:35233/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:35233/api/uploads/complete4312026/11/06 07:11:52 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"432=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails433=== RUN TestSetClientTLS/rejects_connection_without_client_cert434=== CONT TestUploadMultipart_SupersededByPeer/missing4352026/11/06 07:11:52 INFO Garbage collection started436=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert437=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA438=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA439=== RUN TestSetClientTLS/preserves_debug_logging_transport440=== PAUSE TestSetClientTLS/preserves_debug_logging_transport441=== CONT TestSetClientTLS/rejects_connection_without_client_cert442--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.11s)443--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.97s)444=== CONT TestSetClientTLS/preserves_debug_logging_transport4452026/11/06 07:11:52 INFO Uploading abc-hello (1.0GB)446--- PASS: TestUploadMultipart_ReturnsAfterDroppedBody (1.10s)447=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA448--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.10s)449--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.96s)4502026/11/06 07:11:52 INFO Garbage collection started451--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)452 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)453 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.97s)4542026/11/06 07:11:52 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:41379455--- PASS: TestDumpPathSingleFile (1.11s)456--- PASS: TestCaseHackSuffix (1.11s)4572026/11/06 07:11:52 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=04582026/11/06 07:11:52 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:413794592026/11/06 07:11:52 WARN Garbage collection finished on another replica. Its statistics are not available here460--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.97s)4612026/11/06 07:11:52 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:413794622026/11/06 07:11:52 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:41379463--- PASS: TestRegisterUploadedObjectReusesConnections (0.99s)4642026/11/06 07:11:52 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:413794652026/11/06 07:11:52 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:413794662026/11/06 07:11:52 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:413794672026/11/06 07:11:52 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:413794682026/11/06 07:11:52 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:413794692026/11/06 07:11:52 http: TLS handshake error from 127.0.0.1:42288: remote error: tls: bad certificate4702026/11/06 07:11:52 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:41379471--- PASS: TestDumpPathWriterError (2.28s)472--- PASS: TestSetClientTLS (2.26s)473 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)474 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)475 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)4762026/11/06 07:11:52 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:413794772026/11/06 07:11:52 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:413794782026/11/06 07:11:52 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:413794792026/11/06 07:11:52 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:413794802026/11/06 07:11:52 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:413794812026/11/06 07:11:52 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:41379482--- PASS: TestRetryTimeoutOutlastsMaxRetries (2.29s)483--- PASS: TestStreamPushRequestLine (1.13s)4842026/11/06 07:11:52 INFO Uploading abc-hello (1.0GB)4852026/11/06 07:11:53 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:33683/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:33683/part/2486--- PASS: TestDumpPathMatchesNix (1.23s)4872026/11/06 07:11:53 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:33683/part/3\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:33683/part/34882026/11/06 07:11:53 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"489--- PASS: TestSupersededNARStillUploadsListing (0.00s)490 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.01s)491 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.97s)492 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (1.57s)493--- PASS: TestUploadMultipart_PartsInParallel (1.61s)494PASS495Running server tests...496The files belonging to this database system will be owned by user "nixbld".497This user must also own the server process.498499The database cluster will be initialized with locale "C".500The default database encoding has accordingly been set to "SQL_ASCII".501The default text search configuration will be set to "english".502503Data page checksums are enabled.504505creating directory /build/postgres2422118499/data ... ok506creating subdirectories ... ok507selecting dynamic shared memory implementation ... posix508selecting default "max_connections" ... 100509selecting default "shared_buffers" ... 128MB510selecting default time zone ... UTC511creating configuration files ... ok512running bootstrap script ... ok513performing post-bootstrap initialization ... ok514syncing data to disk ... ok515516initdb: warning: enabling "trust" authentication for local connections517initdb: 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.518519Success. You can now start the database server using:520521 pg_ctl -D /build/postgres2422118499/data -l logfile start522523/build/postgres2422118499:5432 - no response524/build/postgres2422118499:5432 - no response525/build/postgres2422118499:5432 - no response526/build/postgres2422118499:5432 - no response527/build/postgres2422118499:5432 - no response528/build/postgres2422118499:5432 - no response529/build/postgres2422118499:5432 - no response530/build/postgres2422118499:5432 - no response531/build/postgres2422118499:5432 - no response5322026-11-06 07:12:07.013 UTC [128] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit5332026-11-06 07:12:07.013 UTC [128] LOG: listening on Unix socket "/build/postgres2422118499/.s.PGSQL.5432"5342026-11-06 07:12:07.021 UTC [143] LOG: database system was shut down at 2026-11-06 07:12:05 UTC5352026-11-06 07:12:07.025 UTC [128] LOG: database system is ready to accept connections536/build/postgres2422118499:5432 - accepting connections537{"timestamp":"2026-11-06T07:12:15.325027866Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"ca77f720-7ef2-43c6-a6eb-3e4c006b6c26","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":11,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(196)"}538{"timestamp":"2026-11-06T07:12:15.435872873Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"7566bac9-ef23-4bda-b28d-627ffcfd2065","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(207)"}539=== RUN TestService_AuthMiddleware540=== PAUSE TestService_AuthMiddleware541=== RUN TestService_AuthMiddleware_MTLSProxyHeader542=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader543=== RUN TestService_AuthMiddleware_MTLSBoundSubjects544=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects545=== RUN TestService_ReadAuthMiddleware546=== PAUSE TestService_ReadAuthMiddleware547=== RUN TestService_AuthMiddleware_OIDC548=== PAUSE TestService_AuthMiddleware_OIDC549=== RUN TestService_RequireScope_OIDC550=== PAUSE TestService_RequireScope_OIDC551=== RUN TestService_ReadScope_PublicByDefault552=== PAUSE TestService_ReadScope_PublicByDefault553=== RUN TestCacheConfigHandler554=== PAUSE TestCacheConfigHandler555=== RUN TestCacheStatsHandler556=== PAUSE TestCacheStatsHandler557=== RUN TestClientCADerivations558=== PAUSE TestClientCADerivations559=== RUN TestClientErrorHandling560=== PAUSE TestClientErrorHandling561=== RUN TestClientIntegration562=== PAUSE TestClientIntegration563=== RUN TestClientMultipleUploads564=== PAUSE TestClientMultipleUploads565=== RUN TestClientWithDependencies566=== PAUSE TestClientWithDependencies567=== RUN TestClientSharedPathCommittedMidPush568=== PAUSE TestClientSharedPathCommittedMidPush569=== RUN TestPinProtectsFromGC570=== PAUSE TestPinProtectsFromGC571=== RUN TestClientPushesUseOnePush572=== PAUSE TestClientPushesUseOnePush573=== RUN TestClientFallsBackToClosures574=== PAUSE TestClientFallsBackToClosures575=== RUN TestDeleteClosuresRacingPins576=== PAUSE TestDeleteClosuresRacingPins577=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock578=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock579=== RUN TestResolveDBConnectionString580=== PAUSE TestResolveDBConnectionString581=== RUN TestConnectWaitsForAPeerMigration582=== PAUSE TestConnectWaitsForAPeerMigration583=== RUN TestLeadElectsOneAndHandsOver584=== PAUSE TestLeadElectsOneAndHandsOver585=== RUN TestLeadIncumbentWinsAfterRestart5862026/11/06 07:12:16 INFO lead: acquired remote=192.0.2.1:12345872026/11/06 07:12:17 INFO lead: released remote=192.0.2.1:12345882026/11/06 07:12:17 INFO lead: acquired remote=192.0.2.1:12345892026/11/06 07:12:18 INFO lead: released remote=192.0.2.1:1234590--- PASS: TestLeadIncumbentWinsAfterRestart (3.17s)591=== RUN TestLeadIncumbentAnnouncesAtOnce592=== PAUSE TestLeadIncumbentAnnouncesAtOnce593=== RUN TestLeadEndsOnShutdown594=== PAUSE TestLeadEndsOnShutdown595=== RUN TestLeadEndsWhenItsConnectionHangs5962026/11/06 07:12:20 INFO lead: acquired remote=192.0.2.1:12345972026-11-06 07:12:22.264 UTC [393] FATAL: terminating connection due to administrator command5982026/11/06 07:12:22 INFO lead: acquired remote=192.0.2.1:12345992026/11/06 07:12:23 WARN lead: lock connection lost error="timeout: context deadline exceeded"6002026/11/06 07:12:23 INFO lead: released remote=192.0.2.1:12346012026/11/06 07:12:23 INFO lead: released remote=192.0.2.1:1234602--- PASS: TestLeadEndsWhenItsConnectionHangs (4.93s)603=== RUN TestGCAdvisoryLockBlocksConcurrentRun604=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun605=== RUN TestGCBugBareHashReferences606=== PAUSE TestGCBugBareHashReferences607=== RUN TestGCMetrics608=== PAUSE TestGCMetrics609=== RUN TestPushDedupSurvivesConcurrentGC610=== PAUSE TestPushDedupSurvivesConcurrentGC611=== RUN TestDeduplicatedObjectsRecordedAsPending612=== PAUSE TestDeduplicatedObjectsRecordedAsPending613=== RUN TestGCSweepSkipsPendingObjects614=== PAUSE TestGCSweepSkipsPendingObjects615=== RUN TestTombstonedObjectOfferedWithoutWaiting616=== PAUSE TestTombstonedObjectOfferedWithoutWaiting617=== RUN TestGCSweepDeliversEachKeyOnce618=== PAUSE TestGCSweepDeliversEachKeyOnce619=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection620=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection621=== RUN TestForceGCDuringPushOffersSweptObject622=== PAUSE TestForceGCDuringPushOffersSweptObject623=== RUN TestFailedS3DeleteKeepsTombstone624=== PAUSE TestFailedS3DeleteKeepsTombstone625=== RUN TestSweepSkipsRowsLockedByPush626=== PAUSE TestSweepSkipsRowsLockedByPush627=== RUN TestRegisterCompletedObjectNeedsPendingRow628=== PAUSE TestRegisterCompletedObjectNeedsPendingRow629=== RUN TestGetExistingObjectsLocksRows630=== PAUSE TestGetExistingObjectsLocksRows631=== RUN TestSweepRechecksPendingAfterLocking632=== PAUSE TestSweepRechecksPendingAfterLocking633=== RUN TestPushWaitsForSweepHoldingRow634=== PAUSE TestPushWaitsForSweepHoldingRow635=== RUN TestCommitRacingPendingCleanupKeepsObjects636=== PAUSE TestCommitRacingPendingCleanupKeepsObjects637=== RUN TestGCEndsOnShutdown638=== PAUSE TestGCEndsOnShutdown639=== RUN TestGCTaskStore_StartNew640=== PAUSE TestGCTaskStore_StartNew641=== RUN TestGCTaskStore_DeduplicateSameParams642=== PAUSE TestGCTaskStore_DeduplicateSameParams643=== RUN TestGCTaskStore_ConflictDifferentParams644=== PAUSE TestGCTaskStore_ConflictDifferentParams645=== RUN TestGCTaskStore_GetEmpty646=== PAUSE TestGCTaskStore_GetEmpty647=== RUN TestGCTaskStore_GetReturnsLatest648=== PAUSE TestGCTaskStore_GetReturnsLatest649=== RUN TestGCTaskStore_CompletedAllowsNewTask650=== PAUSE TestGCTaskStore_CompletedAllowsNewTask651=== RUN TestGCTaskStore_PhaseUpdates652=== PAUSE TestGCTaskStore_PhaseUpdates653=== RUN TestGCTaskStore_Fail654=== PAUSE TestGCTaskStore_Fail655=== RUN TestGracefulShutdownDrainsInflight656=== PAUSE TestGracefulShutdownDrainsInflight657=== RUN TestService_healthCheckHandler658=== PAUSE TestService_healthCheckHandler659=== RUN TestService_readinessHandler660=== PAUSE TestService_readinessHandler661=== RUN TestGenerateLandingPage662=== PAUSE TestGenerateLandingPage663=== RUN TestCacheConfigHandlerMaxNarSize664=== PAUSE TestCacheConfigHandlerMaxNarSize665=== RUN TestCreatePendingClosureRejectsOversizedNAR666=== PAUSE TestCreatePendingClosureRejectsOversizedNAR667=== RUN TestNARDeduplicationMetadataUploadBug668=== PAUSE TestNARDeduplicationMetadataUploadBug669=== RUN TestMetricsInventory670=== PAUSE TestMetricsInventory671=== RUN TestMetricsCommit672=== PAUSE TestMetricsCommit673=== RUN TestService_NativeMTLS674=== PAUSE TestService_NativeMTLS675=== RUN TestServerTLSConfig676=== PAUSE TestServerTLSConfig677=== RUN TestMultipartCleanup678=== PAUSE TestMultipartCleanup679=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded680=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded681=== RUN TestPendingCleanupUsesOneCutoff682=== PAUSE TestPendingCleanupUsesOneCutoff683=== RUN TestObjectStatsTrigger684=== PAUSE TestObjectStatsTrigger685=== RUN TestObjectStatsUpdatedOncePerCommit686=== PAUSE TestObjectStatsUpdatedOncePerCommit687=== RUN TestOrphanedObjectsGC688=== PAUSE TestOrphanedObjectsGC689=== RUN TestOrphanedObjectsGCStressTest690=== PAUSE TestOrphanedObjectsGCStressTest691=== RUN TestCreatePin_ReservedPins692=== PAUSE TestCreatePin_ReservedPins693=== RUN TestPresentReportsOnlyClosureRoots694=== PAUSE TestPresentReportsOnlyClosureRoots695=== RUN TestPresentRefreshesOnlyStaleClosures696=== PAUSE TestPresentRefreshesOnlyStaleClosures697=== RUN TestPresentNotReportedWhileGCDeletesClosure698=== PAUSE TestPresentNotReportedWhileGCDeletesClosure699=== RUN TestParseSingleRange700=== PAUSE TestParseSingleRange701=== RUN TestProxyHeadersOnlyTrustedOnSocket7022026/11/06 07:12:24 INFO Starting HTTP server address=127.0.0.1:340657032026/11/06 07:12:24 INFO Starting HTTP server address=proxy.sock7042026/11/06 07:12:24 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7052026/11/06 07:12:24 INFO Shutdown signal received, draining in-flight requests timeout=10s706--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.82s)707=== RUN TestIsValidCachePath708=== PAUSE TestIsValidCachePath709=== RUN TestReadProxyNarinfo710=== PAUSE TestReadProxyNarinfo711=== RUN TestReadProxyNarinfoAlreadyDecompressed712=== PAUSE TestReadProxyNarinfoAlreadyDecompressed713=== RUN TestReadProxyContentNegotiation714=== PAUSE TestReadProxyContentNegotiation715=== RUN TestReadProxyNarStreaming716=== PAUSE TestReadProxyNarStreaming717=== RUN TestReadProxy404718=== PAUSE TestReadProxy404719=== RUN TestReadProxyInvalidPath720=== PAUSE TestReadProxyInvalidPath721=== RUN TestReadProxyHead722=== PAUSE TestReadProxyHead723=== RUN TestReadProxyOutlastsServerWriteTimeout724=== PAUSE TestReadProxyOutlastsServerWriteTimeout725=== RUN TestReadProxyConditionalGet726=== PAUSE TestReadProxyConditionalGet727=== RUN TestReadProxyRootRedirectsToIndexHTML728=== PAUSE TestReadProxyRootRedirectsToIndexHTML729=== RUN TestReadProxyDisabled730=== PAUSE TestReadProxyDisabled731=== RUN TestReadRedirectNar732=== PAUSE TestReadRedirectNar733=== RUN TestReadRedirectKeepsNarinfoProxied734=== PAUSE TestReadRedirectKeepsNarinfoProxied735=== RUN TestReadProxyRangeRequest736=== PAUSE TestReadProxyRangeRequest737=== RUN TestReadRedirectUsesPublicS3URL738=== PAUSE TestReadRedirectUsesPublicS3URL739=== RUN TestPush_OverlappingRootsStoreOneRowPerKey740=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey741=== RUN TestPush_CompleteCommitsEveryRoot742=== PAUSE TestPush_CompleteCommitsEveryRoot743=== RUN TestPush_RepeatedRootCommitsOnce744=== PAUSE TestPush_RepeatedRootCommitsOnce745=== RUN TestPush_CompleteWaitsForCleanupOfThePush746=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush747=== RUN TestPush_RootsAreLockedInByteOrder748=== PAUSE TestPush_RootsAreLockedInByteOrder749=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit750=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit751=== RUN TestPush_RejectsBadRequests752=== PAUSE TestPush_RejectsBadRequests753=== RUN TestPush_SignsNarinfosOfItsPendingObjects754=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects755=== RUN TestRedundantMultipartUpload756=== PAUSE TestRedundantMultipartUpload757=== RUN TestCompleteMultipartUpload_ErrorButObjectExists758=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists759=== RUN TestCompletedNarNotReofferedAcrossClosures760=== PAUSE TestCompletedNarNotReofferedAcrossClosures761=== RUN TestPresignedUploadRegisteredBeforeCommit762=== PAUSE TestPresignedUploadRegisteredBeforeCommit763=== RUN TestService_Rustfstest764=== PAUSE TestService_Rustfstest765=== RUN TestParseSize766=== PAUSE TestParseSize767=== RUN TestSkippedUploadsHandler768=== PAUSE TestSkippedUploadsHandler769=== RUN TestSystemdListenerNotActivated770--- PASS: TestSystemdListenerNotActivated (0.00s)771=== RUN TestWatchdogBeatsWhenHealthy772--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)773=== RUN TestWatchdogSkipsWhenUnhealthy7742026/11/06 07:12:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7752026/11/06 07:12:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7762026/11/06 07:12:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7772026/11/06 07:12:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7782026/11/06 07:12:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7792026/11/06 07:12:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7802026/11/06 07:12:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7812026/11/06 07:12:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7822026/11/06 07:12:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7832026/11/06 07:12:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"784--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)785=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle786=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle787=== RUN TestProxyWriteTimeout788=== PAUSE TestProxyWriteTimeout789=== RUN TestPendingClosureWriteTimeout790=== PAUSE TestPendingClosureWriteTimeout791=== RUN TestIsValidUploadKey792=== PAUSE TestIsValidUploadKey793=== RUN TestUploadHandlersRejectInvalidKeys794=== PAUSE TestUploadHandlersRejectInvalidKeys795=== RUN TestUploadHandlersRejectOversizedBody796=== PAUSE TestUploadHandlersRejectOversizedBody797=== RUN TestService_cleanupPendingClosuresHandler798=== PAUSE TestService_cleanupPendingClosuresHandler799=== RUN TestService_createPendingClosureHandler800=== PAUSE TestService_createPendingClosureHandler801=== RUN TestService_verifyS3Integrity802=== PAUSE TestService_verifyS3Integrity803=== RUN TestService_verifyS3ReuploadsStaleNarinfo804=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo805=== RUN TestCompleteMultipartUnregistered806=== PAUSE TestCompleteMultipartUnregistered807=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT808=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT809=== CONT TestUploadHandlersRejectOversizedBody810=== CONT TestService_AuthMiddleware811=== CONT TestUploadHandlersRejectInvalidKeys812=== CONT TestIsValidUploadKey813=== CONT TestPendingClosureWriteTimeout814=== CONT TestProxyWriteTimeout815=== RUN TestPendingClosureWriteTimeout/empty816=== RUN TestProxyWriteTimeout/narinfo817=== PAUSE TestProxyWriteTimeout/narinfo818=== CONT TestSkippedUploadsHandler819=== PAUSE TestPendingClosureWriteTimeout/empty820=== RUN TestPendingClosureWriteTimeout/400_objects821=== PAUSE TestPendingClosureWriteTimeout/400_objects822=== RUN TestPendingClosureWriteTimeout/670k_objects823=== PAUSE TestPendingClosureWriteTimeout/670k_objects824=== CONT TestGracefulShutdownDrainsInflight825=== CONT TestGCTaskStore_Fail826--- PASS: TestGCTaskStore_Fail (0.00s)827=== CONT TestPresignedUploadRegisteredBeforeCommit8282026/11/06 07:12:24 INFO Starting HTTP server address=127.0.0.1:428018292026/11/06 07:12:24 INFO Shutdown signal received, draining in-flight requests timeout=10s830=== CONT TestGCTaskStore_PhaseUpdates831--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)832=== CONT TestCompletedNarNotReofferedAcrossClosures8332026/11/06 07:12:24 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000834=== CONT TestGCTaskStore_CompletedAllowsNewTask835=== CONT TestRedundantMultipartUpload836=== CONT TestGCTaskStore_GetReturnsLatest837=== CONT TestGetExistingObjectsLocksRows838=== CONT TestGCTaskStore_GetEmpty839=== CONT TestIsValidCachePath840=== CONT TestGCTaskStore_ConflictDifferentParams841=== CONT TestGCTaskStore_DeduplicateSameParams842=== CONT TestRegisterCompletedObjectNeedsPendingRow843=== CONT TestService_healthCheckHandler844=== CONT TestGCTaskStore_StartNew845=== CONT TestParseSingleRange846=== RUN TestParseSingleRange/none847=== PAUSE TestParseSingleRange/none848=== CONT TestGCEndsOnShutdown849=== CONT TestCommitRacingPendingCleanupKeepsObjects850=== CONT TestPushWaitsForSweepHoldingRow851=== CONT TestSweepSkipsRowsLockedByPush852=== CONT TestParseSize853=== CONT TestService_Rustfstest854=== RUN TestParseSingleRange/unknown_unit855=== PAUSE TestParseSingleRange/unknown_unit856=== RUN TestParseSingleRange/multi-range_ignored857=== PAUSE TestParseSingleRange/multi-range_ignored858=== RUN TestParseSingleRange/malformed_no_dash859=== PAUSE TestParseSingleRange/malformed_no_dash860=== RUN TestParseSingleRange/malformed_both_empty861=== PAUSE TestParseSingleRange/malformed_both_empty862=== RUN TestGCEndsOnShutdown/before_the_run863=== PAUSE TestGCEndsOnShutdown/before_the_run864=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete865=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete866=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark867=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark868=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info869=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info870=== CONT TestPresentNotReportedWhileGCDeletesClosure871=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale872=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale873=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh874=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh875=== RUN TestIsValidUploadKey/narinfo876=== PAUSE TestIsValidUploadKey/narinfo877=== RUN TestIsValidUploadKey/nar_zst878=== PAUSE TestIsValidUploadKey/nar_zst879=== RUN TestIsValidUploadKey/nar_xz880=== PAUSE TestIsValidUploadKey/nar_xz881=== RUN TestIsValidUploadKey/nar_plain882=== PAUSE TestIsValidUploadKey/nar_plain883=== RUN TestIsValidUploadKey/listing884=== PAUSE TestIsValidUploadKey/listing885=== RUN TestIsValidUploadKey/build_log886=== PAUSE TestIsValidUploadKey/build_log887=== RUN TestIsValidUploadKey/build_log_home-manager_file888=== PAUSE TestIsValidUploadKey/build_log_home-manager_file889=== RUN TestIsValidUploadKey/build_log_plus_in_name890=== PAUSE TestIsValidUploadKey/build_log_plus_in_name891=== RUN TestIsValidUploadKey/build_log_question_mark892=== PAUSE TestIsValidUploadKey/build_log_question_mark893=== RUN TestIsValidUploadKey/build_log_equals894=== PAUSE TestIsValidUploadKey/build_log_equals895=== RUN TestParseSingleRange/malformed_end_before_start896=== PAUSE TestParseSingleRange/malformed_end_before_start897=== RUN TestParseSingleRange/closed898=== PAUSE TestParseSingleRange/closed899=== RUN TestParseSingleRange/open-ended900=== PAUSE TestParseSingleRange/open-ended901=== RUN TestParseSingleRange/end_clamped_to_size902=== RUN TestIsValidUploadKey/realisation903=== PAUSE TestIsValidUploadKey/realisation904=== RUN TestIsValidUploadKey/realisation_plus_in_output905=== PAUSE TestIsValidUploadKey/realisation_plus_in_output906=== RUN TestIsValidUploadKey/nix-cache-info907=== PAUSE TestIsValidUploadKey/nix-cache-info908=== RUN TestIsValidUploadKey/index.html909=== PAUSE TestIsValidUploadKey/index.html910=== RUN TestIsValidUploadKey/narinfo_key,_nar_type911=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type912=== RUN TestIsValidUploadKey/nar_key,_narinfo_type913=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type914=== RUN TestIsValidUploadKey/listing_key,_narinfo_type915=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type916=== RUN TestIsValidUploadKey/traversal917=== PAUSE TestIsValidUploadKey/traversal918=== RUN TestIsValidUploadKey/traversal_nar919=== PAUSE TestIsValidUploadKey/traversal_nar920=== RUN TestIsValidUploadKey/absolute921=== PAUSE TestIsValidUploadKey/absolute922=== RUN TestIsValidUploadKey/empty_key923=== PAUSE TestIsValidUploadKey/empty_key924=== RUN TestIsValidUploadKey/unknown_type925=== PAUSE TestIsValidUploadKey/unknown_type926=== RUN TestProxyWriteTimeout/1_GiB_nar927=== PAUSE TestProxyWriteTimeout/1_GiB_nar928=== RUN TestProxyWriteTimeout/10_GiB_nar929=== PAUSE TestProxyWriteTimeout/10_GiB_nar930=== RUN TestProxyWriteTimeout/unknown_size931=== PAUSE TestProxyWriteTimeout/unknown_size932=== CONT TestForceGCDuringPushOffersSweptObject933=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows934=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows935=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check936=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check937=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline938=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline939=== CONT TestPresentReportsOnlyClosureRoots940=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection941--- PASS: TestGracefulShutdownDrainsInflight (0.07s)942--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)943--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)944--- PASS: TestGCTaskStore_GetEmpty (0.00s)945--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)946--- PASS: TestGCTaskStore_StartNew (0.00s)947--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)948=== CONT TestCreatePin_ReservedPins949=== CONT TestCompleteMultipartUpload_ErrorButObjectExists950=== RUN TestIsValidCachePath/narinfo951=== PAUSE TestIsValidCachePath/narinfo952=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars953=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars954=== RUN TestIsValidCachePath/nar_zst955=== PAUSE TestIsValidCachePath/nar_zst956=== RUN TestIsValidCachePath/nar_xz957=== PAUSE TestIsValidCachePath/nar_xz958=== RUN TestIsValidCachePath/nar_bz2959=== PAUSE TestIsValidCachePath/nar_bz2960=== RUN TestIsValidCachePath/nar_uncompressed961=== PAUSE TestIsValidCachePath/nar_uncompressed962=== RUN TestIsValidCachePath/ls963=== PAUSE TestIsValidCachePath/ls964=== RUN TestIsValidCachePath/log965=== PAUSE TestIsValidCachePath/log966=== RUN TestIsValidCachePath/realisation967=== PAUSE TestIsValidCachePath/realisation968=== RUN TestIsValidCachePath/nix-cache-info969=== PAUSE TestIsValidCachePath/nix-cache-info970=== RUN TestIsValidCachePath/index.html971=== PAUSE TestIsValidCachePath/index.html972=== RUN TestIsValidCachePath/traversal_parent973=== PAUSE TestIsValidCachePath/traversal_parent974=== RUN TestIsValidCachePath/traversal_in_middle975=== PAUSE TestIsValidCachePath/traversal_in_middle976=== CONT TestSweepRechecksPendingAfterLocking977=== CONT TestFailedS3DeleteKeepsTombstone978=== CONT TestPresentRefreshesOnlyStaleClosures979=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle980=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal981=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal982=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key983=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key984--- PASS: TestParseSize (0.02s)985=== PAUSE TestParseSingleRange/end_clamped_to_size986=== RUN TestIsValidCachePath/invalid_char_e987=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure988=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key989=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key990=== RUN TestParseSingleRange/suffix991=== PAUSE TestParseSingleRange/suffix992=== RUN TestParseSingleRange/suffix_exceeds_size993=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure994=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart995=== CONT TestGCSweepDeliversEachKeyOnce996=== PAUSE TestParseSingleRange/suffix_exceeds_size997=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart998=== PAUSE TestIsValidCachePath/invalid_char_e999=== RUN TestParseSingleRange/single_byte1000=== PAUSE TestParseSingleRange/single_byte1001=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1002=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1003=== RUN TestIsValidCachePath/invalid_char_u1004=== CONT TestOrphanedObjectsGCStressTest1005=== PAUSE TestIsValidCachePath/invalid_char_u1006=== RUN TestParseSingleRange/start_past_EOF1007=== RUN TestIsValidCachePath/random_path1008=== PAUSE TestParseSingleRange/start_past_EOF1009=== RUN TestParseSingleRange/start_far_past_EOF1010=== PAUSE TestParseSingleRange/start_far_past_EOF1011=== PAUSE TestIsValidCachePath/random_path1012=== RUN TestIsValidCachePath/empty1013=== PAUSE TestIsValidCachePath/empty1014=== RUN TestIsValidCachePath/leading_slash1015=== CONT TestTombstonedObjectOfferedWithoutWaiting1016=== PAUSE TestIsValidCachePath/leading_slash1017=== RUN TestIsValidCachePath/wrong_extension1018=== PAUSE TestIsValidCachePath/wrong_extension1019=== RUN TestIsValidCachePath/short_hash1020=== PAUSE TestIsValidCachePath/short_hash1021--- PASS: TestSkippedUploadsHandler (2.38s)1022=== CONT TestOrphanedObjectsGC1023=== CONT TestGCSweepSkipsPendingObjects10242026/11/06 07:12:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33791/oidc10252026/11/06 07:12:27 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1026--- PASS: TestService_AuthMiddleware (2.66s)1027=== CONT TestReadProxyNarinfo1028--- PASS: TestService_healthCheckHandler (2.59s)1029=== CONT TestPush_SignsNarinfosOfItsPendingObjects10302026/11/06 07:12:27 INFO Received uploads request method=POST path=/api/pending_closures1031--- PASS: TestPresentRefreshesOnlyStaleClosures (2.61s)1032=== CONT TestObjectStatsUpdatedOncePerCommit1033--- PASS: TestPresentReportsOnlyClosureRoots (2.68s)1034=== CONT TestPush_RejectsBadRequests10352026/11/06 07:12:27 INFO Received uploads request method=POST path=/api/pending_closures1036--- PASS: TestGetExistingObjectsLocksRows (2.76s)1037=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit10382026/11/06 07:12:27 INFO Received uploads request method=POST path=/api/pending_closures10392026/11/06 07:12:27 INFO Received uploads request method=POST path=/api/pending_closures10402026/11/06 07:12:27 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10412026/11/06 07:12:27 INFO Received uploads request method=POST path=/api/pending_closures10422026/11/06 07:12:27 INFO Received uploads request method=POST path=/api/pending_closures1043--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.95s)1044=== CONT TestPush_RootsAreLockedInByteOrder10452026/11/06 07:12:27 INFO Aborted multipart uploads count=0 kept=01046--- PASS: TestRegisterCompletedObjectNeedsPendingRow (2.86s)1047=== CONT TestPush_CompleteWaitsForCleanupOfThePush10482026/11/06 07:12:27 INFO Aborted multipart uploads count=0 kept=010492026/11/06 07:12:27 INFO Received uploads request method=POST path=/api/pending_closures10502026/11/06 07:12:27 INFO Aborted multipart uploads count=0 kept=01051--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (2.95s)1052=== CONT TestPush_RepeatedRootCommitsOnce10532026/11/06 07:12:27 INFO Received uploads request method=POST path=/api/pending_closures1054--- PASS: TestService_Rustfstest (3.07s)1055=== CONT TestPush_CompleteCommitsEveryRoot10562026/11/06 07:12:27 WARN Force mode enabled - objects will be deleted immediately without grace period10572026/11/06 07:12:27 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010582026/11/06 07:12:27 INFO Vacuumed table table=pending_closures10592026/11/06 07:12:27 INFO Vacuumed table table=pending_objects10602026/11/06 07:12:27 INFO Vacuumed table table=multipart_uploads10612026/11/06 07:12:27 INFO Vacuumed table table=closures10622026/11/06 07:12:27 INFO Vacuumed table table=objects10632026/11/06 07:12:27 INFO Received uploads request method=POST path=/api/pending_closures10642026/11/06 07:12:27 INFO Aborted multipart uploads count=0 kept=010652026/11/06 07:12:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10662026/11/06 07:12:27 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjNkMDE4ZTQtZjMwYS00ZTdmLTlhMjItYWQzNDY5ZmM3ODBhLjNlMGIzOWM3LTRiMTgtNDY2My04YjU3LWNmNjQxNTg0NDlmYngxNzkzOTQ5MTQ3ODg2MDE1NDI010672026/11/06 07:12:27 INFO Aborted multipart uploads count=0 kept=010682026/11/06 07:12:27 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjNkMDE4ZTQtZjMwYS00ZTdmLTlhMjItYWQzNDY5ZmM3ODBhLjNlMGIzOWM3LTRiMTgtNDY2My04YjU3LWNmNjQxNTg0NDlmYngxNzkzOTQ5MTQ3ODg2MDE1NDI0 parts=11069--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (3.14s)1070=== CONT TestPush_OverlappingRootsStoreOneRowPerKey10712026/11/06 07:12:28 INFO Received uploads request method=POST path=/api/pending_closures10722026/11/06 07:12:28 WARN Force mode enabled - objects will be deleted immediately without grace period10732026/11/06 07:12:28 WARN Force mode enabled - objects will be deleted immediately without grace period10742026/11/06 07:12:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10752026/11/06 07:12:28 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=010762026/11/06 07:12:28 INFO Vacuumed table table=pending_closures10772026/11/06 07:12:28 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10782026/11/06 07:12:28 WARN Refused reserved pin name=worker-x86_64-linux10792026/11/06 07:12:28 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10802026/11/06 07:12:28 INFO Received create pin request method=POST path=/api/pins/my-app10812026/11/06 07:12:28 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1082--- PASS: TestCreatePin_ReservedPins (3.21s)1083=== CONT TestReadRedirectUsesPublicS3URL10842026/11/06 07:12:28 INFO Vacuumed table table=pending_objects10852026/11/06 07:12:28 INFO Vacuumed table table=multipart_uploads10862026/11/06 07:12:28 INFO Vacuumed table table=closures10872026/11/06 07:12:28 INFO Vacuumed table table=objects10882026/11/06 07:12:28 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NjNkMDE4ZTQtZjMwYS00ZTdmLTlhMjItYWQzNDY5ZmM3ODBhLmJmNjhhOWYyLWQ1YWQtNDQ5NC1hM2Y5LTc5OTkwYjIwOTE4OHgxNzkzOTQ5MTQ3NDc0NTEzODgy parts=121089--- PASS: TestSweepRechecksPendingAfterLocking (3.23s)1090=== CONT TestReadProxyRangeRequest10912026/11/06 07:12:28 INFO Received uploads request method=POST path=/api/pending_closures1092--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.37s)1093=== CONT TestObjectStatsTrigger10942026/11/06 07:12:28 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=010952026/11/06 07:12:28 INFO Vacuumed table table=pending_closures10962026/11/06 07:12:28 INFO Vacuumed table table=pending_objects10972026/11/06 07:12:28 INFO Vacuumed table table=multipart_uploads10982026/11/06 07:12:28 INFO Vacuumed table table=closures10992026/11/06 07:12:28 INFO Vacuumed table table=objects1100--- PASS: TestSweepSkipsRowsLockedByPush (3.29s)1101=== CONT TestReadRedirectKeepsNarinfoProxied11022026/11/06 07:12:28 INFO Received uploads request method=POST path=/api/pending_closures11032026/11/06 07:12:28 INFO Aborted multipart uploads count=0 kept=011042026/11/06 07:12:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11052026/11/06 07:12:28 INFO Aborted multipart uploads count=0 kept=011062026/11/06 07:12:28 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NjNkMDE4ZTQtZjMwYS00ZTdmLTlhMjItYWQzNDY5ZmM3ODBhLjVmOTEzYmNjLWQ3OGItNDRhMi04ZGVhLTE1NzZiNDczYWY3MHgxNzkzOTQ5MTQ3NjYyODIxMDU1 parts=121107--- PASS: TestPushWaitsForSweepHoldingRow (3.47s)1108=== CONT TestPendingCleanupUsesOneCutoff1109=== RUN TestPush_RejectsBadRequests/no_roots1110=== PAUSE TestPush_RejectsBadRequests/no_roots1111=== RUN TestPush_RejectsBadRequests/no_objects1112=== PAUSE TestPush_RejectsBadRequests/no_objects1113=== RUN TestPush_RejectsBadRequests/bad_root1114=== PAUSE TestPush_RejectsBadRequests/bad_root1115=== RUN TestPush_RejectsBadRequests/root_not_in_objects1116=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1117=== CONT TestReadRedirectNar11182026/11/06 07:12:28 INFO Received uploads request method=POST path=/api/pending_closures11192026/11/06 07:12:28 INFO Received uploads request method=POST path=/api/pending_closures11202026/11/06 07:12:28 WARN Force mode enabled - objects will be deleted immediately without grace period11212026/11/06 07:12:28 INFO Received push request method=POST path=/api/pushes11222026/11/06 07:12:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11232026-11-06 07:12:28.413 UTC [568] ERROR: could not obtain lock on row in relation "closures"11242026-11-06 07:12:28.413 UTC [568] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11252026-11-06 07:12:28.415 UTC [568] ERROR: could not obtain lock on row in relation "closures"11262026-11-06 07:12:28.415 UTC [568] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11272026-11-06 07:12:28.415 UTC [568] ERROR: could not obtain lock on row in relation "closures"11282026-11-06 07:12:28.415 UTC [568] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11292026-11-06 07:12:28.415 UTC [568] ERROR: could not obtain lock on row in relation "closures"11302026-11-06 07:12:28.415 UTC [568] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11312026-11-06 07:12:28.416 UTC [568] ERROR: could not obtain lock on row in relation "closures"11322026-11-06 07:12:28.416 UTC [568] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11332026/11/06 07:12:28 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=01134--- PASS: TestPush_RootsAreLockedInByteOrder (0.76s)1135=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded11362026/11/06 07:12:28 INFO Received push request method=POST path=/api/pushes11372026/11/06 07:12:28 INFO Vacuumed table table=pending_closures11382026/11/06 07:12:28 INFO Vacuumed table table=pending_objects11392026/11/06 07:12:28 INFO Vacuumed table table=multipart_uploads11402026/11/06 07:12:28 INFO Vacuumed table table=closures11412026/11/06 07:12:28 INFO Vacuumed table table=objects1142--- PASS: TestGCSweepDeliversEachKeyOnce (1.34s)1143=== CONT TestReadProxyDisabled11442026/11/06 07:12:28 INFO Received complete push request method=POST path=/api/pushes/1/complete11452026/11/06 07:12:28 INFO Completed push id=1 objects=4 duration=16.637211ms1146--- PASS: TestPush_RepeatedRootCommitsOnce (0.68s)1147=== CONT TestReadProxyRootRedirectsToIndexHTML11482026/11/06 07:12:28 WARN Force mode enabled - objects will be deleted immediately without grace period11492026/11/06 07:12:28 INFO Received push request method=POST path=/api/pushes11502026/11/06 07:12:28 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=011512026/11/06 07:12:28 INFO Vacuumed table table=pending_closures11522026/11/06 07:12:28 INFO Vacuumed table table=pending_objects11532026/11/06 07:12:28 INFO Vacuumed table table=multipart_uploads11542026/11/06 07:12:28 INFO Vacuumed table table=closures1155=== NAME TestOrphanedObjectsGC1156 orphaned_objects_gc_test.go:287: GC Test Summary:1157 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1158 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1159 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1160 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1161 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1162--- PASS: TestOrphanedObjectsGC (1.40s)1163=== CONT TestMultipartCleanup11642026/11/06 07:12:28 INFO Vacuumed table table=objects1165--- PASS: TestGCSweepSkipsPendingObjects (1.42s)1166=== CONT TestReadProxyConditionalGet11672026/11/06 07:12:28 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1168--- PASS: TestReadProxyNarinfo (1.15s)1169=== CONT TestServerTLSConfig1170=== RUN TestServerTLSConfig/no_client_CA1171=== PAUSE TestServerTLSConfig/no_client_CA1172=== RUN TestServerTLSConfig/missing_CA_file1173=== PAUSE TestServerTLSConfig/missing_CA_file1174=== RUN TestServerTLSConfig/not_a_PEM_file1175=== PAUSE TestServerTLSConfig/not_a_PEM_file1176=== CONT TestReadProxyOutlastsServerWriteTimeout11772026/11/06 07:12:28 INFO Received uploads request method=POST path=/api/pending_closures1178--- PASS: TestTombstonedObjectOfferedWithoutWaiting (1.46s)1179=== CONT TestService_NativeMTLS1180--- PASS: TestReadRedirectKeepsNarinfoProxied (0.47s)1181=== CONT TestReadProxyHead1182--- PASS: TestReadProxyRangeRequest (0.57s)1183=== CONT TestMetricsCommit1184--- PASS: TestReadRedirectUsesPublicS3URL (0.64s)1185=== CONT TestReadProxyInvalidPath1186--- PASS: TestObjectStatsTrigger (0.65s)1187=== CONT TestMetricsInventory11882026/11/06 07:12:28 INFO Received uploads request method=POST path=/api/pending_closures11892026/11/06 07:12:28 INFO Received uploads request method=POST path=/api/pending_closures11902026-11-06 07:12:28.807 UTC [582] ERROR: Push does not exist: id=111912026-11-06 07:12:28.807 UTC [582] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE11922026-11-06 07:12:28.807 UTC [582] STATEMENT: SELECT commit_push($1)1193--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.12s)1194=== CONT TestReadProxy40411952026/11/06 07:12:28 INFO Received cleanup request method=DELETE path=/api/pending_closures1196--- PASS: TestReadRedirectNar (0.53s)1197=== CONT TestNARDeduplicationMetadataUploadBug11982026/11/06 07:12:28 INFO Received uploads request method=POST path=/api/pending_closures11992026/11/06 07:12:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1200--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.43s)1201=== CONT TestReadProxyNarStreaming12022026/11/06 07:12:28 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NjNkMDE4ZTQtZjMwYS00ZTdmLTlhMjItYWQzNDY5ZmM3ODBhLjBlYmE5NmM4LThiMjMtNGFjNy04ZjliLTc1ZmM4YzRmZmE4ZHgxNzkzOTQ5MTQ4MzEzNzgzOTU0 error="Get \"http://127.0.0.1:1/bucket13/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"12032026/11/06 07:12:28 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NjNkMDE4ZTQtZjMwYS00ZTdmLTlhMjItYWQzNDY5ZmM3ODBhLmYxNmQ0OGIyLWViN2YtNGUwMi05NWU4LWZkZTlmZmVmMGI0OHgxNzkzOTQ5MTQ4MzAzNDA3MjAw parts=1212042026/11/06 07:12:28 INFO Received cleanup request method=DELETE path=/api/pending_closures1205--- PASS: TestReadProxyDisabled (0.44s)1206=== CONT TestCreatePendingClosureRejectsOversizedNAR12072026/11/06 07:12:28 INFO Aborted multipart uploads count=1 kept=012082026/11/06 07:12:28 INFO Received uploads request method=POST path=/api/pending_closures1209--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1210=== CONT TestReadProxyContentNegotiation1211--- PASS: TestRedundantMultipartUpload (4.06s)1212=== CONT TestCacheConfigHandlerMaxNarSize1213--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1214=== CONT TestReadProxyNarinfoAlreadyDecompressed1215--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.46s)1216=== CONT TestGenerateLandingPage1217--- PASS: TestGenerateLandingPage (0.01s)1218=== CONT TestDeduplicatedObjectsRecordedAsPending12192026/11/06 07:12:28 INFO Received uploads request method=POST path=/api/pending_closures12202026/11/06 07:12:29 WARN Force mode enabled - objects will be deleted immediately without grace period12212026/11/06 07:12:29 WARN Force mode enabled - objects will be deleted immediately without grace period12222026/11/06 07:12:29 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=012232026/11/06 07:12:29 INFO Vacuumed table table=pending_closures12242026/11/06 07:12:29 INFO Vacuumed table table=pending_objects12252026/11/06 07:12:29 INFO Vacuumed table table=multipart_uploads12262026/11/06 07:12:29 INFO Vacuumed table table=closures12272026/11/06 07:12:29 INFO Vacuumed table table=objects12282026/11/06 07:12:29 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12292026/11/06 07:12:29 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1230--- PASS: TestFailedS3DeleteKeepsTombstone (4.16s)1231=== CONT TestService_readinessHandler1232--- PASS: TestReadProxyConditionalGet (0.53s)1233=== CONT TestLeadElectsOneAndHandsOver12342026/11/06 07:12:29 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12352026/11/06 07:12:29 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1236--- PASS: TestService_NativeMTLS (0.52s)1237=== CONT TestClientSharedPathCommittedMidPush1238--- PASS: TestReadProxyHead (0.54s)1239=== CONT TestGCBugBareHashReferences12402026/11/06 07:12:29 INFO Received cleanup request method=DELETE path=/api/pending_closures12412026/11/06 07:12:29 INFO Received push request method=POST path=/api/pushes12422026/11/06 07:12:29 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket42/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""12432026/11/06 07:12:29 INFO Aborted multipart uploads count=0 kept=112442026/11/06 07:12:29 INFO Received cleanup request method=DELETE path=/api/pending_closures12452026/11/06 07:12:29 INFO Aborted multipart uploads count=1 kept=01246--- PASS: TestMultipartCleanup (0.68s)1247=== CONT TestGCAdvisoryLockBlocksConcurrentRun12482026/11/06 07:12:29 INFO Received complete push request method=POST path=/api/pushes/1/complete1249--- PASS: TestReadProxyInvalidPath (0.53s)1250=== CONT TestPinProtectsFromGC12512026/11/06 07:12:29 INFO Received push request method=POST path=/api/pushes12522026/11/06 07:12:29 INFO Received complete push request method=POST path=/api/pushes/1/complete12532026/11/06 07:12:30 INFO Completed push id=1 objects=4 duration=1.072562554s12542026/11/06 07:12:30 INFO Completed push id=1 objects=4 duration=1.182630415s12552026/11/06 07:12:30 INFO Received push request method=POST path=/api/pushes12562026/11/06 07:12:30 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12572026/11/06 07:12:30 INFO Completed upload id=2 objects=2 duration=2.312021ms1258=== NAME TestNARDeduplicationMetadataUploadBug1259 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug427360472/001/store/azqb4bfrv24fjxj68kz756zxr1rw2ji6-file1.txt1260--- PASS: TestMetricsCommit (1.74s)1261=== CONT TestLeadEndsOnShutdown1262--- PASS: TestCommitRacingPendingCleanupKeepsObjects (5.56s)1263=== CONT TestConnectWaitsForAPeerMigration12642026/11/06 07:12:30 INFO Aborted multipart uploads count=0 kept=012652026/11/06 07:12:30 WARN Force mode enabled - objects will be deleted immediately without grace period12662026/11/06 07:12:30 INFO Received uploads request method=POST path=/api/pending_closures1267=== CONT TestResolveDBConnectionString1268--- PASS: TestDeduplicatedObjectsRecordedAsPending (1.58s)1269=== RUN TestResolveDBConnectionString/flag_wins1270=== PAUSE TestResolveDBConnectionString/flag_wins1271=== RUN TestResolveDBConnectionString/file_when_flag_empty1272=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1273=== RUN TestResolveDBConnectionString/missing_file_is_an_error1274=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1275=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1276=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1277=== RUN TestResolveDBConnectionString/nothing_configured1278=== PAUSE TestResolveDBConnectionString/nothing_configured1279=== CONT TestLeadIncumbentAnnouncesAtOnce12802026/11/06 07:12:30 WARN readiness check failed error="closed pool"1281--- PASS: TestService_readinessHandler (1.51s)1282=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1283--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.77s)1284=== CONT TestDeleteClosuresRacingPins1285--- PASS: TestReadProxyContentNegotiation (1.83s)1286=== CONT TestClientFallsBackToClosures1287--- PASS: TestMetricsInventory (1.96s)1288=== CONT TestService_createPendingClosureHandler1289--- PASS: TestReadProxyNarStreaming (1.87s)1290=== CONT TestClientWithDependencies12912026/11/06 07:12:30 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"1292--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (1.58s)1293=== CONT TestClientPushesUseOnePush1294=== NAME TestOrphanedObjectsGCStressTest1295 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1296 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion12972026/11/06 07:12:31 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=012982026/11/06 07:12:31 INFO Vacuumed table table=pending_closures12992026/11/06 07:12:31 INFO Vacuumed table table=pending_objects13002026/11/06 07:12:31 INFO Vacuumed table table=multipart_uploads13012026/11/06 07:12:31 INFO Received push request method=POST path=/api/pushes13022026/11/06 07:12:31 INFO Vacuumed table table=closures13032026/11/06 07:12:31 INFO Vacuumed table table=objects13042026/11/06 07:12:31 INFO Received complete push request method=POST path=/api/pushes/2/complete13052026/11/06 07:12:31 INFO Completed push id=2 objects=4 duration=5.338909ms1306--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (3.59s)1307=== CONT TestPushDedupSurvivesConcurrentGC13082026/11/06 07:12:31 INFO Received complete push request method=POST path=/api/pushes/1/complete13092026/11/06 07:12:31 INFO lead: acquired remote=192.0.2.1:123413102026/11/06 07:12:31 INFO Received uploads request method=POST path=/api/pending_closures13112026/11/06 07:12:31 INFO Received uploads request method=POST path=/api/pending_closures13122026/11/06 07:12:31 INFO Received uploads request method=POST path=/api/pending_closures13132026/11/06 07:12:31 INFO Received push request method=POST path=/api/pushes13142026/11/06 07:12:31 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13152026/11/06 07:12:31 INFO Signed narinfos id=1 count=113162026/11/06 07:12:31 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13172026/11/06 07:12:31 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13182026/11/06 07:12:31 INFO Received push request method=POST path=/api/pushes13192026/11/06 07:12:31 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"13202026/11/06 07:12:31 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13212026/11/06 07:12:31 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"13222026/11/06 07:12:31 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13232026/11/06 07:12:31 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=113242026/11/06 07:12:31 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13252026/11/06 07:12:31 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1326=== CONT TestClientMultipleUploads1327--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (4.13s)1328--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (3.59s)1329=== CONT TestGCMetrics13302026/11/06 07:12:31 WARN Rate limiter enabled after throttle name=s3-test rate=513312026/11/06 07:12:31 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1332=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1333 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101334 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001335--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.76s)1336=== CONT TestService_cleanupPendingClosuresHandler1337--- PASS: TestObjectStatsUpdatedOncePerCommit (4.34s)1338=== CONT TestService_verifyS3ReuploadsStaleNarinfo1339=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed1340=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed1341=== RUN TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed1342=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed1343=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost1344=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost1345=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed1346=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed1347=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed1348=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed1349=== CONT TestService_ReadScope_PublicByDefault13502026/11/06 07:12:32 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13512026/11/06 07:12:32 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NjNkMDE4ZTQtZjMwYS00ZTdmLTlhMjItYWQzNDY5ZmM3ODBhLjM1YjE2ZGZjLTQ3ZjItNDA4MC1hYTkzLWI5ZTg0NTgzMjVkYngxNzkzOTQ5MTUxNTI2OTExMDk0 parts=1013522026/11/06 07:12:32 INFO Completed push id=1 objects=6 duration=1.072681736s13532026/11/06 07:12:32 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1354=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT1355--- PASS: TestPush_CompleteCommitsEveryRoot (4.44s)1356=== NAME TestPinProtectsFromGC1357 client_integration_test.go:778: Pinned store path: /build/TestPinProtectsFromGC1195557787/001/store/albv928qdvbqn5fx0i7fjswhddkzmwpf-pinned-file.txt1358 client_integration_test.go:779: Unpinned store path: /build/TestPinProtectsFromGC1195557787/001/store/a11dhfin5iy6il90v89qyki1x53imiin-unpinned-file.txt13592026/11/06 07:12:32 INFO Completed upload id=1 objects=2 duration=5.51983ms13602026/11/06 07:12:32 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013612026/11/06 07:12:32 INFO Received uploads request method=POST path=/api/pending_closures13622026/11/06 07:12:32 INFO Starting cleanup of old closures method=DELETE path=/api/closures1363--- PASS: TestGCBugBareHashReferences (3.24s)1364=== CONT TestClientCADerivations13652026/11/06 07:12:32 INFO Aborted multipart uploads count=0 kept=013662026/11/06 07:12:32 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=013672026/11/06 07:12:32 INFO Aborted multipart uploads count=0 kept=013682026/11/06 07:12:32 INFO Received push request method=POST path=/api/pushes13692026/11/06 07:12:32 INFO Vacuumed table table=pending_closures13702026/11/06 07:12:32 INFO Vacuumed table table=pending_objects13712026/11/06 07:12:32 INFO Vacuumed table table=multipart_uploads13722026/11/06 07:12:32 WARN Force mode enabled - objects will be deleted immediately without grace period13732026/11/06 07:12:32 INFO Vacuumed table table=closures13742026/11/06 07:12:32 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13752026/11/06 07:12:32 INFO Uploading azqb4bfrv24fjxj68kz756zxr1rw2ji6-file1.txt (160B)13762026/11/06 07:12:32 INFO Vacuumed table table=objects13772026/11/06 07:12:32 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=013782026/11/06 07:12:32 INFO Vacuumed table table=pending_closures13792026/11/06 07:12:32 INFO Vacuumed table table=pending_objects13802026/11/06 07:12:32 INFO Vacuumed table table=multipart_uploads13812026/11/06 07:12:32 INFO Vacuumed table table=closures13822026/11/06 07:12:32 INFO Vacuumed table table=objects13832026/11/06 07:12:32 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001384=== CONT TestCompleteMultipartUnregistered1385--- PASS: TestService_createPendingClosureHandler (1.81s)1386--- PASS: TestGCMetrics (0.94s)1387=== CONT TestClientErrorHandling1388=== RUN TestClientErrorHandling/InvalidStorePath1389=== PAUSE TestClientErrorHandling/InvalidStorePath13902026/11/06 07:12:32 WARN Failed to register uploaded object key=azqb4bfrv24fjxj68kz756zxr1rw2ji6.ls error="server returned 404: 404 page not found\n"1391=== RUN TestClientErrorHandling/InvalidAuthToken1392=== PAUSE TestClientErrorHandling/InvalidAuthToken1393=== RUN TestClientErrorHandling/ServerNotAvailable1394=== PAUSE TestClientErrorHandling/ServerNotAvailable1395=== CONT TestCacheStatsHandler13962026/11/06 07:12:32 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"13972026/11/06 07:12:32 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13982026/11/06 07:12:32 INFO Signed narinfos id=1 count=113992026/11/06 07:12:32 INFO Uploading 1 narinfos14002026/11/06 07:12:32 INFO Received cleanup request method=DELETE path=/api/pending_closures14012026/11/06 07:12:32 INFO Aborted multipart uploads count=0 kept=014022026/11/06 07:12:32 INFO Received uploads request method=POST path=/api/pending_closures14032026/11/06 07:12:32 INFO Received complete push request method=POST path=/api/pushes/1/complete14042026/11/06 07:12:32 WARN Failed to register uploaded object key=azqb4bfrv24fjxj68kz756zxr1rw2ji6.narinfo error="server returned 404: 404 page not found\n"1405=== NAME TestOrphanedObjectsGCStressTest1406 orphaned_objects_gc_test.go:503: Stress test completed successfully:1407 orphaned_objects_gc_test.go:504: - Active objects preserved: 201408 orphaned_objects_gc_test.go:505: - Objects deleted: 2101409 orphaned_objects_gc_test.go:506: - Total GC'd: 2101410--- PASS: TestOrphanedObjectsGCStressTest (5.44s)1411=== CONT TestCacheConfigHandler1412=== RUN TestCacheConfigHandler/full_config,_no_issuer1413=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1414=== RUN TestCacheConfigHandler/no_cache_url_configured1415=== PAUSE TestCacheConfigHandler/no_cache_url_configured1416=== RUN TestCacheConfigHandler/no_signing_keys1417=== PAUSE TestCacheConfigHandler/no_signing_keys1418=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1419=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1420=== CONT TestService_ReadAuthMiddleware14212026/11/06 07:12:32 INFO Completed push id=1 objects=3 duration=13.847206ms14222026/11/06 07:12:32 INFO Upload complete. (246ms)14232026/11/06 07:12:32 INFO Received cleanup request method=DELETE path=/api/pending_closures1424=== NAME TestNARDeduplicationMetadataUploadBug1425 metadata_upload_test.go:54: Retrieved narinfo from S3:1426 StorePath: /build/TestNARDeduplicationMetadataUploadBug427360472/001/store/azqb4bfrv24fjxj68kz756zxr1rw2ji6-file1.txt1427 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1428 Compression: zstd1429 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1430 NarSize: 1601431 References: 1432 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf14332026/11/06 07:12:32 INFO Aborted multipart uploads count=1 kept=01434 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1435 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1436 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}14372026/11/06 07:12:32 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14382026-11-06 07:12:32.565 UTC [751] ERROR: Closure does not exist: id=114392026-11-06 07:12:32.565 UTC [751] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE14402026-11-06 07:12:32.565 UTC [751] STATEMENT: -- name: CommitPendingClosure :one1441 SELECT commit_pending_closure($1::bigint)::bigint1442 1443--- PASS: TestService_cleanupPendingClosuresHandler (0.92s)1444=== CONT TestService_verifyS3Integrity1445--- PASS: TestService_ReadScope_PublicByDefault (0.74s)1446=== CONT TestService_AuthMiddleware_MTLSBoundSubjects14472026/11/06 07:12:32 INFO lead: acquired remote=192.0.2.1:123414482026/11/06 07:12:32 INFO lead: released remote=192.0.2.1:12341449--- PASS: TestLeadIncumbentAnnouncesAtOnce (2.11s)1450=== CONT TestService_AuthMiddleware_OIDC14512026/11/06 07:12:32 INFO lead: released remote=192.0.2.1:123414522026/11/06 07:12:32 INFO Received uploads request method=POST path=/api/pending_closures14532026/11/06 07:12:32 INFO lead: acquired remote=192.0.2.1:123414542026/11/06 07:12:32 INFO lead: acquired remote=192.0.2.1:123414552026/11/06 07:12:32 INFO Aborted multipart uploads count=0 kept=014562026/11/06 07:12:32 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46837/oidc14572026/11/06 07:12:32 INFO Received uploads request method=POST path=/api/pending_closures1458=== CONT TestService_RequireScope_OIDC1459--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.50s)1460--- PASS: TestReadProxy404 (4.04s)1461=== CONT TestService_AuthMiddleware_MTLSProxyHeader14622026/11/06 07:12:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45623/oidc1463--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.79s)1464=== CONT TestClientIntegration14652026/11/06 07:12:33 INFO lead: released remote=192.0.2.1:12341466--- PASS: TestLeadEndsOnShutdown (3.42s)1467=== CONT TestGCEndsOnShutdown/before_the_run14682026/11/06 07:12:33 INFO lead: released remote=192.0.2.1:12341469--- PASS: TestLeadElectsOneAndHandsOver (4.77s)1470=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1471--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (3.30s)1472=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1473=== NAME TestNARDeduplicationMetadataUploadBug1474 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug427360472/001/store/phvaf2bdb15wxylssx95b814mndram7s-file2.txt1475=== NAME TestClientMultipleUploads1476 client_integration_test.go:405: Created store path 0: /build/TestClientMultipleUploads411066437/001/store/48ywfz30dpw92rjshva7c5q6gidybywc-test-file-0.txt14772026/11/06 07:12:34 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=014782026/11/06 07:12:34 INFO Received push request method=POST path=/api/pushes14792026/11/06 07:12:34 INFO Vacuumed table table=pending_closures1480=== NAME TestClientWithDependencies1481 client_integration_test.go:660: Built derivation: /build/TestClientWithDependencies3686571451/001/store/6n9l3q3zg3hpqrsi9bn2r7nkdgykhycy-test-script14822026/11/06 07:12:34 INFO Vacuumed table table=pending_objects14832026/11/06 07:12:34 INFO Vacuumed table table=multipart_uploads14842026/11/06 07:12:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14852026/11/06 07:12:34 INFO Uploading albv928qdvbqn5fx0i7fjswhddkzmwpf-pinned-file.txt (128B)14862026/11/06 07:12:34 INFO Vacuumed table table=closures14872026/11/06 07:12:34 INFO Vacuumed table table=objects14882026/11/06 07:12:34 INFO Aborted multipart uploads count=0 kept=014892026/11/06 07:12:34 WARN Force mode enabled - objects will be deleted immediately without grace period14902026/11/06 07:12:34 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=01491=== NAME TestClientMultipleUploads1492 client_integration_test.go:405: Created store path 1: /build/TestClientMultipleUploads411066437/001/store/dsa8s35rrarh3y67zb4fg5yj8ai0sq66-test-file-1.txt14932026/11/06 07:12:34 INFO Vacuumed table table=pending_closures14942026/11/06 07:12:34 INFO Vacuumed table table=pending_objects14952026/11/06 07:12:34 INFO Vacuumed table table=multipart_uploads14962026/11/06 07:12:34 INFO Vacuumed table table=closures14972026/11/06 07:12:34 INFO Vacuumed table table=objects1498=== NAME TestClientWithDependencies1499 client_integration_test.go:662: Found 1 dependencies (including self)1500=== NAME TestClientCADerivations1501 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations4033948984/001/store/f76aa4fmnd8cc7ks5qrym9fxbd72s8lr-ca-test1502--- PASS: TestPushDedupSurvivesConcurrentGC (3.02s)1503=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete15042026/11/06 07:12:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15052026/11/06 07:12:34 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"15062026/11/06 07:12:34 WARN Failed to register uploaded object key=albv928qdvbqn5fx0i7fjswhddkzmwpf.ls error="server returned 404: 404 page not found\n"15072026/11/06 07:12:34 INFO Signed narinfos id=1 count=115082026/11/06 07:12:34 INFO Uploading 1 narinfos15092026/11/06 07:12:34 INFO Received complete push request method=POST path=/api/pushes/1/complete15102026/11/06 07:12:34 WARN Failed to register uploaded object key=albv928qdvbqn5fx0i7fjswhddkzmwpf.narinfo error="server returned 404: 404 page not found\n"15112026/11/06 07:12:34 INFO Completed push id=1 objects=3 duration=13.786585ms15122026/11/06 07:12:34 INFO Upload complete. (1.726s)1513--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.37s)1514=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1515=== NAME TestClientMultipleUploads1516 client_integration_test.go:405: Created store path 2: /build/TestClientMultipleUploads411066437/001/store/x57q2fc822hmw1c5lz4m9kj7s1ri8wn8-test-file-2.txt15172026/11/06 07:12:34 INFO Received uploads request method=POST path=/api/pending_closures15182026/11/06 07:12:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15192026/11/06 07:12:34 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1520--- PASS: TestCompleteMultipartUnregistered (1.83s)1521=== CONT TestIsValidUploadKey/narinfo1522=== CONT TestProxyWriteTimeout/narinfo1523=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1524--- PASS: TestService_ReadAuthMiddleware (1.83s)1525=== CONT TestIsValidUploadKey/unknown_type1526=== CONT TestIsValidUploadKey/empty_key1527=== CONT TestIsValidUploadKey/absolute1528=== CONT TestIsValidUploadKey/traversal_nar1529=== CONT TestIsValidUploadKey/traversal1530=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1531=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1532=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1533=== CONT TestIsValidUploadKey/index.html1534=== CONT TestIsValidUploadKey/nix-cache-info1535=== CONT TestIsValidUploadKey/realisation_plus_in_output1536=== CONT TestIsValidUploadKey/realisation1537=== CONT TestIsValidUploadKey/build_log_equals1538=== CONT TestIsValidUploadKey/build_log_question_mark1539=== CONT TestIsValidUploadKey/build_log_plus_in_name1540=== CONT TestIsValidUploadKey/build_log_home-manager_file1541=== CONT TestIsValidUploadKey/build_log1542=== CONT TestIsValidUploadKey/listing1543=== CONT TestIsValidUploadKey/nar_plain1544=== CONT TestIsValidUploadKey/nar_xz1545=== CONT TestIsValidUploadKey/nar_zst1546--- PASS: TestIsValidUploadKey (0.13s)1547 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1548 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1549 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1550 --- PASS: TestIsValidUploadKey/absolute (0.00s)1551 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1552 --- PASS: TestIsValidUploadKey/traversal (0.00s)1553 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1554 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1555 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1556 --- PASS: TestIsValidUploadKey/index.html (0.00s)1557 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1558 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1559 --- PASS: TestIsValidUploadKey/realisation (0.00s)1560 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1561 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1562 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1563 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1564 --- PASS: TestIsValidUploadKey/build_log (0.00s)1565 --- PASS: TestIsValidUploadKey/listing (0.00s)1566 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1567 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1568 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1569=== CONT TestPendingClosureWriteTimeout/empty1570=== CONT TestProxyWriteTimeout/unknown_size1571=== CONT TestProxyWriteTimeout/10_GiB_nar1572=== CONT TestProxyWriteTimeout/1_GiB_nar1573--- PASS: TestProxyWriteTimeout (0.13s)1574 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1575 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1576 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1577 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1578=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check15792026/11/06 07:12:34 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15802026/11/06 07:12:34 WARN mTLS auth: bound subjects configured but subject DN unavailable15812026/11/06 07:12:34 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1582--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.86s)1583=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1584=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1585=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1586=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1587=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1588=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1589=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1590=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1591=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1592=== CONT TestPendingClosureWriteTimeout/670k_objects1593=== CONT TestPendingClosureWriteTimeout/400_objects1594=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info15952026/11/06 07:12:34 INFO Received uploads request method=POST path=/1596=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15972026/11/06 07:12:34 INFO Received complete multipart upload request method=POST path=/1598=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key15992026/11/06 07:12:34 INFO Received request for more parts method=POST path=/1600=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16012026/11/06 07:12:34 INFO Received uploads request method=POST path=/1602--- PASS: TestUploadHandlersRejectInvalidKeys (2.38s)1603 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1604 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1605 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1606 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1607=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16082026/11/06 07:12:34 INFO Received uploads request method=POST path=/1609=== NAME TestClientCADerivations1610 client_ca_test.go:139: Found 1 dependencies (including self)1611--- PASS: TestCacheStatsHandler (2.04s)1612=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16132026/11/06 07:12:34 INFO Received request for more parts method=POST path=/1614=== RUN TestService_RequireScope_OIDC/builder_may_write1615=== PAUSE TestService_RequireScope_OIDC/builder_may_write1616=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1617=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1618=== RUN TestService_RequireScope_OIDC/ops_may_admin1619=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1620=== RUN TestService_RequireScope_OIDC/ops_may_not_write1621=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1622=== RUN TestService_RequireScope_OIDC/reader_may_not_write1623=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1624=== RUN TestService_RequireScope_OIDC/static_token_may_admin1625=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1626=== RUN TestService_RequireScope_OIDC/static_token_may_write1627=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1628=== RUN TestService_RequireScope_OIDC/reader_may_read1629=== PAUSE TestService_RequireScope_OIDC/reader_may_read1630=== RUN TestService_RequireScope_OIDC/writer_implies_read1631=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1632=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1633=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1634=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1635=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1636=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1637=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1638=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1639=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1640=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1641=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1642=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16432026/11/06 07:12:34 INFO Received complete multipart upload request method=POST path=/1644=== CONT TestParseSingleRange/none1645=== CONT TestParseSingleRange/end_clamped_to_size1646=== CONT TestParseSingleRange/start_far_past_EOF1647=== CONT TestParseSingleRange/suffix_exceeds_size1648=== CONT TestParseSingleRange/suffix1649=== CONT TestParseSingleRange/malformed_both_empty1650=== CONT TestParseSingleRange/open-ended1651=== CONT TestParseSingleRange/closed1652=== CONT TestParseSingleRange/single_byte1653=== CONT TestParseSingleRange/malformed_end_before_start1654=== CONT TestParseSingleRange/start_past_EOF1655=== CONT TestParseSingleRange/multi-range_ignored1656=== CONT TestParseSingleRange/malformed_no_dash1657=== CONT TestParseSingleRange/unknown_unit1658--- PASS: TestParseSingleRange (2.27s)1659 --- PASS: TestParseSingleRange/none (0.00s)1660 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1661 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1662 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1663 --- PASS: TestParseSingleRange/suffix (0.00s)1664 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1665 --- PASS: TestParseSingleRange/open-ended (0.00s)1666 --- PASS: TestParseSingleRange/closed (0.00s)1667 --- PASS: TestParseSingleRange/single_byte (0.00s)1668 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1669 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1670 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1671 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1672 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1673=== CONT TestIsValidCachePath/narinfo1674=== CONT TestIsValidCachePath/short_hash1675=== CONT TestIsValidCachePath/wrong_extension1676=== CONT TestIsValidCachePath/leading_slash1677=== CONT TestIsValidCachePath/empty1678=== CONT TestIsValidCachePath/random_path1679=== CONT TestIsValidCachePath/invalid_char_u1680=== CONT TestIsValidCachePath/invalid_char_e1681=== CONT TestIsValidCachePath/traversal_in_middle1682=== CONT TestIsValidCachePath/traversal_parent1683=== CONT TestIsValidCachePath/index.html1684=== CONT TestIsValidCachePath/nix-cache-info1685=== CONT TestIsValidCachePath/realisation1686=== CONT TestIsValidCachePath/log1687=== CONT TestIsValidCachePath/ls1688=== CONT TestIsValidCachePath/nar_uncompressed1689=== CONT TestIsValidCachePath/nar_bz21690=== CONT TestIsValidCachePath/nar_xz1691=== CONT TestIsValidCachePath/nar_zst1692=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1693--- PASS: TestIsValidCachePath (2.27s)1694 --- PASS: TestIsValidCachePath/narinfo (0.00s)1695 --- PASS: TestIsValidCachePath/short_hash (0.00s)1696 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1697 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1698 --- PASS: TestIsValidCachePath/empty (0.00s)1699 --- PASS: TestIsValidCachePath/random_path (0.00s)1700 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1701 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1702 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1703 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1704 --- PASS: TestIsValidCachePath/index.html (0.00s)1705 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1706 --- PASS: TestIsValidCachePath/realisation (0.00s)1707 --- PASS: TestIsValidCachePath/log (0.00s)1708 --- PASS: TestIsValidCachePath/ls (0.00s)1709 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1710 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1711 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1712 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1713 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1714=== CONT TestPush_RejectsBadRequests/no_roots17152026/11/06 07:12:34 INFO Received push request method=POST path=/api/pushes1716=== CONT TestPush_RejectsBadRequests/bad_root17172026/11/06 07:12:34 INFO Received push request method=POST path=/api/pushes1718=== CONT TestPush_RejectsBadRequests/root_not_in_objects17192026/11/06 07:12:34 INFO Received push request method=POST path=/api/pushes1720=== CONT TestPush_RejectsBadRequests/no_objects17212026/11/06 07:12:34 INFO Received push request method=POST path=/api/pushes1722=== CONT TestServerTLSConfig/no_client_CA1723--- PASS: TestPush_RejectsBadRequests (0.77s)1724 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1725 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1726 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1727 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1728=== CONT TestServerTLSConfig/missing_CA_file1729=== CONT TestServerTLSConfig/not_a_PEM_file1730--- PASS: TestServerTLSConfig (0.00s)1731 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1732 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1733 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1734=== CONT TestResolveDBConnectionString/flag_wins1735=== CONT TestResolveDBConnectionString/nothing_configured1736=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1737=== CONT TestResolveDBConnectionString/missing_file_is_an_error1738=== CONT TestResolveDBConnectionString/file_when_flag_empty1739=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed1740--- PASS: TestResolveDBConnectionString (0.00s)1741 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1742 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1743 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1744 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1745 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1746=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed1747=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed17482026/11/06 07:12:34 INFO Aborted multipart uploads count=0 kept=017492026/11/06 07:12:34 INFO Received uploads request method=POST path=/api/pending_closures17502026/11/06 07:12:34 INFO Received push request method=POST path=/api/pushes17512026/11/06 07:12:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17522026/11/06 07:12:34 INFO Received uploads request method=POST path=/api/pending_closures17532026/11/06 07:12:34 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17542026/11/06 07:12:34 INFO Uploading 7cncqdv25mahix05m2rakam6d4p0dcsy-b (216B)17552026/11/06 07:12:34 INFO Uploading 94wp4yh9hyd3pdyikr2mrvr0k0zmfxfg-shared-dep (136B)1756=== NAME TestClientIntegration1757 client_integration_test.go:291: Created store path: /build/TestClientIntegration2450271632/002/store/5v3gwbksl1alikk5j6fjm0r0f1m789d7-test-file.txt17582026/11/06 07:12:34 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)17592026/11/06 07:12:34 INFO Uploading 2xak2p28llqafa5q9pklshvyba0a07fj-top (224B)17602026/11/06 07:12:34 INFO Uploading lkf6w3w3bzzvrjvvsifi8aigkhpjfp3s-shared-dep (136B)17612026/11/06 07:12:34 WARN Failed to register uploaded object key=7cncqdv25mahix05m2rakam6d4p0dcsy.ls error="server returned 404: 404 page not found\n"17622026/11/06 07:12:34 WARN Failed to register uploaded object key=3d3kaa32f2644l0zpgdnin6dhb8261y7.ls error="server returned 404: 404 page not found\n"17632026/11/06 07:12:34 WARN Failed to register uploaded object key=nar/07vwbwlzn0pg00328l7ahmri4xi7l0gmgkq0gdx64563aw0njbq0.nar.zst error="server returned 404: 404 page not found\n"17642026/11/06 07:12:34 WARN Failed to register uploaded object key=94wp4yh9hyd3pdyikr2mrvr0k0zmfxfg.ls error="server returned 404: 404 page not found\n"17652026/11/06 07:12:34 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17662026/11/06 07:12:34 INFO Signed narinfos id=1 count=217672026/11/06 07:12:34 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17682026/11/06 07:12:34 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17692026/11/06 07:12:34 INFO Signed narinfos id=2 count=217702026/11/06 07:12:34 INFO Uploading 4 narinfos17712026/11/06 07:12:34 WARN Failed to register uploaded object key=2xak2p28llqafa5q9pklshvyba0a07fj.ls error="server returned 404: 404 page not found\n"17722026/11/06 07:12:34 WARN Failed to register uploaded object key=nar/0bi61srfni3yn5lv4jcwryzykw73hd3d7cz9rcfnphmqnq1f6b47.nar.zst error="server returned 404: 404 page not found\n"17732026/11/06 07:12:34 WARN Failed to register uploaded object key=lkf6w3w3bzzvrjvvsifi8aigkhpjfp3s.ls error="server returned 404: 404 page not found\n"17742026/11/06 07:12:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17752026/11/06 07:12:34 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17762026/11/06 07:12:34 INFO Signed narinfos id=1 count=217772026/11/06 07:12:34 INFO Uploading 2 narinfos17782026/11/06 07:12:34 WARN Failed to register uploaded object key=94wp4yh9hyd3pdyikr2mrvr0k0zmfxfg.narinfo error="server returned 404: 404 page not found\n"17792026/11/06 07:12:34 WARN Failed to register uploaded object key=7cncqdv25mahix05m2rakam6d4p0dcsy.narinfo error="server returned 404: 404 page not found\n"17802026/11/06 07:12:34 WARN Failed to register uploaded object key=3d3kaa32f2644l0zpgdnin6dhb8261y7.narinfo error="server returned 404: 404 page not found\n"17812026/11/06 07:12:34 WARN Failed to register uploaded object key=lkf6w3w3bzzvrjvvsifi8aigkhpjfp3s.narinfo error="server returned 404: 404 page not found\n"17822026/11/06 07:12:34 WARN Failed to register uploaded object key=2xak2p28llqafa5q9pklshvyba0a07fj.narinfo error="server returned 404: 404 page not found\n"17832026/11/06 07:12:34 INFO Received complete push request method=POST path=/api/pushes/1/complete17842026/11/06 07:12:34 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17852026/11/06 07:12:34 WARN Failed to register uploaded object key=94wp4yh9hyd3pdyikr2mrvr0k0zmfxfg.narinfo error="server returned 404: 404 page not found\n"17862026/11/06 07:12:34 INFO Completed upload id=1 objects=6 duration=8.84938ms17872026/11/06 07:12:34 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17882026/11/06 07:12:34 INFO Completed push id=1 objects=6 duration=14.528872ms17892026/11/06 07:12:34 INFO Completed upload id=2 objects=6 duration=3.29409ms17902026/11/06 07:12:34 INFO Upload complete. (639ms)17912026/11/06 07:12:34 INFO Upload complete. (274ms)17922026/11/06 07:12:34 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NjNkMDE4ZTQtZjMwYS00ZTdmLTlhMjItYWQzNDY5ZmM3ODBhLjIyNmU3ZmU5LWU5MWMtNGQxNi1hNjg1LTgzMDM5NTVlMTQ3Y3gxNzkzOTQ5MTU0MzEwNjQ0MjUy parts=1017932026/11/06 07:12:34 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17942026/11/06 07:12:34 INFO Aborted multipart uploads count=1 kept=017952026/11/06 07:12:34 INFO Completed upload id=1 objects=2 duration=2.905386ms1796=== NAME TestClientFallsBackToClosures1797 client_pushes_test.go:112: Retrieved narinfo from S3:1798 StorePath: /build/TestClientFallsBackToClosures251765220/001/store/94wp4yh9hyd3pdyikr2mrvr0k0zmfxfg-shared-dep1799 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1800 Compression: zstd1801 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821802 NarSize: 1361803 References: 1804 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1805=== NAME TestClientSharedPathCommittedMidPush1806 client_integration_test.go:727: Retrieved narinfo from S3:1807 StorePath: /build/TestClientSharedPathCommittedMidPush2784104038/001/store/lkf6w3w3bzzvrjvvsifi8aigkhpjfp3s-shared-dep1808 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1809 Compression: zstd1810 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821811 NarSize: 1361812 References: 1813 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1814 client_integration_test.go:727: Retrieved narinfo from S3:1815 StorePath: /build/TestClientSharedPathCommittedMidPush2784104038/001/store/2xak2p28llqafa5q9pklshvyba0a07fj-top1816 URL: nar/0bi61srfni3yn5lv4jcwryzykw73hd3d7cz9rcfnphmqnq1f6b47.nar.zst1817 Compression: zstd1818 NarHash: sha256:0bi61srfni3yn5lv4jcwryzykw73hd3d7cz9rcfnphmqnq1f6b471819 NarSize: 2241820 References: /build/TestClientSharedPathCommittedMidPush2784104038/001/store/lkf6w3w3bzzvrjvvsifi8aigkhpjfp3s-shared-dep1821 CA: text:sha256:0r3k7qk3ci0d9pi8l7pjcdzvc77l88mn1j156a1hnjrrkd1nyfdy1822=== NAME TestClientFallsBackToClosures1823 client_pushes_test.go:112: Retrieved narinfo from S3:1824 StorePath: /build/TestClientFallsBackToClosures251765220/001/store/3d3kaa32f2644l0zpgdnin6dhb8261y7-a1825 URL: nar/07vwbwlzn0pg00328l7ahmri4xi7l0gmgkq0gdx64563aw0njbq0.nar.zst1826 Compression: zstd1827 NarHash: sha256:07vwbwlzn0pg00328l7ahmri4xi7l0gmgkq0gdx64563aw0njbq01828 NarSize: 2161829 References: /build/TestClientFallsBackToClosures251765220/001/store/94wp4yh9hyd3pdyikr2mrvr0k0zmfxfg-shared-dep1830 CA: text:sha256:1rky84x9f36qvpf455z3shzhd824ps0xwb2izwgxlav8054xlrgw1831 client_pushes_test.go:112: Retrieved narinfo from S3:1832 StorePath: /build/TestClientFallsBackToClosures251765220/001/store/7cncqdv25mahix05m2rakam6d4p0dcsy-b1833 URL: nar/07vwbwlzn0pg00328l7ahmri4xi7l0gmgkq0gdx64563aw0njbq0.nar.zst1834 Compression: zstd1835 NarHash: sha256:07vwbwlzn0pg00328l7ahmri4xi7l0gmgkq0gdx64563aw0njbq01836 NarSize: 2161837 References: /build/TestClientFallsBackToClosures251765220/001/store/94wp4yh9hyd3pdyikr2mrvr0k0zmfxfg-shared-dep1838 CA: text:sha256:1rky84x9f36qvpf455z3shzhd824ps0xwb2izwgxlav8054xlrgw18392026/11/06 07:12:34 INFO Received uploads request method=POST path=/api/pending_closures18402026/11/06 07:12:34 INFO Received cleanup request method=DELETE path=/api/pending_closures1841--- PASS: TestClientSharedPathCommittedMidPush (5.78s)1842=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost18432026/11/06 07:12:34 INFO Received uploads request method=POST path=/api/pending_closures1844--- PASS: TestClientFallsBackToClosures (4.15s)1845=== CONT TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed18462026/11/06 07:12:34 INFO Aborted multipart uploads count=1 kept=018472026/11/06 07:12:34 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo18482026/11/06 07:12:34 WARN Found objects in DB but missing from S3, will re-upload count=11849--- PASS: TestService_verifyS3Integrity (2.29s)1850=== CONT TestClientErrorHandling/InvalidStorePath1851--- PASS: TestPendingCleanupUsesOneCutoff (6.57s)1852=== CONT TestClientErrorHandling/InvalidAuthToken18532026/11/06 07:12:34 INFO Received push request method=POST path=/api/pushes18542026/11/06 07:12:34 INFO Received uploads request method=POST path=/api/pending_closures18552026/11/06 07:12:34 INFO Aborted multipart uploads count=0 kept=018562026/11/06 07:12:34 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)18572026/11/06 07:12:34 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18582026/11/06 07:12:34 INFO Signed narinfos id=2 count=118592026/11/06 07:12:34 INFO Uploading 1 narinfos18602026/11/06 07:12:34 WARN Failed to register uploaded object key=phvaf2bdb15wxylssx95b814mndram7s.ls error="server returned 404: 404 page not found\n"18612026/11/06 07:12:34 INFO Received uploads request method=POST path=/api/pending_closures18622026/11/06 07:12:34 INFO Received complete push request method=POST path=/api/pushes/2/complete18632026/11/06 07:12:34 WARN Failed to register uploaded object key=phvaf2bdb15wxylssx95b814mndram7s.narinfo error="server returned 404: 404 page not found\n"18642026/11/06 07:12:34 INFO Completed push id=2 objects=3 duration=6.405598ms18652026/11/06 07:12:34 INFO Upload complete. (377ms)1866=== NAME TestNARDeduplicationMetadataUploadBug1867 metadata_upload_test.go:76: Retrieved narinfo from S3:1868 StorePath: /build/TestNARDeduplicationMetadataUploadBug427360472/001/store/phvaf2bdb15wxylssx95b814mndram7s-file2.txt1869 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1870 Compression: zstd1871 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1872 NarSize: 1601873 References: 1874 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1875 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1876 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1877 {"version":1,"root":{"type":"regular","size":44}}1878--- PASS: TestNARDeduplicationMetadataUploadBug (6.12s)1879=== CONT TestClientErrorHandling/ServerNotAvailable18802026/11/06 07:12:34 INFO Aborted multipart uploads count=0 kept=018812026/11/06 07:12:34 INFO Received uploads request method=POST path=/api/pending_closures18822026/11/06 07:12:35 INFO Received push request method=POST path=/api/pushes18832026/11/06 07:12:35 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18842026/11/06 07:12:35 INFO Uploading f76aa4fmnd8cc7ks5qrym9fxbd72s8lr-ca-test (144B)18852026/11/06 07:12:35 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"18862026/11/06 07:12:35 WARN Failed to register uploaded object key=log/knxqmb2v875pvcg8cxfy3a3h95nlxahl-ca-test.drv error="server returned 404: 404 page not found\n"18872026/11/06 07:12:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18882026/11/06 07:12:35 INFO Signed narinfos id=1 count=118892026/11/06 07:12:35 WARN Failed to register uploaded object key=f76aa4fmnd8cc7ks5qrym9fxbd72s8lr.ls error="server returned 404: 404 page not found\n"18902026/11/06 07:12:35 INFO Uploading 1 narinfos18912026/11/06 07:12:35 INFO Received complete push request method=POST path=/api/pushes/1/complete18922026/11/06 07:12:35 WARN Failed to register uploaded object key=f76aa4fmnd8cc7ks5qrym9fxbd72s8lr.narinfo error="server returned 404: 404 page not found\n"18932026/11/06 07:12:35 WARN Force mode enabled - objects will be deleted immediately without grace period18942026/11/06 07:12:35 INFO Completed push id=1 objects=4 duration=16.847774ms18952026/11/06 07:12:35 INFO Upload complete. (152ms)1896=== NAME TestClientCADerivations1897 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations4033948984/001/store/f76aa4fmnd8cc7ks5qrym9fxbd72s8lr-ca-test1898 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1899 Compression: zstd1900 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1901 NarSize: 1441902 References: 1903 Deriver: /build/TestClientCADerivations4033948984/001/store/knxqmb2v875pvcg8cxfy3a3h95nlxahl-ca-test.drv1904 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1905 client_ca_test.go:185: Checking for realisation files in S3...1906=== CONT TestCacheConfigHandler/full_config,_no_issuer1907=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1908=== CONT TestCacheConfigHandler/no_signing_keys1909=== CONT TestCacheConfigHandler/no_cache_url_configured1910--- PASS: TestCacheConfigHandler (0.00s)1911 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1912 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1913 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1914 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1915=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1916=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1917=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19182026/11/06 07:12:35 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]1919=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19202026/11/06 07:12:35 WARN Authentication failed token_preview=eyJhbGciOi...PFZeefx4Wg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1921=== CONT TestService_RequireScope_OIDC/builder_may_write1922--- PASS: TestService_AuthMiddleware_OIDC (1.83s)1923 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)1924 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1925 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1926 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1927=== CONT TestService_RequireScope_OIDC/reader_may_read1928=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1929=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19302026/11/06 07:12:35 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]1931=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1932=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1933=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1934=== CONT TestService_RequireScope_OIDC/writer_implies_read1935=== CONT TestService_RequireScope_OIDC/reader_may_not_write1936=== CONT TestService_RequireScope_OIDC/static_token_may_write1937=== CONT TestService_RequireScope_OIDC/static_token_may_admin1938=== CONT TestService_RequireScope_OIDC/ops_may_admin1939=== CONT TestService_RequireScope_OIDC/ops_may_not_write1940=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1941--- PASS: TestService_RequireScope_OIDC (1.75s)1942 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1943 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1944 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1945 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1946 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1947 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1948 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1949 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1950 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1951 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1952 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1953 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1954 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1955 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1956=== NAME TestClientCADerivations1957 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1958 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache19592026/11/06 07:12:35 INFO Received uploads request method=POST path=/api/pending_closures19602026/11/06 07:12:35 WARN Force mode enabled - objects will be deleted immediately without grace period19612026/11/06 07:12:35 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:33487/bucket93/?delete=\": context canceled"1962--- PASS: TestGCEndsOnShutdown (0.02s)1963 --- PASS: TestGCEndsOnShutdown/before_the_run (0.82s)1964 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.95s)1965 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.91s)19662026/11/06 07:12:35 INFO Received uploads request method=POST path=/api/pending_closures19672026/11/06 07:12:35 INFO Received uploads request method=POST path=/api/pending_closures19682026/11/06 07:12:35 INFO Received uploads request method=POST path=/api/pending_closures19692026/11/06 07:12:35 INFO Received uploads request method=POST path=/api/pending_closures19702026/11/06 07:12:35 INFO Aborted multipart uploads count=0 kept=01971--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)1972 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (1.35s)1973 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (1.13s)19742026/11/06 07:12:35 INFO Received push request method=POST path=/api/pushes19752026/11/06 07:12:35 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19762026/11/06 07:12:35 INFO Uploading a11dhfin5iy6il90v89qyki1x53imiin-unpinned-file.txt (128B)19772026/11/06 07:12:35 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"19782026/11/06 07:12:35 WARN Failed to register uploaded object key=a11dhfin5iy6il90v89qyki1x53imiin.ls error="server returned 404: 404 page not found\n"19792026/11/06 07:12:35 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign19802026/11/06 07:12:35 INFO Signed narinfos id=2 count=119812026/11/06 07:12:35 INFO Uploading 1 narinfos19822026/11/06 07:12:35 INFO Received complete push request method=POST path=/api/pushes/2/complete19832026/11/06 07:12:35 WARN Failed to register uploaded object key=a11dhfin5iy6il90v89qyki1x53imiin.narinfo error="server returned 404: 404 page not found\n"19842026/11/06 07:12:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19852026/11/06 07:12:35 INFO Completed push id=2 objects=3 duration=76.320494ms19862026/11/06 07:12:35 INFO Upload complete. (405ms)19872026/11/06 07:12:35 WARN Force mode enabled - objects will be deleted immediately without grace period19882026/11/06 07:12:35 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst upload_id=NjNkMDE4ZTQtZjMwYS00ZTdmLTlhMjItYWQzNDY5ZmM3ODBhLjhhOThkYzM1LWYzYzItNGIyNS04YzNkLTI1OTMwOTZmODRmZngxNzkzOTQ5MTU0OTkyMTU3NDcx parts=101989--- PASS: TestConnectWaitsForAPeerMigration (5.29s)19902026/11/06 07:12:35 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/present19912026/11/06 07:12:35 WARN Force mode enabled - objects will be deleted immediately without grace period19922026/11/06 07:12:35 INFO Received push request method=POST path=/api/pushes19932026/11/06 07:12:35 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19942026/11/06 07:12:35 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=019952026/11/06 07:12:35 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)19962026/11/06 07:12:35 INFO Uploading 48ywfz30dpw92rjshva7c5q6gidybywc-test-file-0.txt (160B)19972026/11/06 07:12:35 INFO Uploading x57q2fc822hmw1c5lz4m9kj7s1ri8wn8-test-file-2.txt (160B)19982026/11/06 07:12:35 INFO Completed upload id=1 objects=3 duration=4.810924ms19992026/11/06 07:12:35 INFO Uploading dsa8s35rrarh3y67zb4fg5yj8ai0sq66-test-file-1.txt (160B)20002026/11/06 07:12:35 INFO Vacuumed table table=pending_closures20012026/11/06 07:12:35 INFO Vacuumed table table=pending_objects20022026/11/06 07:12:35 WARN Failed to register uploaded object key=48ywfz30dpw92rjshva7c5q6gidybywc.ls error="server returned 404: 404 page not found\n"20032026/11/06 07:12:35 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"20042026/11/06 07:12:35 WARN Failed to register uploaded object key=dsa8s35rrarh3y67zb4fg5yj8ai0sq66.ls error="server returned 404: 404 page not found\n"20052026/11/06 07:12:35 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"20062026/11/06 07:12:35 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"20072026/11/06 07:12:35 INFO Vacuumed table table=multipart_uploads20082026/11/06 07:12:35 INFO Vacuumed table table=closures20092026/11/06 07:12:35 INFO Vacuumed table table=objects20102026/11/06 07:12:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20112026/11/06 07:12:35 INFO Starting cleanup of old closures method=DELETE path=/api/closures20122026/11/06 07:12:35 INFO Signed narinfos id=1 count=320132026/11/06 07:12:35 WARN Failed to register uploaded object key=x57q2fc822hmw1c5lz4m9kj7s1ri8wn8.ls error="server returned 404: 404 page not found\n"20142026/11/06 07:12:35 INFO Uploading 3 narinfos20152026/11/06 07:12:35 INFO Garbage collection started2016--- PASS: TestPendingClosureWriteTimeout (0.13s)2017 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2018 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2019 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2020 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.29s)20212026/11/06 07:12:35 WARN Failed to register uploaded object key=x57q2fc822hmw1c5lz4m9kj7s1ri8wn8.narinfo error="server returned 404: 404 page not found\n"20222026/11/06 07:12:35 INFO Aborted multipart uploads count=0 kept=02023--- PASS: TestUploadHandlersRejectOversizedBody (2.39s)2024 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)2025 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)2026 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.26s)20272026/11/06 07:12:35 INFO Received complete push request method=POST path=/api/pushes/1/complete20282026/11/06 07:12:35 WARN Failed to register uploaded object key=48ywfz30dpw92rjshva7c5q6gidybywc.narinfo error="server returned 404: 404 page not found\n"20292026/11/06 07:12:35 WARN Failed to register uploaded object key=dsa8s35rrarh3y67zb4fg5yj8ai0sq66.narinfo error="server returned 404: 404 page not found\n"20302026/11/06 07:12:35 INFO Completed push id=1 objects=9 duration=10.802399ms20312026/11/06 07:12:35 INFO Upload complete. (667ms)2032=== NAME TestClientMultipleUploads2033 client_integration_test.go:416: Uploaded 3 paths in 1.504425683s20342026/11/06 07:12:35 INFO Received uploads request method=POST path=/api/pending_closures20352026/11/06 07:12:35 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=020362026/11/06 07:12:35 INFO Vacuumed table table=pending_closures20372026/11/06 07:12:35 INFO Vacuumed table table=pending_objects20382026/11/06 07:12:35 INFO Vacuumed table table=multipart_uploads20392026/11/06 07:12:35 INFO Vacuumed table table=closures20402026/11/06 07:12:35 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst20412026/11/06 07:12:35 WARN Found objects in DB but missing from S3, will re-upload count=120422026/11/06 07:12:35 INFO Vacuumed table table=objects20432026/11/06 07:12:35 WARN Request failed, retrying attempt=2 backoff=212.91211ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2044--- PASS: TestClientMultipleUploads (4.24s)20452026/11/06 07:12:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20462026/11/06 07:12:35 WARN Force mode enabled - objects will be deleted immediately without grace period20472026/11/06 07:12:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2048--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2049 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (1.39s)2050 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (1.47s)20512026/11/06 07:12:35 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000200000000000000000000.nar.zst upload_id=NjNkMDE4ZTQtZjMwYS00ZTdmLTlhMjItYWQzNDY5ZmM3ODBhLmEwM2E3Nzc3LTQ1NzYtNDFmNC05MmQ1LTY0MjBjYWFjODc1ZngxNzkzOTQ5MTU1MTk2MjIzMTY3 parts=1020522026/11/06 07:12:35 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20532026/11/06 07:12:35 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst upload_id=NjNkMDE4ZTQtZjMwYS00ZTdmLTlhMjItYWQzNDY5ZmM3ODBhLmEzNjFhZDc3LTQ1MzAtNGNhZC05N2FjLTY2ZWU3NjAwYzIwN3gxNzkzOTQ5MTU1MTQ4OTU0MjU3 parts=1020542026/11/06 07:12:35 INFO Completed upload id=1 objects=3 duration=3.783494ms20552026/11/06 07:12:35 INFO Received uploads request method=POST path=/api/pending_closures20562026/11/06 07:12:35 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20572026/11/06 07:12:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20582026/11/06 07:12:35 INFO Completed upload id=1 objects=3 duration=4.45698ms20592026/11/06 07:12:35 INFO Received uploads request method=POST path=/api/pending_closures20602026/11/06 07:12:35 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=020612026/11/06 07:12:35 INFO Vacuumed table table=pending_closures20622026/11/06 07:12:35 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst upload_id=NjNkMDE4ZTQtZjMwYS00ZTdmLTlhMjItYWQzNDY5ZmM3ODBhLjhiYzQ0NDdkLTczODEtNGZjOC05ODA1LTkxNjFmOGM2MDJhMngxNzkzOTQ5MTU1MTIzMDQ4OTIx parts=1020632026/11/06 07:12:35 INFO Vacuumed table table=pending_objects20642026/11/06 07:12:35 INFO Vacuumed table table=multipart_uploads20652026/11/06 07:12:35 INFO Vacuumed table table=closures20662026/11/06 07:12:35 INFO Vacuumed table table=objects20672026/11/06 07:12:35 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20682026/11/06 07:12:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20692026/11/06 07:12:35 INFO Completed upload id=1 objects=3 duration=6.522059ms20702026/11/06 07:12:35 INFO Received uploads request method=POST path=/api/pending_closures20712026/11/06 07:12:35 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst upload_id=NjNkMDE4ZTQtZjMwYS00ZTdmLTlhMjItYWQzNDY5ZmM3ODBhLjYwN2RlMTQwLWJlOTEtNGI0Ni1iNzViLTU0NzBhYjAwMzMwYngxNzkzOTQ5MTU1MDgyNTUzMDMz parts=1020722026/11/06 07:12:35 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20732026/11/06 07:12:35 INFO Completed upload id=1 objects=3 duration=3.974716ms20742026/11/06 07:12:35 INFO Received uploads request method=POST path=/api/pending_closures20752026/11/06 07:12:35 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst20762026/11/06 07:12:35 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0001.narinfo20772026/11/06 07:12:35 WARN Request failed, retrying attempt=3 backoff=430.107323ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20782026/11/06 07:12:36 INFO Received push request method=POST path=/api/pushes20792026/11/06 07:12:36 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20802026/11/06 07:12:36 INFO Received push request method=POST path=/api/pushes20812026/11/06 07:12:36 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20822026/11/06 07:12:36 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20832026/11/06 07:12:36 INFO Uploading 5v3gwbksl1alikk5j6fjm0r0f1m789d7-test-file.txt (152B)20842026/11/06 07:12:36 INFO Uploading 6n9l3q3zg3hpqrsi9bn2r7nkdgykhycy-test-script (136B)20852026/11/06 07:12:36 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20862026/11/06 07:12:36 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"20872026/11/06 07:12:36 WARN Failed to register uploaded object key=log/866h8wx2fack2sj809y5rsf0q9vfixvm-test-script.drv error="server returned 404: 404 page not found\n"20882026/11/06 07:12:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20892026/11/06 07:12:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20902026/11/06 07:12:36 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"20912026/11/06 07:12:36 WARN Failed to register uploaded object key=6n9l3q3zg3hpqrsi9bn2r7nkdgykhycy.ls error="server returned 404: 404 page not found\n"20922026/11/06 07:12:36 INFO Signed narinfos id=1 count=120932026/11/06 07:12:36 INFO Signed narinfos id=1 count=120942026/11/06 07:12:36 INFO Uploading 1 narinfos20952026/11/06 07:12:36 INFO Uploading 1 narinfos20962026/11/06 07:12:36 WARN Failed to register uploaded object key=5v3gwbksl1alikk5j6fjm0r0f1m789d7.ls error="server returned 404: 404 page not found\n"20972026/11/06 07:12:36 INFO Received complete push request method=POST path=/api/pushes/1/complete20982026/11/06 07:12:36 INFO Received complete push request method=POST path=/api/pushes/1/complete20992026/11/06 07:12:36 WARN Failed to register uploaded object key=6n9l3q3zg3hpqrsi9bn2r7nkdgykhycy.narinfo error="server returned 404: 404 page not found\n"21002026/11/06 07:12:36 WARN Failed to register uploaded object key=5v3gwbksl1alikk5j6fjm0r0f1m789d7.narinfo error="server returned 404: 404 page not found\n"21012026/11/06 07:12:36 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100300000000000000000000.nar.zst upload_id=NjNkMDE4ZTQtZjMwYS00ZTdmLTlhMjItYWQzNDY5ZmM3ODBhLjdhYTQ1MTJlLWRmNWUtNGZlNi1hOGI2LWMxYThkMDViOGNjMHgxNzkzOTQ5MTU1ODMxOTE2MTg5 parts=1021022026/11/06 07:12:36 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21032026/11/06 07:12:36 INFO Completed upload id=2 objects=3 duration=1.319952ms21042026/11/06 07:12:36 INFO Completed push id=1 objects=3 duration=12.841756ms21052026/11/06 07:12:36 INFO Upload complete. (486ms)21062026/11/06 07:12:36 INFO Completed push id=1 objects=4 duration=13.048779ms21072026/11/06 07:12:36 INFO Upload complete. (561ms)21082026/11/06 07:12:36 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2109=== NAME TestClientWithDependencies2110 client_integration_test.go:664: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3686571451/001/store) requires matching store prefix2111--- PASS: TestClientWithDependencies (5.54s)21122026/11/06 07:12:36 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100400000000000000000000.nar.zst upload_id=NjNkMDE4ZTQtZjMwYS00ZTdmLTlhMjItYWQzNDY5ZmM3ODBhLjI2NWZlYzM2LTczYWQtNDBjNS1iNzM4LWZiYjYyNTNiMjMyZXgxNzkzOTQ5MTU1ODY2MTc3MjQw parts=1021132026/11/06 07:12:36 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21142026/11/06 07:12:36 INFO Completed upload id=2 objects=3 duration=1.16115ms21152026/11/06 07:12:36 INFO Received uploads request method=POST path=/api/pending_closures21162026/11/06 07:12:36 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst21172026/11/06 07:12:36 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0003.narinfo21182026/11/06 07:12:36 INFO Received uploads request method=POST path=/api/pending_closures21192026/11/06 07:12:36 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst21202026/11/06 07:12:36 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0004.narinfo2121--- PASS: TestService_verifyS3ReuploadsStaleNarinfo (0.00s)2122 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed (1.16s)2123 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed (0.98s)2124 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed (1.35s)2125 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost (1.45s)2126 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed (1.67s)21272026/11/06 07:12:36 INFO Received push request method=POST path=/api/pushes21282026/11/06 07:12:36 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)21292026/11/06 07:12:36 INFO Uploading 8rl235wizvqy71zwnfk6c2ka9kqj7h7c-shared-dep (136B)21302026/11/06 07:12:36 INFO Uploading 1ri1qxsbs5g58fh71l6lnv2vhv4212xj-a (216B)21312026/11/06 07:12:36 WARN Failed to register uploaded object key=8rl235wizvqy71zwnfk6c2ka9kqj7h7c.ls error="server returned 404: 404 page not found\n"21322026/11/06 07:12:36 WARN Failed to register uploaded object key=nar/07951qlxv2l9z13nh6ix60caj77m4420xg87m3ll6bhadqc4dism.nar.zst error="server returned 404: 404 page not found\n"21332026/11/06 07:12:36 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"21342026/11/06 07:12:36 WARN Failed to register uploaded object key=18z2758ykg2cbwigsya2v9g1qyriy76r.ls error="server returned 404: 404 page not found\n"21352026/11/06 07:12:36 WARN Failed to register uploaded object key=1ri1qxsbs5g58fh71l6lnv2vhv4212xj.ls error="server returned 404: 404 page not found\n"21362026/11/06 07:12:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign21372026/11/06 07:12:36 INFO Signed narinfos id=1 count=321382026/11/06 07:12:36 INFO Uploading 3 narinfos21392026/11/06 07:12:36 WARN Failed to register uploaded object key=8rl235wizvqy71zwnfk6c2ka9kqj7h7c.narinfo error="server returned 404: 404 page not found\n"21402026/11/06 07:12:36 WARN Failed to register uploaded object key=18z2758ykg2cbwigsya2v9g1qyriy76r.narinfo error="server returned 404: 404 page not found\n"21412026/11/06 07:12:36 INFO Received complete push request method=POST path=/api/pushes/1/complete21422026/11/06 07:12:36 WARN Failed to register uploaded object key=1ri1qxsbs5g58fh71l6lnv2vhv4212xj.narinfo error="server returned 404: 404 page not found\n"21432026/11/06 07:12:36 INFO All 1 paths already cached2144=== NAME TestClientIntegration2145 client_integration_test.go:317: Retrieved narinfo from S3:2146 StorePath: /build/TestClientIntegration2450271632/002/store/5v3gwbksl1alikk5j6fjm0r0f1m789d7-test-file.txt2147 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2148 Compression: zstd2149 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12150 NarSize: 1522151 References: 2152 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk121532026/11/06 07:12:36 INFO Completed push id=1 objects=8 duration=9.92635ms21542026/11/06 07:12:36 INFO Upload complete. (227ms)2155=== NAME TestClientPushesUseOnePush2156 client_pushes_test.go:97: Retrieved narinfo from S3:2157 StorePath: /build/TestClientPushesUseOnePush1995077242/001/store/8rl235wizvqy71zwnfk6c2ka9kqj7h7c-shared-dep2158 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2159 Compression: zstd2160 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822161 NarSize: 1362162 References: 2163 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2164=== NAME TestClientIntegration2165 client_integration_test.go:318: Retrieved .ls file from S3 (compressed size: 77 bytes)2166 client_integration_test.go:318: Decompressed .ls content (64 bytes):2167 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2168=== NAME TestClientPushesUseOnePush2169 client_pushes_test.go:97: Retrieved narinfo from S3:2170 StorePath: /build/TestClientPushesUseOnePush1995077242/001/store/1ri1qxsbs5g58fh71l6lnv2vhv4212xj-a2171 URL: nar/07951qlxv2l9z13nh6ix60caj77m4420xg87m3ll6bhadqc4dism.nar.zst2172 Compression: zstd2173 NarHash: sha256:07951qlxv2l9z13nh6ix60caj77m4420xg87m3ll6bhadqc4dism2174 NarSize: 2162175 References: /build/TestClientPushesUseOnePush1995077242/001/store/8rl235wizvqy71zwnfk6c2ka9kqj7h7c-shared-dep2176 CA: text:sha256:0xlrzw166qqdx9p2h157c6kzy18dzkk76x5alhw0li02hzpxbxfi21772026/11/06 07:12:36 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2178 client_pushes_test.go:97: Retrieved narinfo from S3:2179 StorePath: /build/TestClientPushesUseOnePush1995077242/001/store/18z2758ykg2cbwigsya2v9g1qyriy76r-b2180 URL: nar/07951qlxv2l9z13nh6ix60caj77m4420xg87m3ll6bhadqc4dism.nar.zst2181 Compression: zstd2182 NarHash: sha256:07951qlxv2l9z13nh6ix60caj77m4420xg87m3ll6bhadqc4dism2183 NarSize: 2162184 References: /build/TestClientPushesUseOnePush1995077242/001/store/8rl235wizvqy71zwnfk6c2ka9kqj7h7c-shared-dep2185 CA: text:sha256:0xlrzw166qqdx9p2h157c6kzy18dzkk76x5alhw0li02hzpxbxfi2186--- PASS: TestClientPushesUseOnePush (5.64s)21872026/11/06 07:12:36 WARN Request failed, retrying attempt=4 backoff=725.098733ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2188--- PASS: TestDeleteClosuresRacingPins (5.84s)21892026/11/06 07:12:37 WARN Request failed, retrying attempt=5 backoff=1.564396812s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21902026/11/06 07:12:37 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=021912026/11/06 07:12:37 INFO Received create pin request method=POST path=/api/pins/myapp21922026/11/06 07:12:37 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1195557787/001/store/albv928qdvbqn5fx0i7fjswhddkzmwpf-pinned-file.txt narinfo_key=albv928qdvbqn5fx0i7fjswhddkzmwpf.narinfo21932026/11/06 07:12:37 INFO Starting cleanup of old closures method=DELETE path=/api/closures21942026/11/06 07:12:37 INFO Garbage collection started21952026/11/06 07:12:37 INFO Aborted multipart uploads count=0 kept=021962026/11/06 07:12:38 WARN Force mode enabled - objects will be deleted immediately without grace period21972026/11/06 07:12:38 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=021982026/11/06 07:12:38 INFO Vacuumed table table=pending_closures21992026/11/06 07:12:38 INFO Vacuumed table table=pending_objects22002026/11/06 07:12:38 INFO Vacuumed table table=multipart_uploads22012026/11/06 07:12:38 INFO Vacuumed table table=closures22022026/11/06 07:12:38 INFO Vacuumed table table=objects22032026/11/06 07:12:38 INFO Received push request method=POST path=/api/pushes22042026/11/06 07:12:38 INFO Object in database but missing from S3 key=5v3gwbksl1alikk5j6fjm0r0f1m789d7.ls22052026/11/06 07:12:38 WARN Found objects in DB but missing from S3, will re-upload count=122062026/11/06 07:12:38 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)22072026/11/06 07:12:38 INFO Received complete push request method=POST path=/api/pushes/2/complete22082026/11/06 07:12:38 WARN Failed to register uploaded object key=5v3gwbksl1alikk5j6fjm0r0f1m789d7.ls error="server returned 404: 404 page not found\n"22092026/11/06 07:12:38 INFO Completed push id=2 objects=3 duration=3.211669ms22102026/11/06 07:12:38 INFO Upload complete. (1.909s)2211=== NAME TestClientIntegration2212 client_integration_test.go:335: Retrieved .ls file from S3 (compressed size: 62 bytes)2213 client_integration_test.go:335: Decompressed .ls content (49 bytes):2214 {"version":1,"root":{"type":"regular","size":39}}2215=== NAME TestClientCADerivations2216 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2217 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2218 error: binary cache 's3://bucket81?endpoint=http://localhost:33487®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations4033948984/001/store'2219 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12220--- PASS: TestClientCADerivations (6.36s)22212026/11/06 07:12:39 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-config22222026/11/06 07:12:39 INFO Received push request method=POST path=/api/pushes22232026/11/06 07:12:39 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)22242026/11/06 07:12:39 INFO Received complete push request method=POST path=/api/pushes/3/complete22252026/11/06 07:12:39 WARN Failed to register uploaded object key=5v3gwbksl1alikk5j6fjm0r0f1m789d7.ls error="server returned 404: 404 page not found\n"22262026/11/06 07:12:39 INFO Completed push id=3 objects=3 duration=2.436103ms22272026/11/06 07:12:39 INFO Upload complete. (141ms)2228=== NAME TestClientIntegration2229 client_integration_test.go:352: Retrieved .ls file from S3 (compressed size: 62 bytes)2230 client_integration_test.go:352: Decompressed .ls content (49 bytes):2231 {"version":1,"root":{"type":"regular","size":39}}2232 client_integration_test.go:363: Testing garbage collection...22332026/11/06 07:12:39 WARN Request failed, retrying attempt=2 backoff=200.941714ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22342026/11/06 07:12:39 INFO Starting cleanup of old closures method=DELETE path=/api/closures22352026/11/06 07:12:39 INFO Garbage collection started22362026/11/06 07:12:39 INFO Aborted multipart uploads count=0 kept=022372026/11/06 07:12:39 WARN Force mode enabled - objects will be deleted immediately without grace period22382026/11/06 07:12:39 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=022392026/11/06 07:12:39 INFO Vacuumed table table=pending_closures22402026/11/06 07:12:39 INFO Vacuumed table table=pending_objects22412026/11/06 07:12:39 INFO Vacuumed table table=multipart_uploads22422026/11/06 07:12:39 INFO Vacuumed table table=closures22432026/11/06 07:12:39 INFO Vacuumed table table=objects22442026/11/06 07:12:39 WARN Request failed, retrying attempt=3 backoff=360.508011ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22452026/11/06 07:12:39 WARN Request failed, retrying attempt=4 backoff=852.5193ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2246=== NAME TestPinProtectsFromGC2247 client_integration_test.go:887: Pin successfully protected closure from garbage collection2248--- PASS: TestPinProtectsFromGC (10.76s)22492026/11/06 07:12:40 WARN Request failed, retrying attempt=5 backoff=1.737750639s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22502026/11/06 07:12:41 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02251=== NAME TestClientIntegration2252 client_integration_test.go:370: Objects in database after GC:2253 client_integration_test.go:370: Successfully deleted all objects with GC --force2254--- PASS: TestClientIntegration (7.94s)22552026/11/06 07:12:42 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"22562026/11/06 07:12:42 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-config22572026/11/06 07:12:42 WARN Request failed, retrying attempt=2 backoff=195.28748ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22582026/11/06 07:12:42 WARN Request failed, retrying attempt=3 backoff=412.779466ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22592026/11/06 07:12:43 WARN Request failed, retrying attempt=4 backoff=831.116627ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22602026/11/06 07:12:43 WARN Request failed, retrying attempt=5 backoff=1.653358739s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22612026/11/06 07:12:45 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_closures22622026/11/06 07:12:45 WARN Request failed, retrying attempt=2 backoff=208.608801ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22632026/11/06 07:12:45 WARN Request failed, retrying attempt=3 backoff=372.854149ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22642026/11/06 07:12:46 WARN Request failed, retrying attempt=4 backoff=823.071133ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22652026/11/06 07:12:47 WARN Request failed, retrying attempt=5 backoff=1.501231333s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2266--- PASS: TestClientErrorHandling (0.00s)2267 --- PASS: TestClientErrorHandling/InvalidStorePath (1.30s)2268 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.54s)2269 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.65s)2270PASS2271{"timestamp":"2026-11-06T07:12:48.599544444Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:44360","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(201)"}22722026-11-06 07:12:49.103 UTC [128] LOG: received smart shutdown request22732026-11-06 07:12:49.118 UTC [128] LOG: background worker "logical replication launcher" (PID 146) exited with exit code 122742026-11-06 07:12:49.129 UTC [141] LOG: shutting down22752026-11-06 07:12:49.130 UTC [141] LOG: checkpoint starting: shutdown immediate22762026-11-06 07:12:50.481 UTC [141] LOG: checkpoint complete: wrote 10792 buffers (65.9%), wrote 6 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.368 s, sync=0.927 s, total=1.353 s; sync files=35726, longest=0.005 s, average=0.001 s; distance=517310 kB, estimate=517310 kB; lsn=0/21095728, redo lsn=0/2109572822772026-11-06 07:12:50.636 UTC [128] LOG: database system is shut down2278Running OIDC tests...2279=== RUN TestAudienceForIssuer2280=== PAUSE TestAudienceForIssuer2281=== RUN TestGlobMatch2282=== PAUSE TestGlobMatch2283=== RUN TestValidateToken_ValidToken2284=== PAUSE TestValidateToken_ValidToken2285=== RUN TestValidateToken_WrongAudience2286=== PAUSE TestValidateToken_WrongAudience2287=== RUN TestValidateToken_Expired2288=== PAUSE TestValidateToken_Expired2289=== RUN TestValidateToken_BoundClaimsMismatch2290=== PAUSE TestValidateToken_BoundClaimsMismatch2291=== RUN TestValidateToken_BoundSubjectMismatch2292=== PAUSE TestValidateToken_BoundSubjectMismatch2293=== RUN TestValidateToken_MultipleProviders2294=== PAUSE TestValidateToken_MultipleProviders2295=== RUN TestValidateToken_NoMatchingProvider2296=== PAUSE TestValidateToken_NoMatchingProvider2297=== RUN TestValidateToken_KubernetesServiceAccount2298=== PAUSE TestValidateToken_KubernetesServiceAccount2299=== RUN TestNewValidator_KubernetesRequiresCA2300=== PAUSE TestNewValidator_KubernetesRequiresCA2301=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2302=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2303=== RUN TestPins_ReservedForMatchingRule2304=== PAUSE TestPins_ReservedForMatchingRule2305=== RUN TestPins_TopLevelShorthand2306=== PAUSE TestPins_TopLevelShorthand2307=== RUN TestPins_ConfigValidation2308=== PAUSE TestPins_ConfigValidation2309=== RUN TestScopes_LegacyProviderDefaultsToWrite2310=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2311=== RUN TestScopes_Rules2312=== PAUSE TestScopes_Rules2313=== RUN TestScopes_ConfigValidation2314=== PAUSE TestScopes_ConfigValidation2315=== CONT TestAudienceForIssuer2316=== CONT TestValidateToken_KubernetesServiceAccount2317=== CONT TestPins_ConfigValidation2318--- PASS: TestAudienceForIssuer (0.00s)2319=== CONT TestValidateToken_NoMatchingProvider2320--- PASS: TestPins_ConfigValidation (0.00s)2321=== CONT TestScopes_ConfigValidation2322--- PASS: TestScopes_ConfigValidation (0.00s)2323=== CONT TestScopes_Rules2324=== CONT TestValidateToken_MultipleProviders2325=== CONT TestScopes_LegacyProviderDefaultsToWrite2326=== CONT TestPins_TopLevelShorthand2327=== CONT TestPins_ReservedForMatchingRule2328=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2329=== CONT TestNewValidator_KubernetesRequiresCA2330=== CONT TestValidateToken_BoundSubjectMismatch23312026/11/06 07:12:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42347/oidc2332=== CONT TestValidateToken_Expired2333=== CONT TestValidateToken_ValidToken2334=== CONT TestValidateToken_WrongAudience2335=== CONT TestGlobMatch2336=== RUN TestGlobMatch/foo_foo2337=== PAUSE TestGlobMatch/foo_foo2338=== RUN TestGlobMatch/foo_bar2339=== PAUSE TestGlobMatch/foo_bar2340=== RUN TestGlobMatch/*_2341=== PAUSE TestGlobMatch/*_2342=== RUN TestGlobMatch/*_anything2343=== PAUSE TestGlobMatch/*_anything2344=== RUN TestGlobMatch/foo*_foo2345=== PAUSE TestGlobMatch/foo*_foo2346=== RUN TestGlobMatch/foo*_foobar2347=== PAUSE TestGlobMatch/foo*_foobar2348=== RUN TestGlobMatch/foo*_bar2349=== PAUSE TestGlobMatch/foo*_bar2350=== RUN TestGlobMatch/*bar_bar2351=== PAUSE TestGlobMatch/*bar_bar2352=== RUN TestGlobMatch/*bar_foobar2353=== PAUSE TestGlobMatch/*bar_foobar2354=== RUN TestGlobMatch/*bar_foo2355=== PAUSE TestGlobMatch/*bar_foo2356=== RUN TestGlobMatch/foo*bar_foobar2357=== PAUSE TestGlobMatch/foo*bar_foobar2358=== RUN TestGlobMatch/foo*bar_foo123bar2359=== PAUSE TestGlobMatch/foo*bar_foo123bar23602026/11/06 07:12:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37777/oidc2361=== RUN TestGlobMatch/foo*bar_foobarbaz2362=== PAUSE TestGlobMatch/foo*bar_foobarbaz2363=== RUN TestGlobMatch/*/*_foo/bar2364=== PAUSE TestGlobMatch/*/*_foo/bar2365=== RUN TestGlobMatch/*/*_foo2366=== PAUSE TestGlobMatch/*/*_foo2367=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2368=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2369=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02370=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02371=== RUN TestGlobMatch/refs/*/main_refs/heads/main2372=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2373=== RUN TestGlobMatch/fo?_foo2374=== PAUSE TestGlobMatch/fo?_foo2375=== RUN TestGlobMatch/fo?_fo2376=== PAUSE TestGlobMatch/fo?_fo2377=== RUN TestGlobMatch/fo?_fooo2378=== PAUSE TestGlobMatch/fo?_fooo2379=== RUN TestGlobMatch/?oo_foo2380=== PAUSE TestGlobMatch/?oo_foo2381=== RUN TestGlobMatch/?oo_boo2382=== PAUSE TestGlobMatch/?oo_boo2383=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2384=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2385=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2386=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2387=== CONT TestGlobMatch/foo_foo2388=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2389=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2390=== CONT TestGlobMatch/?oo_boo2391=== CONT TestGlobMatch/?oo_foo2392=== CONT TestGlobMatch/fo?_fooo2393=== CONT TestGlobMatch/fo?_fo2394=== CONT TestGlobMatch/fo?_foo2395=== CONT TestGlobMatch/refs/*/main_refs/heads/main2396=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02397=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2398=== CONT TestGlobMatch/*/*_foo2399=== CONT TestGlobMatch/*/*_foo/bar2400=== CONT TestGlobMatch/foo*bar_foobarbaz2401=== CONT TestGlobMatch/foo*bar_foo123bar2402=== CONT TestGlobMatch/foo*bar_foobar2403=== CONT TestGlobMatch/*bar_foo2404=== CONT TestGlobMatch/*bar_foobar2405=== CONT TestGlobMatch/*bar_bar2406=== CONT TestGlobMatch/foo*_bar2407=== CONT TestGlobMatch/foo*_foobar2408=== CONT TestGlobMatch/foo*_foo2409=== CONT TestGlobMatch/*_anything2410=== CONT TestGlobMatch/*_2411=== CONT TestGlobMatch/foo_bar2412--- PASS: TestGlobMatch (0.00s)2413 --- PASS: TestGlobMatch/foo_foo (0.00s)2414 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2415 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2416 --- PASS: TestGlobMatch/?oo_boo (0.00s)2417 --- PASS: TestGlobMatch/?oo_foo (0.00s)2418 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2419 --- PASS: TestGlobMatch/fo?_fo (0.00s)2420 --- PASS: TestGlobMatch/fo?_foo (0.00s)2421 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2422 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2423 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2424 --- PASS: TestGlobMatch/*/*_foo (0.00s)2425 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2426 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2427 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2428 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2429 --- PASS: TestGlobMatch/*bar_foo (0.00s)2430 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2431 --- PASS: TestGlobMatch/*bar_bar (0.00s)2432 --- PASS: TestGlobMatch/foo*_bar (0.00s)2433 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2434 --- PASS: TestGlobMatch/foo*_foo (0.00s)2435 --- PASS: TestGlobMatch/*_anything (0.00s)2436 --- PASS: TestGlobMatch/*_ (0.00s)2437 --- PASS: TestGlobMatch/foo_bar (0.00s)2438--- PASS: TestPins_TopLevelShorthand (0.20s)2439=== CONT TestValidateToken_BoundClaimsMismatch24402026/11/06 07:12:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33947/oidc2441--- PASS: TestPins_ReservedForMatchingRule (0.25s)2442--- PASS: TestScopes_Rules (0.29s)24432026/11/06 07:12:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37461/oidc2444--- PASS: TestValidateToken_Expired (0.08s)24452026/11/06 07:12:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40023/oidc2446--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.31s)24472026/11/06 07:12:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44115/oidc24482026/11/06 07:12:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45471/oidc2449--- PASS: TestValidateToken_BoundClaimsMismatch (0.10s)2450--- PASS: TestValidateToken_BoundSubjectMismatch (0.13s)24512026/11/06 07:12:53 http: TLS handshake error from 127.0.0.1:55690: remote error: tls: bad certificate2452--- PASS: TestNewValidator_KubernetesRequiresCA (0.28s)24532026/11/06 07:12:53 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:426232454--- PASS: TestValidateToken_KubernetesServiceAccount (0.42s)24552026/11/06 07:12:53 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:41127/oidc2456--- PASS: TestValidateToken_NoMatchingProvider (0.42s)24572026/11/06 07:12:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45789/oidc2458--- PASS: TestValidateToken_ValidToken (0.21s)24592026/11/06 07:12:53 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232460--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.39s)24612026/11/06 07:12:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46265/oidc2462--- PASS: TestValidateToken_WrongAudience (0.27s)24632026/11/06 07:12:54 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:43919/oidc24642026/11/06 07:12:54 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:41323/oidc2465--- PASS: TestValidateToken_MultipleProviders (0.50s)2466PASS2467Running hook tests...2468=== RUN TestSendPathsEmpty2469=== PAUSE TestSendPathsEmpty2470=== RUN TestQueueEnqueueAndFetch2471=== PAUSE TestQueueEnqueueAndFetch2472=== RUN TestQueueDeduplication2473=== PAUSE TestQueueDeduplication2474=== RUN TestQueueRemove2475=== PAUSE TestQueueRemove2476=== RUN TestQueueFetchBatchLimit2477=== PAUSE TestQueueFetchBatchLimit2478=== RUN TestQueueRetryMovesToBack2479=== PAUSE TestQueueRetryMovesToBack2480=== RUN TestQueueFetchRemoveLifecycle2481=== PAUSE TestQueueFetchRemoveLifecycle2482=== RUN TestQueueConcurrentWriters2483=== PAUSE TestQueueConcurrentWriters2484=== RUN TestQueueRemoveLargeClosure2485=== PAUSE TestQueueRemoveLargeClosure2486=== RUN TestServerClientIntegration2487--- PASS: TestServerClientIntegration (0.00s)2488=== RUN TestServerQueueError24892026/11/06 07:12:54 ERROR Failed to queue paths error="permission denied" count=12490--- PASS: TestServerQueueError (0.00s)2491=== RUN TestGetListenerSocketActivation2492 server_test.go:218: === RUN TestGetListenerSocketActivation2493 --- PASS: TestGetListenerSocketActivation (0.00s)2494 PASS2495 2496--- PASS: TestGetListenerSocketActivation (0.08s)2497=== RUN TestServerStalledClientDoesNotBlockShutdown2498=== PAUSE TestServerStalledClientDoesNotBlockShutdown2499=== RUN TestServerBacksOffOnAcceptErrors2500=== PAUSE TestServerBacksOffOnAcceptErrors2501=== RUN TestDrainIsolatesPoisonPath2502=== PAUSE TestDrainIsolatesPoisonPath2503=== RUN TestRunNotBlockedByPoisonHead2504=== PAUSE TestRunNotBlockedByPoisonHead2505=== RUN TestDrainGivesUpWhenServerDown2506=== PAUSE TestDrainGivesUpWhenServerDown2507=== RUN TestFailedPathPrunedByLaterClosure2508=== PAUSE TestFailedPathPrunedByLaterClosure2509=== RUN TestWorkerUploadsAndRemoves2510=== PAUSE TestWorkerUploadsAndRemoves2511=== RUN TestWorkerSkipsGCdPaths2512=== PAUSE TestWorkerSkipsGCdPaths2513=== RUN TestWorkerPrunesClosureDeps2514=== PAUSE TestWorkerPrunesClosureDeps2515=== RUN TestDrainTimeout2516=== PAUSE TestDrainTimeout2517=== RUN TestWorkerRemoveFailureIsNotProgress2518=== PAUSE TestWorkerRemoveFailureIsNotProgress2519=== RUN TestWorkerKeepsPathItCannotStat2520=== PAUSE TestWorkerKeepsPathItCannotStat2521=== CONT TestSendPathsEmpty2522--- PASS: TestSendPathsEmpty (0.00s)2523=== CONT TestWorkerRemoveFailureIsNotProgress2524=== CONT TestWorkerPrunesClosureDeps2525=== CONT TestWorkerKeepsPathItCannotStat2526=== CONT TestDrainIsolatesPoisonPath2527=== CONT TestWorkerUploadsAndRemoves2528=== CONT TestWorkerSkipsGCdPaths2529=== CONT TestDrainTimeout2530=== CONT TestFailedPathPrunedByLaterClosure2531=== CONT TestDrainGivesUpWhenServerDown2532=== CONT TestRunNotBlockedByPoisonHead2533=== CONT TestQueueRetryMovesToBack2534=== CONT TestServerStalledClientDoesNotBlockShutdown2535=== CONT TestQueueRemoveLargeClosure2536=== CONT TestQueueConcurrentWriters2537=== CONT TestQueueFetchRemoveLifecycle2538=== CONT TestQueueRemove2539=== CONT TestQueueFetchBatchLimit2540=== CONT TestQueueDeduplication2541=== CONT TestQueueEnqueueAndFetch2542=== CONT TestServerBacksOffOnAcceptErrors25432026/11/06 07:12:54 ERROR Accept failed error="too many open files"25442026/11/06 07:12:54 ERROR Accept failed error="too many open files"25452026/11/06 07:12:54 INFO Uploading batch count=125462026/11/06 07:12:54 ERROR Upload failed error="upload failed" count=125472026/11/06 07:12:54 INFO Uploading batch count=125482026/11/06 07:12:54 INFO Uploading batch count=12549--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)2550--- PASS: TestQueueRetryMovesToBack (0.02s)25512026/11/06 07:12:54 ERROR Accept failed error="too many open files"2552--- PASS: TestQueueRemove (0.02s)25532026/11/06 07:12:54 INFO Uploading batch count=425542026/11/06 07:12:54 ERROR Upload failed error="upload failed" count=425552026/11/06 07:12:54 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath4017530914/002/bbb25562026/11/06 07:12:54 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3772185773/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat3772185773/002/locked/aaa: permission denied"25572026/11/06 07:12:54 INFO Uploading batch count=125582026/11/06 07:12:54 ERROR Upload failed error="upload failed" count=125592026/11/06 07:12:54 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3772185773/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat3772185773/002/locked/aaa: permission denied"25602026/11/06 07:12:54 INFO Uploading batch count=125612026/11/06 07:12:54 ERROR Upload failed error="upload failed" count=125622026/11/06 07:12:54 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3772185773/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat3772185773/002/locked/aaa: permission denied"25632026/11/06 07:12:54 ERROR Drain finished with paths left in queue remaining=12564--- PASS: TestWorkerKeepsPathItCannotStat (0.03s)25652026/11/06 07:12:54 INFO Uploading batch count=125662026/11/06 07:12:54 ERROR Upload failed error="upload failed" count=125672026/11/06 07:12:54 ERROR Drain finished with paths left in queue remaining=12568--- PASS: TestDrainIsolatesPoisonPath (0.03s)25692026/11/06 07:12:54 INFO Upload queue status pending=225702026/11/06 07:12:54 ERROR Accept failed error="too many open files"25712026/11/06 07:12:54 INFO Uploading batch count=125722026/11/06 07:12:54 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress3270598282/002/nonexistent25732026/11/06 07:12:54 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125742026/11/06 07:12:54 INFO Uploading batch count=225752026/11/06 07:12:54 ERROR Upload failed error="upload failed" count=225762026/11/06 07:12:54 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown309344274/002/a25772026/11/06 07:12:54 INFO Upload queue status pending=325782026/11/06 07:12:54 INFO Uploading batch count=125792026/11/06 07:12:54 ERROR Upload failed error="upload failed" count=125802026/11/06 07:12:54 INFO Uploading batch count=225812026/11/06 07:12:54 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress3270598282/002/nonexistent25822026/11/06 07:12:54 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125832026/11/06 07:12:54 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress3270598282/002/nonexistent25842026/11/06 07:12:54 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown309344274/002/b25852026/11/06 07:12:54 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125862026/11/06 07:12:54 INFO Uploading batch count=225872026/11/06 07:12:54 ERROR Upload failed error="upload failed" count=225882026/11/06 07:12:54 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown309344274/002/c25892026/11/06 07:12:54 ERROR Drain finished with paths left in queue remaining=125902026/11/06 07:12:54 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown309344274/002/d25912026/11/06 07:12:54 INFO Uploading batch count=225922026/11/06 07:12:54 ERROR Upload failed error="upload failed" count=225932026/11/06 07:12:54 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown309344274/002/e25942026/11/06 07:12:54 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown309344274/002/f25952026/11/06 07:12:54 ERROR Drain finished with paths left in queue remaining=102596--- PASS: TestWorkerRemoveFailureIsNotProgress (0.05s)2597--- PASS: TestDrainGivesUpWhenServerDown (0.05s)2598--- PASS: TestQueueEnqueueAndFetch (0.05s)2599--- PASS: TestQueueDeduplication (0.05s)2600--- PASS: TestWorkerPrunesClosureDeps (0.07s)26012026/11/06 07:12:54 INFO Upload queue status pending=226022026/11/06 07:12:54 INFO Uploading batch count=226032026/11/06 07:12:54 INFO Upload queue status pending=226042026/11/06 07:12:54 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths175584865/002/nonexistent26052026/11/06 07:12:54 INFO Uploading batch count=12606--- PASS: TestQueueFetchBatchLimit (0.08s)2607--- PASS: TestQueueFetchRemoveLifecycle (0.08s)26082026/11/06 07:12:54 ERROR Accept failed error="too many open files"2609--- PASS: TestWorkerUploadsAndRemoves (0.09s)2610--- PASS: TestWorkerSkipsGCdPaths (0.10s)2611--- PASS: TestQueueRemoveLargeClosure (0.16s)26122026/11/06 07:12:54 ERROR Accept failed error="too many open files"26132026/11/06 07:12:54 ERROR Failed to decode request error="read unix /build/hook979335806/test.sock->@: i/o timeout"26142026/11/06 07:12:54 ERROR Failed to write response error="write unix /build/hook979335806/test.sock->@: i/o timeout"2615--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)2616--- PASS: TestQueueConcurrentWriters (0.21s)26172026/11/06 07:12:54 ERROR Upload failed error="context deadline exceeded" count=226182026/11/06 07:12:54 ERROR Drain finished with paths left in queue remaining=42619--- PASS: TestDrainTimeout (0.27s)26202026/11/06 07:12:54 ERROR Accept failed error="too many open files"26212026/11/06 07:12:54 ERROR Accept failed error="too many open files"2622--- PASS: TestServerBacksOffOnAcceptErrors (0.65s)26232026/11/06 07:12:55 INFO Uploading batch count=126242026/11/06 07:12:55 INFO Uploading batch count=126252026/11/06 07:12:55 INFO Uploading batch count=126262026/11/06 07:12:55 ERROR Upload failed error="upload failed" count=126272026/11/06 07:12:55 INFO Uploading batch count=126282026/11/06 07:12:55 ERROR Upload failed error="upload failed" count=126292026/11/06 07:12:55 INFO Uploading batch count=126302026/11/06 07:12:55 ERROR Upload failed error="upload failed" count=126312026/11/06 07:12:55 INFO Uploading batch count=126322026/11/06 07:12:55 ERROR Upload failed error="upload failed" count=126332026/11/06 07:12:55 ERROR Drain finished with paths left in queue remaining=12634--- PASS: TestRunNotBlockedByPoisonHead (1.07s)2635PASS2636Running signing tests...2637=== RUN TestExternalSigner2638=== PAUSE TestExternalSigner2639=== RUN TestExternalSignerWrongPublicKey2640=== PAUSE TestExternalSignerWrongPublicKey2641=== RUN TestExternalSignerErrors2642=== PAUSE TestExternalSignerErrors2643=== RUN TestExternalSignerRestartsAfterCrash2644=== PAUSE TestExternalSignerRestartsAfterCrash2645=== RUN TestExternalSignerProgramErrorKeepsProcess2646=== PAUSE TestExternalSignerProgramErrorKeepsProcess2647=== RUN TestExternalSignerClose2648=== PAUSE TestExternalSignerClose2649=== RUN TestExternalSignerRejectsInvalidPublicKey2650=== PAUSE TestExternalSignerRejectsInvalidPublicKey2651=== RUN TestExternalSignerCancellation2652=== PAUSE TestExternalSignerCancellation2653=== RUN TestGenerateFingerprint2654=== PAUSE TestGenerateFingerprint2655=== RUN TestParseSigningKey2656=== PAUSE TestParseSigningKey2657=== RUN TestSign2658=== PAUSE TestSign2659=== RUN TestSignBatch2660=== PAUSE TestSignBatch2661=== RUN TestNilKeyPublicKey2662=== PAUSE TestNilKeyPublicKey2663=== RUN TestSignErrors2664=== PAUSE TestSignErrors2665=== CONT TestExternalSigner2666=== CONT TestExternalSignerCancellation2667=== CONT TestExternalSignerProgramErrorKeepsProcess2668=== CONT TestSignBatch2669=== CONT TestSignErrors2670=== CONT TestNilKeyPublicKey2671--- PASS: TestNilKeyPublicKey (0.00s)2672=== CONT TestExternalSignerRejectsInvalidPublicKey2673=== RUN TestExternalSignerRejectsInvalidPublicKey/#002674=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002675=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2676=== CONT TestParseSigningKey2677=== CONT TestSign2678=== CONT TestExternalSignerClose2679=== CONT TestGenerateFingerprint2680=== CONT TestExternalSignerErrors2681=== CONT TestExternalSignerRestartsAfterCrash2682=== CONT TestExternalSignerWrongPublicKey2683=== RUN TestParseSigningKey/valid_32-byte_key2684=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2685=== PAUSE TestParseSigningKey/valid_32-byte_key2686=== RUN TestGenerateFingerprint/basic_with_references2687=== RUN TestSignErrors/nil_key2688=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2689=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2690=== PAUSE TestSignErrors/nil_key2691--- PASS: TestSign (0.00s)2692--- PASS: TestSignBatch (0.00s)2693=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2694=== PAUSE TestGenerateFingerprint/basic_with_references2695=== RUN TestParseSigningKey/no_colon2696=== RUN TestExternalSignerErrors/exit_on_request2697=== RUN TestSignErrors/nil_narinfo2698=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2699=== PAUSE TestExternalSignerErrors/exit_on_request2700=== PAUSE TestParseSigningKey/no_colon2701=== RUN TestParseSigningKey/empty_name2702=== PAUSE TestParseSigningKey/empty_name2703=== PAUSE TestSignErrors/nil_narinfo2704=== RUN TestGenerateFingerprint/no_references2705=== RUN TestExternalSignerErrors/null2706=== PAUSE TestExternalSignerErrors/null2707=== RUN TestExternalSignerErrors/too_few_signatures2708=== PAUSE TestExternalSignerErrors/too_few_signatures2709=== RUN TestExternalSignerErrors/invalid_signature_base642710=== PAUSE TestExternalSignerErrors/invalid_signature_base642711=== RUN TestExternalSignerErrors/wrong_id2712=== PAUSE TestExternalSignerErrors/wrong_id2713=== RUN TestExternalSignerErrors/null_signatures2714=== PAUSE TestExternalSignerErrors/null_signatures2715=== RUN TestExternalSignerErrors/unrequested_key2716=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2717=== RUN TestParseSigningKey/invalid_base642718=== PAUSE TestParseSigningKey/invalid_base642719=== RUN TestParseSigningKey/wrong_length2720=== RUN TestSignErrors/invalid_narinfo2721=== PAUSE TestSignErrors/invalid_narinfo2722=== RUN TestSignErrors/canceled2723=== PAUSE TestSignErrors/canceled2724=== CONT TestSignErrors/nil_key2725=== CONT TestSignErrors/canceled2726=== PAUSE TestGenerateFingerprint/no_references2727=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2728--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.01s)2729=== PAUSE TestExternalSignerErrors/unrequested_key2730=== RUN TestExternalSignerErrors/missing_signature_name2731=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2732=== PAUSE TestParseSigningKey/wrong_length2733=== CONT TestSignErrors/invalid_narinfo2734=== CONT TestSignErrors/nil_narinfo2735--- PASS: TestSignErrors (0.00s)2736 --- PASS: TestSignErrors/nil_key (0.00s)2737 --- PASS: TestSignErrors/canceled (0.00s)2738 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2739 --- PASS: TestSignErrors/nil_narinfo (0.00s)2740=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2741=== PAUSE TestExternalSignerErrors/missing_signature_name2742=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2743=== CONT TestParseSigningKey/valid_32-byte_key2744=== CONT TestParseSigningKey/wrong_length2745=== CONT TestParseSigningKey/invalid_base642746=== CONT TestParseSigningKey/empty_name2747=== CONT TestParseSigningKey/no_colon2748=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2749--- PASS: TestParseSigningKey (0.00s)2750 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2751 --- PASS: TestParseSigningKey/wrong_length (0.00s)2752 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2753 --- PASS: TestParseSigningKey/empty_name (0.00s)2754 --- PASS: TestParseSigningKey/no_colon (0.00s)2755 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2756=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2757=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2758=== RUN TestExternalSignerErrors/invalid_JSON2759=== PAUSE TestExternalSignerErrors/invalid_JSON2760=== RUN TestExternalSignerErrors/missing_signatures2761=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2762=== CONT TestExternalSignerRejectsInvalidPublicKey/#002763=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2764=== RUN TestGenerateFingerprint/invalid_nar_hash_length2765=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2766=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2767=== PAUSE TestExternalSignerErrors/missing_signatures2768=== RUN TestExternalSignerErrors/wrong_signatures_shape2769=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2770--- PASS: TestExternalSignerClose (0.00s)2771=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2772=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2773=== RUN TestGenerateFingerprint/invalid_store_path_prefix2774=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2775=== RUN TestGenerateFingerprint/invalid_reference_prefix2776--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2777 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2778 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2779 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2780 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2781 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2782=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2783=== CONT TestGenerateFingerprint/basic_with_references2784=== CONT TestGenerateFingerprint/invalid_store_path_prefix2785=== RUN TestExternalSignerErrors/exit_at_startup2786=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2787=== CONT TestGenerateFingerprint/invalid_nar_hash_length2788=== CONT TestGenerateFingerprint/invalid_reference_prefix2789=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2790=== CONT TestGenerateFingerprint/no_references2791--- PASS: TestGenerateFingerprint (0.00s)2792 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2793 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2794 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2795 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2796 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2797 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2798 --- PASS: TestGenerateFingerprint/no_references (0.00s)2799=== PAUSE TestExternalSignerErrors/exit_at_startup2800=== RUN TestExternalSignerErrors/wrong_shape2801=== PAUSE TestExternalSignerErrors/wrong_shape2802=== RUN TestExternalSignerErrors/wrong_signature_name2803=== PAUSE TestExternalSignerErrors/wrong_signature_name2804=== RUN TestExternalSignerErrors/wrong_signature_length2805=== PAUSE TestExternalSignerErrors/wrong_signature_length2806=== RUN TestExternalSignerErrors/program_error2807=== PAUSE TestExternalSignerErrors/program_error2808=== CONT TestExternalSignerErrors/exit_on_request2809=== CONT TestExternalSignerErrors/wrong_signature_name2810=== CONT TestExternalSignerErrors/exit_at_startup2811=== CONT TestExternalSignerErrors/invalid_JSON2812=== CONT TestExternalSignerErrors/wrong_signature_length2813=== CONT TestExternalSignerErrors/wrong_signatures_shape2814=== CONT TestExternalSignerErrors/missing_signatures2815=== CONT TestExternalSignerErrors/wrong_shape2816=== CONT TestExternalSignerErrors/wrong_id2817--- PASS: TestExternalSignerWrongPublicKey (0.01s)2818=== CONT TestExternalSignerErrors/missing_signature_name2819=== CONT TestExternalSignerErrors/null_signatures2820=== CONT TestExternalSignerErrors/too_few_signatures2821=== CONT TestExternalSignerErrors/invalid_signature_base642822=== CONT TestExternalSignerErrors/null2823=== CONT TestExternalSignerErrors/unrequested_key2824=== CONT TestExternalSignerErrors/program_error2825--- PASS: TestExternalSigner (0.01s)2826--- PASS: TestExternalSignerRestartsAfterCrash (0.02s)2827--- PASS: TestExternalSignerCancellation (0.03s)2828--- PASS: TestExternalSignerErrors (0.00s)2829 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2830 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2831 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2832 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2833 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2834 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2835 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2836 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2837 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.02s)2838 --- PASS: TestExternalSignerErrors/program_error (0.01s)2839 --- PASS: TestExternalSignerErrors/exit_on_request (0.02s)2840 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2841 --- PASS: TestExternalSignerErrors/null_signatures (0.02s)2842 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2843 --- PASS: TestExternalSignerErrors/missing_signature_name (0.02s)2844 --- PASS: TestExternalSignerErrors/null (0.01s)2845PASS2846Running OpenBao signer tests...2847=== RUN TestSign2848=== PAUSE TestSign2849=== RUN TestSignErrors2850=== PAUSE TestSignErrors2851=== RUN TestServe2852=== PAUSE TestServe2853=== RUN TestServeRejectsGarbage2854=== PAUSE TestServeRejectsGarbage2855=== CONT TestSign2856=== CONT TestServeRejectsGarbage2857--- PASS: TestServeRejectsGarbage (0.00s)2858=== CONT TestServe2859--- PASS: TestServe (0.00s)2860=== CONT TestSignErrors2861=== RUN TestSignErrors/invalid_base642862=== PAUSE TestSignErrors/invalid_base642863=== RUN TestSignErrors/http_error2864=== PAUSE TestSignErrors/http_error2865=== RUN TestSignErrors/invalid_json2866=== PAUSE TestSignErrors/invalid_json2867=== RUN TestSignErrors/no_prefix2868=== PAUSE TestSignErrors/no_prefix2869=== CONT TestSignErrors/invalid_base642870=== CONT TestSignErrors/no_prefix2871=== CONT TestSignErrors/invalid_json2872=== CONT TestSignErrors/http_error2873--- PASS: TestSign (0.03s)2874--- PASS: TestSignErrors (0.00s)2875 --- PASS: TestSignErrors/no_prefix (0.03s)2876 --- PASS: TestSignErrors/invalid_base64 (0.03s)2877 --- PASS: TestSignErrors/http_error (0.03s)2878 --- PASS: TestSignErrors/invalid_json (0.05s)2879PASS