niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #461
· 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.24s)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 TestScriptTokenEmptyCommand117--- PASS: TestScriptTokenEmptyCommand (0.00s)118=== CONT TestScriptTokenScriptFails119=== CONT TestScriptTokenBadJSON120=== CONT TestScriptTokenEmptyToken121=== CONT TestScriptTokenCachesUntilRefresh122=== CONT TestRateLimiterFeedback123=== RUN TestRateLimiterFeedback/429_enables_limiter124=== PAUSE TestRateLimiterFeedback/429_enables_limiter125=== RUN TestRateLimiterFeedback/503_enables_limiter126=== PAUSE TestRateLimiterFeedback/503_enables_limiter127=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter128=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter129=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter130=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter131=== CONT TestRateLimiterFeedback/429_enables_limiter132=== CONT TestScriptTokenNoExpiryRerunsEveryCall133--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)134=== CONT TestPathInfoCACompatibility135=== RUN TestPathInfoCACompatibility/null_ca_field136=== PAUSE TestPathInfoCACompatibility/null_ca_field137=== RUN TestPathInfoCACompatibility/old_string_format_-_text138=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text139=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive140=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive141=== RUN TestPathInfoCACompatibility/new_structured_format_-_text142=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text143=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method144=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method145=== CONT TestPathInfoCACompatibility/null_ca_field146=== CONT TestParsePathInfoJSONMultiplePaths147=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths148=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths149=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths150=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths151=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths152=== CONT TestParsePathInfoJSON153=== RUN TestParsePathInfoJSON/Nix_format154=== PAUSE TestParsePathInfoJSON/Nix_format155=== RUN TestParsePathInfoJSON/Lix_format156=== PAUSE TestParsePathInfoJSON/Lix_format157=== RUN TestParsePathInfoJSON/empty_input158=== PAUSE TestParsePathInfoJSON/empty_input159=== RUN TestParsePathInfoJSON/whitespace_only160=== PAUSE TestParsePathInfoJSON/whitespace_only161=== RUN TestParsePathInfoJSON/invalid_JSON162=== PAUSE TestParsePathInfoJSON/invalid_JSON163=== CONT TestParsePathInfoJSON/Nix_format164=== CONT TestPathInfoHashCompatibility165=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)166=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)167=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon168=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon169=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI170=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI171=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512172=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512173=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)174=== CONT TestGetStorePathHash175=== RUN TestGetStorePathHash/valid_store_path176=== PAUSE TestGetStorePathHash/valid_store_path177=== RUN TestGetStorePathHash/basename_without_hyphen_should_error178=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error179=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error180=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error181=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error182=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error183=== CONT TestGetStorePathHash/valid_store_path184=== CONT TestConvertHashToNix32185=== RUN TestConvertHashToNix32/SRI_format_to_Nix32186=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32187=== RUN TestConvertHashToNix32/already_Nix32_format188=== PAUSE TestConvertHashToNix32/already_Nix32_format189=== RUN TestConvertHashToNix32/invalid_format190=== PAUSE TestConvertHashToNix32/invalid_format191=== CONT TestConvertHashToNix32/SRI_format_to_Nix32192=== CONT TestEncodeNixBase32WithRealHash193--- PASS: TestEncodeNixBase32WithRealHash (0.00s)194=== CONT TestEncodeNixBase32195=== RUN TestEncodeNixBase32/test_string_hash196=== PAUSE TestEncodeNixBase32/test_string_hash197=== RUN TestEncodeNixBase32/empty_input198=== PAUSE TestEncodeNixBase32/empty_input199=== CONT TestEncodeNixBase32/test_string_hash200=== CONT TestDumpPathWriterError201=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method202=== CONT TestDumpPathSingleFile203=== CONT TestPathInfoCACompatibility/new_structured_format_-_text204=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive205=== CONT TestPathInfoCACompatibility/old_string_format_-_text206=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths207--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)208 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)209 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)210=== CONT TestParsePathInfoJSON/invalid_JSON211=== CONT TestParsePathInfoJSON/whitespace_only212=== CONT TestParsePathInfoJSON/empty_input213=== CONT TestParsePathInfoJSON/Lix_format214--- PASS: TestParsePathInfoJSON (0.00s)215 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)216 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)217 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)218 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)219 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)220=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512221=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI222=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon223--- PASS: TestPathInfoHashCompatibility (0.00s)224 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)225 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)226 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)227 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)228=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error229=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error230=== CONT TestGetStorePathHash/basename_without_hyphen_should_error231--- PASS: TestGetStorePathHash (0.00s)232 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)233 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)234 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)235 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)236=== CONT TestConvertHashToNix32/invalid_format237=== CONT TestConvertHashToNix32/already_Nix32_format238--- PASS: TestConvertHashToNix32 (0.00s)239 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)240 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)241 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)242=== CONT TestEncodeNixBase32/empty_input243--- PASS: TestEncodeNixBase32 (0.00s)244 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)245 --- PASS: TestEncodeNixBase32/empty_input (0.00s)246=== CONT TestFileTokenEmpty247--- PASS: TestFileTokenEmpty (0.00s)248=== CONT TestStreamPushBatchesUnderLoad249=== CONT TestFileTokenMissing250=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false251=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false252=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true253=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true254=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false255=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true256--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)257--- PASS: TestFileTokenMissing (0.00s)258=== CONT TestFileTokenReadsAndCaches259--- PASS: TestPathInfoCACompatibility (0.00s)260 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)261 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)262 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)263 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)264 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.02s)265--- PASS: TestStreamPushBatchesUnderLoad (0.00s)266 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)267 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)268=== CONT TestResolveStorePath269--- PASS: TestFileTokenReadsAndCaches (0.00s)270=== CONT TestUploadMultipart_SupersededByPeer271=== RUN TestUploadMultipart_SupersededByPeer/exists272=== PAUSE TestUploadMultipart_SupersededByPeer/exists273=== RUN TestUploadMultipart_SupersededByPeer/missing274=== PAUSE TestUploadMultipart_SupersededByPeer/missing275=== CONT TestPartSizeForNAR276=== RUN TestPartSizeForNAR/zero_stays_at_minimum277=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum278=== RUN TestPartSizeForNAR/small_stays_at_minimum279=== PAUSE TestPartSizeForNAR/small_stays_at_minimum280=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum281=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum282=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts283=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts284=== RUN TestPartSizeForNAR/1_TiB285=== PAUSE TestPartSizeForNAR/1_TiB286=== RUN TestPartSizeForNAR/5_TiB_S3_max_object287=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object288=== RUN TestPartSizeForNAR/capped_at_5_GiB289=== PAUSE TestPartSizeForNAR/capped_at_5_GiB290=== CONT TestUploadMultipart_ReturnsAfterDroppedBody291=== CONT TestStreamPushReportsEveryPath292=== CONT TestShellSplitErrors293=== CONT TestShellSplit294=== CONT TestDoWithRetry_FinalResponseBodyReadable295=== CONT TestRetryTimeoutOutlastsMaxRetries296=== CONT TestDoWithRetry_BodyReplayedViaGetBody297=== CONT TestClientSignaturesByStorePath298=== CONT TestStaticToken299=== CONT TestSetClientTLSErrors300=== CONT TestSetClientTLSDoesNotMutateDefaultTransport301=== CONT TestSetClientTLS302=== CONT TestStreamPushStopsWhenCanceled303=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun304=== CONT TestSupersededNARStillUploadsListing305=== CONT TestDumpPathMatchesNix306--- PASS: TestClientSignaturesByStorePath (0.00s)307--- PASS: TestShellSplitErrors (0.00s)308--- PASS: TestScriptTokenScriptFails (0.07s)309=== CONT TestUploadMultipart_PartsInParallel310=== CONT TestFilterOversizedClosures311=== CONT TestCaseHackSuffix312--- PASS: TestShellSplit (0.00s)313--- PASS: TestScriptTokenEmptyToken (0.07s)314--- PASS: TestScriptTokenBadJSON (0.07s)315--- PASS: TestDoServerRequestAttachesToken (0.08s)316=== CONT TestStreamPushRequestLine3172026/11/06 06:52:44 ERROR Upload failed error=boom count=1318=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer3192026/11/06 06:52:44 WARN Rate limiter enabled after throttle name=server-test rate=53202026/11/06 06:52:44 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:45857321=== RUN TestFilterOversizedClosures/no_limit_keeps_everything322=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess323--- PASS: TestResolveStorePath (0.03s)3242026/11/06 06:52:44 WARN Rate limiter backed off name=server-test rate=5325--- PASS: TestStreamPushStopsWhenCanceled (0.00s)326--- PASS: TestStaticToken (0.00s)327--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.05s)328--- PASS: TestStreamPushReportsEveryPath (0.07s)329--- PASS: TestDumpPathSingleFile (0.20s)330=== CONT TestUploadMultipart_SupersededByPeer/exists331=== RUN TestSupersededNARStillUploadsListing/small_NAR332=== PAUSE TestSupersededNARStillUploadsListing/small_NAR333=== RUN TestSupersededNARStillUploadsListing/dump_cut_short334=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short335=== CONT TestRegisterUploadedObjectReusesConnections3362026/11/06 06:52:44 WARN Rate limiter enabled after throttle name=server-test rate=53372026/11/06 06:52:44 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:397013382026/11/06 06:52:44 INFO Garbage collection started339--- PASS: TestUploadMultipart_ReturnsAfterDroppedBody (0.18s)340=== CONT TestStreamPushIsolatesFailures341=== RUN TestSetClientTLSErrors/missing_cert_file3422026/11/06 06:52:44 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:453633432026/11/06 06:52:44 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:453633442026/11/06 06:52:44 WARN Rate limiter enabled after throttle name=server-test rate=5345=== PAUSE TestSetClientTLSErrors/missing_cert_file346=== RUN TestSetClientTLSErrors/missing_key_file3472026/11/06 06:52:44 ERROR Upload failed error="bad path" count=3348=== PAUSE TestSetClientTLSErrors/missing_key_file3492026/11/06 06:52:44 WARN Rate limiter backed off name=server-test rate=5350=== RUN TestSetClientTLSErrors/missing_ca_file351=== PAUSE TestSetClientTLSErrors/missing_ca_file352=== RUN TestSetClientTLSErrors/invalid_ca_file353=== PAUSE TestSetClientTLSErrors/invalid_ca_file354=== CONT TestStreamPushGivesUpOnDeadServer355--- PASS: TestStreamPushIsolatesFailures (0.00s)356=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry357--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.11s)358=== CONT TestPartSizeForNAR/capped_at_5_GiB359=== CONT TestPartSizeForNAR/5_TiB_S3_max_object360=== CONT TestPartSizeForNAR/1_TiB3612026/11/06 06:52:44 WARN Rate limiter enabled after throttle name=server-test rate=53622026/11/06 06:52:44 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:37593363=== CONT TestUploadMultipart_SupersededByPeer/missing3642026/11/06 06:52:44 WARN Rate limiter backed off name=server-test rate=53652026/11/06 06:52:44 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:37593366=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts367=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum368=== CONT TestPartSizeForNAR/small_stays_at_minimum369=== CONT TestRateLimiterFeedback/503_enables_limiter370=== RUN TestSetClientTLS/rejects_connection_without_client_cert371=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert372=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA373=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA374=== RUN TestSetClientTLS/preserves_debug_logging_transport375=== PAUSE TestSetClientTLS/preserves_debug_logging_transport376=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter377=== CONT TestSetClientTLSErrors/missing_cert_file378=== CONT TestSetClientTLSErrors/missing_ca_file379--- PASS: TestCaseHackSuffix (0.36s)380=== CONT TestSetClientTLSErrors/invalid_ca_file3812026/11/06 06:52:44 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:45363382=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica3832026/11/06 06:52:44 WARN Rate limiter enabled after throttle name=server-test rate=53842026/11/06 06:52:44 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:36333385--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.31s)386=== CONT TestSetClientTLS/preserves_debug_logging_transport387=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA388=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails389=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter390=== CONT TestStreamPushReportsSkippedPaths391=== CONT TestStreamPushReportsSignatures392=== CONT TestPartSizeForNAR/zero_stays_at_minimum393=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything3942026/11/06 06:52:44 ERROR Upload failed error="connection refused" count=203952026/11/06 06:52:44 ERROR Server seems unavailable, giving up on batch untried=173962026/11/06 06:52:44 WARN Rate limiter backed off name=server-test rate=53972026/11/06 06:52:44 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:45363398=== CONT TestSetClientTLSErrors/missing_key_file399=== CONT TestSetClientTLS/rejects_connection_without_client_cert400=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped4012026/11/06 06:52:44 INFO Garbage collection started402=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped4032026/11/06 06:52:44 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:45363404=== RUN TestFilterOversizedClosures/all_closures_skipped4052026/11/06 06:52:44 ERROR Upload failed error=boom count=1406=== PAUSE TestFilterOversizedClosures/all_closures_skipped407=== CONT TestFilterOversizedClosures/no_limit_keeps_everything408--- PASS: TestStreamPushReportsSkippedPaths (0.00s)409--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)410 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.20s)411 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.24s)412=== CONT TestFilterOversizedClosures/all_closures_skipped4132026/11/06 06:52:44 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=50414=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped4152026/11/06 06:52:44 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=2000416=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails417=== CONT TestSupersededNARStillUploadsListing/small_NAR418=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails4192026/11/06 06:52:44 INFO Uploading abc-hello (1.0GB)420--- PASS: TestStreamPushGivesUpOnDeadServer (0.24s)421--- PASS: TestRateLimiterFeedback (0.00s)422 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.21s)423 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.16s)424 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.24s)425 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)4262026/11/06 06:52:44 INFO Uploading abc-hello (1.0GB)4272026/11/06 06:52:44 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:453634282026/11/06 06:52:44 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=0429--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.32s)430--- PASS: TestPartSizeForNAR (0.00s)431 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)432 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)433 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)434 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)435 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)436 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)437 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)438--- PASS: TestFilterOversizedClosures (0.40s)439 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)440 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)441 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)442--- PASS: TestStreamPushReportsSignatures (0.00s)443=== CONT TestSupersededNARStillUploadsListing/dump_cut_short444--- PASS: TestSetClientTLSErrors (0.11s)445 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)446 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.03s)447 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.05s)448 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)4492026/11/06 06:52:44 WARN Garbage collection finished on another replica. Its statistics are not available here450--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.31s)4512026/11/06 06:52:44 WARN Rate limiter enabled after throttle name=s3-test rate=54522026/11/06 06:52:44 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:378114532026/11/06 06:52:44 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:45363454--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.53s)4552026/11/06 06:52:44 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:453634562026/11/06 06:52:44 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:453634572026/11/06 06:52:44 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:453634582026/11/06 06:52:44 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:453634592026/11/06 06:52:44 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:453634602026/11/06 06:52:44 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:453634612026/11/06 06:52:44 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:453634622026/11/06 06:52:44 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:453634632026/11/06 06:52:44 http: TLS handshake error from 127.0.0.1:42938: remote error: tls: bad certificate4642026/11/06 06:52:44 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:453634652026/11/06 06:52:44 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:453634662026/11/06 06:52:44 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:453634672026/11/06 06:52:44 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:45363468--- PASS: TestSetClientTLS (0.16s)469 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.31s)470 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.30s)471 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.30s)472--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.71s)473--- PASS: TestRegisterUploadedObjectReusesConnections (0.56s)474--- PASS: TestStreamPushRequestLine (0.71s)475--- PASS: TestDumpPathWriterError (0.77s)4762026/11/06 06:52:44 INFO Uploading abc-hello (1.0GB)4772026/11/06 06:52:44 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:42481/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:42481/part/2478--- PASS: TestDumpPathMatchesNix (0.79s)4792026/11/06 06:52:44 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:42481/part/3\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:42481/part/34802026/11/06 06:52:44 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:42481/part/4\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:42481/part/44812026/11/06 06:52:44 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:42481/part/5\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:42481/part/54822026/11/06 06:52:44 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:42481/part/6\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:42481/part/64832026/11/06 06:52:44 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"4842026/11/06 06:52:45 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:37039/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:37039/api/uploads/complete4852026/11/06 06:52:45 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4862026/11/06 06:52:45 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:37039/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:37039/api/uploads/complete4872026/11/06 06:52:45 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4882026/11/06 06:52:45 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:37039/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:37039/api/uploads/complete4892026/11/06 06:52:45 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"490--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.08s)491--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.05s)492--- PASS: TestSupersededNARStillUploadsListing (0.33s)493 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.29s)494 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.29s)495 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.86s)496--- PASS: TestUploadMultipart_PartsInParallel (1.28s)497PASS498Running server tests...499The files belonging to this database system will be owned by user "nixbld".500This user must also own the server process.501502The database cluster will be initialized with locale "C".503The default database encoding has accordingly been set to "SQL_ASCII".504The default text search configuration will be set to "english".505506Data page checksums are enabled.507508creating directory /build/postgres2062737939/data ... ok509creating subdirectories ... ok510selecting dynamic shared memory implementation ... posix511selecting default "max_connections" ... 100512selecting default "shared_buffers" ... 128MB513selecting default time zone ... UTC514creating configuration files ... ok515running bootstrap script ... ok516performing post-bootstrap initialization ... ok517syncing data to disk ... ok518519initdb: warning: enabling "trust" authentication for local connections520initdb: 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.521522Success. You can now start the database server using:523524 pg_ctl -D /build/postgres2062737939/data -l logfile start525526/build/postgres2062737939:5432 - no response5272026-11-06 06:52:47.961 UTC [131] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit5282026-11-06 06:52:47.962 UTC [131] LOG: listening on Unix socket "/build/postgres2062737939/.s.PGSQL.5432"5292026-11-06 06:52:47.969 UTC [138] LOG: database system was shut down at 2026-11-06 06:52:47 UTC5302026-11-06 06:52:47.974 UTC [131] LOG: database system is ready to accept connections531/build/postgres2062737939:5432 - accepting connections532{"timestamp":"2026-11-06T06:52:52.113070028Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"4bd77170-bf6e-44a3-ad17-a1a4541916a9","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":6,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(209)"}533=== RUN TestService_AuthMiddleware534=== PAUSE TestService_AuthMiddleware535=== RUN TestService_AuthMiddleware_MTLSProxyHeader536=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader537=== RUN TestService_AuthMiddleware_MTLSBoundSubjects538=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects539=== RUN TestService_ReadAuthMiddleware540=== PAUSE TestService_ReadAuthMiddleware541=== RUN TestService_AuthMiddleware_OIDC542=== PAUSE TestService_AuthMiddleware_OIDC543=== RUN TestService_RequireScope_OIDC544=== PAUSE TestService_RequireScope_OIDC545=== RUN TestService_ReadScope_PublicByDefault546=== PAUSE TestService_ReadScope_PublicByDefault547=== RUN TestCacheConfigHandler548=== PAUSE TestCacheConfigHandler549=== RUN TestCacheStatsHandler550=== PAUSE TestCacheStatsHandler551=== RUN TestClientCADerivations552=== PAUSE TestClientCADerivations553=== RUN TestClientErrorHandling554=== PAUSE TestClientErrorHandling555=== RUN TestClientIntegration556=== PAUSE TestClientIntegration557=== RUN TestClientMultipleUploads558=== PAUSE TestClientMultipleUploads559=== RUN TestClientWithDependencies560=== PAUSE TestClientWithDependencies561=== RUN TestClientSharedPathCommittedMidPush562=== PAUSE TestClientSharedPathCommittedMidPush563=== RUN TestPinProtectsFromGC564=== PAUSE TestPinProtectsFromGC565=== RUN TestClientPushesUseOnePush566=== PAUSE TestClientPushesUseOnePush567=== RUN TestClientFallsBackToClosures568=== PAUSE TestClientFallsBackToClosures569=== RUN TestDeleteClosuresRacingPins570=== PAUSE TestDeleteClosuresRacingPins571=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock572=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock573=== RUN TestResolveDBConnectionString574=== PAUSE TestResolveDBConnectionString575=== RUN TestConnectWaitsForAPeerMigration576=== PAUSE TestConnectWaitsForAPeerMigration577=== RUN TestLeadElectsOneAndHandsOver578=== PAUSE TestLeadElectsOneAndHandsOver579=== RUN TestLeadIncumbentWinsAfterRestart5802026/11/06 06:52:52 INFO lead: acquired remote=192.0.2.1:12345812026/11/06 06:52:53 INFO lead: released remote=192.0.2.1:12345822026/11/06 06:52:53 INFO lead: acquired remote=192.0.2.1:12345832026/11/06 06:52:54 INFO lead: released remote=192.0.2.1:1234584--- PASS: TestLeadIncumbentWinsAfterRestart (2.19s)585=== RUN TestLeadIncumbentAnnouncesAtOnce586=== PAUSE TestLeadIncumbentAnnouncesAtOnce587=== RUN TestLeadEndsOnShutdown588=== PAUSE TestLeadEndsOnShutdown589=== RUN TestLeadEndsWhenItsConnectionHangs5902026/11/06 06:52:55 INFO lead: acquired remote=192.0.2.1:12345912026-11-06 06:52:56.682 UTC [389] FATAL: terminating connection due to administrator command5922026/11/06 06:52:56 INFO lead: acquired remote=192.0.2.1:12345932026/11/06 06:52:57 WARN lead: lock connection lost error="timeout: context deadline exceeded"5942026/11/06 06:52:57 INFO lead: released remote=192.0.2.1:12345952026/11/06 06:52:58 INFO lead: released remote=192.0.2.1:1234596--- PASS: TestLeadEndsWhenItsConnectionHangs (3.64s)597=== RUN TestGCAdvisoryLockBlocksConcurrentRun598=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun599=== RUN TestGCBugBareHashReferences600=== PAUSE TestGCBugBareHashReferences601=== RUN TestGCMetrics602=== PAUSE TestGCMetrics603=== RUN TestPushDedupSurvivesConcurrentGC604=== PAUSE TestPushDedupSurvivesConcurrentGC605=== RUN TestDeduplicatedObjectsRecordedAsPending606=== PAUSE TestDeduplicatedObjectsRecordedAsPending607=== RUN TestGCSweepSkipsPendingObjects608=== PAUSE TestGCSweepSkipsPendingObjects609=== RUN TestTombstonedObjectOfferedWithoutWaiting610=== PAUSE TestTombstonedObjectOfferedWithoutWaiting611=== RUN TestGCSweepDeliversEachKeyOnce612=== PAUSE TestGCSweepDeliversEachKeyOnce613=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection614=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection615=== RUN TestForceGCDuringPushOffersSweptObject616=== PAUSE TestForceGCDuringPushOffersSweptObject617=== RUN TestFailedS3DeleteKeepsTombstone618=== PAUSE TestFailedS3DeleteKeepsTombstone619=== RUN TestSweepSkipsRowsLockedByPush620=== PAUSE TestSweepSkipsRowsLockedByPush621=== RUN TestRegisterCompletedObjectNeedsPendingRow622=== PAUSE TestRegisterCompletedObjectNeedsPendingRow623=== RUN TestGetExistingObjectsLocksRows624=== PAUSE TestGetExistingObjectsLocksRows625=== RUN TestSweepRechecksPendingAfterLocking626=== PAUSE TestSweepRechecksPendingAfterLocking627=== RUN TestPushWaitsForSweepHoldingRow628=== PAUSE TestPushWaitsForSweepHoldingRow629=== RUN TestCommitRacingPendingCleanupKeepsObjects630=== PAUSE TestCommitRacingPendingCleanupKeepsObjects631=== RUN TestGCEndsOnShutdown632=== PAUSE TestGCEndsOnShutdown633=== RUN TestGCTaskStore_StartNew634=== PAUSE TestGCTaskStore_StartNew635=== RUN TestGCTaskStore_DeduplicateSameParams636=== PAUSE TestGCTaskStore_DeduplicateSameParams637=== RUN TestGCTaskStore_ConflictDifferentParams638=== PAUSE TestGCTaskStore_ConflictDifferentParams639=== RUN TestGCTaskStore_GetEmpty640=== PAUSE TestGCTaskStore_GetEmpty641=== RUN TestGCTaskStore_GetReturnsLatest642=== PAUSE TestGCTaskStore_GetReturnsLatest643=== RUN TestGCTaskStore_CompletedAllowsNewTask644=== PAUSE TestGCTaskStore_CompletedAllowsNewTask645=== RUN TestGCTaskStore_PhaseUpdates646=== PAUSE TestGCTaskStore_PhaseUpdates647=== RUN TestGCTaskStore_Fail648=== PAUSE TestGCTaskStore_Fail649=== RUN TestGracefulShutdownDrainsInflight650=== PAUSE TestGracefulShutdownDrainsInflight651=== RUN TestService_healthCheckHandler652=== PAUSE TestService_healthCheckHandler653=== RUN TestService_readinessHandler654=== PAUSE TestService_readinessHandler655=== RUN TestGenerateLandingPage656=== PAUSE TestGenerateLandingPage657=== RUN TestCacheConfigHandlerMaxNarSize658=== PAUSE TestCacheConfigHandlerMaxNarSize659=== RUN TestCreatePendingClosureRejectsOversizedNAR660=== PAUSE TestCreatePendingClosureRejectsOversizedNAR661=== RUN TestNARDeduplicationMetadataUploadBug662=== PAUSE TestNARDeduplicationMetadataUploadBug663=== RUN TestMetricsInventory664=== PAUSE TestMetricsInventory665=== RUN TestMetricsCommit666=== PAUSE TestMetricsCommit667=== RUN TestService_NativeMTLS668=== PAUSE TestService_NativeMTLS669=== RUN TestServerTLSConfig670=== PAUSE TestServerTLSConfig671=== RUN TestMultipartCleanup672=== PAUSE TestMultipartCleanup673=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded674=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded675=== RUN TestPendingCleanupUsesOneCutoff676=== PAUSE TestPendingCleanupUsesOneCutoff677=== RUN TestObjectStatsTrigger678=== PAUSE TestObjectStatsTrigger679=== RUN TestObjectStatsUpdatedOncePerCommit680=== PAUSE TestObjectStatsUpdatedOncePerCommit681=== RUN TestOrphanedObjectsGC682=== PAUSE TestOrphanedObjectsGC683=== RUN TestOrphanedObjectsGCStressTest684=== PAUSE TestOrphanedObjectsGCStressTest685=== RUN TestCreatePin_ReservedPins686=== PAUSE TestCreatePin_ReservedPins687=== RUN TestPresentReportsOnlyClosureRoots688=== PAUSE TestPresentReportsOnlyClosureRoots689=== RUN TestPresentRefreshesOnlyStaleClosures690=== PAUSE TestPresentRefreshesOnlyStaleClosures691=== RUN TestPresentNotReportedWhileGCDeletesClosure692=== PAUSE TestPresentNotReportedWhileGCDeletesClosure693=== RUN TestParseSingleRange694=== PAUSE TestParseSingleRange695=== RUN TestProxyHeadersOnlyTrustedOnSocket6962026/11/06 06:52:58 INFO Starting HTTP server address=127.0.0.1:423996972026/11/06 06:52:58 INFO Starting HTTP server address=proxy.sock6982026/11/06 06:52:58 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6992026/11/06 06:52:58 INFO Shutdown signal received, draining in-flight requests timeout=10s700--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.33s)701=== RUN TestIsValidCachePath702=== PAUSE TestIsValidCachePath703=== RUN TestReadProxyNarinfo704=== PAUSE TestReadProxyNarinfo705=== RUN TestReadProxyNarinfoAlreadyDecompressed706=== PAUSE TestReadProxyNarinfoAlreadyDecompressed707=== RUN TestReadProxyContentNegotiation708=== PAUSE TestReadProxyContentNegotiation709=== RUN TestReadProxyNarStreaming710=== PAUSE TestReadProxyNarStreaming711=== RUN TestReadProxy404712=== PAUSE TestReadProxy404713=== RUN TestReadProxyInvalidPath714=== PAUSE TestReadProxyInvalidPath715=== RUN TestReadProxyHead716=== PAUSE TestReadProxyHead717=== RUN TestReadProxyOutlastsServerWriteTimeout718=== PAUSE TestReadProxyOutlastsServerWriteTimeout719=== RUN TestReadProxyConditionalGet720=== PAUSE TestReadProxyConditionalGet721=== RUN TestReadProxyRootRedirectsToIndexHTML722=== PAUSE TestReadProxyRootRedirectsToIndexHTML723=== RUN TestReadProxyDisabled724=== PAUSE TestReadProxyDisabled725=== RUN TestReadRedirectNar726=== PAUSE TestReadRedirectNar727=== RUN TestReadRedirectKeepsNarinfoProxied728=== PAUSE TestReadRedirectKeepsNarinfoProxied729=== RUN TestReadProxyRangeRequest730=== PAUSE TestReadProxyRangeRequest731=== RUN TestReadRedirectUsesPublicS3URL732=== PAUSE TestReadRedirectUsesPublicS3URL733=== RUN TestPush_OverlappingRootsStoreOneRowPerKey734=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey735=== RUN TestPush_CompleteCommitsEveryRoot736=== PAUSE TestPush_CompleteCommitsEveryRoot737=== RUN TestPush_RepeatedRootCommitsOnce738=== PAUSE TestPush_RepeatedRootCommitsOnce739=== RUN TestPush_CompleteWaitsForCleanupOfThePush740=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush741=== RUN TestPush_RootsAreLockedInByteOrder742=== PAUSE TestPush_RootsAreLockedInByteOrder743=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit744=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit745=== RUN TestPush_RejectsBadRequests746=== PAUSE TestPush_RejectsBadRequests747=== RUN TestPush_SignsNarinfosOfItsPendingObjects748=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects749=== RUN TestRedundantMultipartUpload750=== PAUSE TestRedundantMultipartUpload751=== RUN TestCompleteMultipartUpload_ErrorButObjectExists752=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists753=== RUN TestCompletedNarNotReofferedAcrossClosures754=== PAUSE TestCompletedNarNotReofferedAcrossClosures755=== RUN TestPresignedUploadRegisteredBeforeCommit756=== PAUSE TestPresignedUploadRegisteredBeforeCommit757=== RUN TestService_Rustfstest758=== PAUSE TestService_Rustfstest759=== RUN TestParseSize760=== PAUSE TestParseSize761=== RUN TestSkippedUploadsHandler762=== PAUSE TestSkippedUploadsHandler763=== RUN TestSystemdListenerNotActivated764--- PASS: TestSystemdListenerNotActivated (0.00s)765=== RUN TestWatchdogBeatsWhenHealthy766--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)767=== RUN TestWatchdogSkipsWhenUnhealthy7682026/11/06 06:52:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7692026/11/06 06:52:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7702026/11/06 06:52:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7712026/11/06 06:52:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7722026/11/06 06:52:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7732026/11/06 06:52:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7742026/11/06 06:52:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7752026/11/06 06:52:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7762026/11/06 06:52:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7772026/11/06 06:52:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"778--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)779=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle780=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle781=== RUN TestProxyWriteTimeout782=== PAUSE TestProxyWriteTimeout783=== RUN TestPendingClosureWriteTimeout784=== PAUSE TestPendingClosureWriteTimeout785=== RUN TestIsValidUploadKey786=== PAUSE TestIsValidUploadKey787=== RUN TestUploadHandlersRejectInvalidKeys788=== PAUSE TestUploadHandlersRejectInvalidKeys789=== RUN TestUploadHandlersRejectOversizedBody790=== PAUSE TestUploadHandlersRejectOversizedBody791=== RUN TestService_cleanupPendingClosuresHandler792=== PAUSE TestService_cleanupPendingClosuresHandler793=== RUN TestService_createPendingClosureHandler794=== PAUSE TestService_createPendingClosureHandler795=== RUN TestService_verifyS3Integrity796=== PAUSE TestService_verifyS3Integrity797=== RUN TestService_verifyS3ReuploadsStaleNarinfo798=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo799=== RUN TestCompleteMultipartUnregistered800=== PAUSE TestCompleteMultipartUnregistered801=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT802=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT803=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle804=== CONT TestPush_CompleteWaitsForCleanupOfThePush805=== CONT TestService_cleanupPendingClosuresHandler806=== CONT TestGCTaskStore_GetReturnsLatest807=== CONT TestService_verifyS3ReuploadsStaleNarinfo808=== CONT TestParseSize809=== CONT TestPush_CompleteCommitsEveryRoot810=== CONT TestService_Rustfstest811=== CONT TestPresignedUploadRegisteredBeforeCommit812=== CONT TestCompletedNarNotReofferedAcrossClosures813=== CONT TestCompleteMultipartUpload_ErrorButObjectExists814=== CONT TestRedundantMultipartUpload815=== CONT TestPush_SignsNarinfosOfItsPendingObjects816=== CONT TestPush_RejectsBadRequests817=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit818=== CONT TestPush_RootsAreLockedInByteOrder819=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT820=== CONT TestCompleteMultipartUnregistered821=== CONT TestIsValidUploadKey822=== CONT TestUploadHandlersRejectOversizedBody823=== CONT TestUploadHandlersRejectInvalidKeys824=== CONT TestPendingClosureWriteTimeout825=== CONT TestPresentReportsOnlyClosureRoots826=== CONT TestService_AuthMiddleware827=== CONT TestSkippedUploadsHandler828--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)829--- PASS: TestParseSize (0.00s)830=== CONT TestPush_RepeatedRootCommitsOnce831=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed832=== RUN TestPendingClosureWriteTimeout/empty833=== PAUSE TestPendingClosureWriteTimeout/empty834=== RUN TestPendingClosureWriteTimeout/400_objects835=== PAUSE TestPendingClosureWriteTimeout/400_objects836=== RUN TestPendingClosureWriteTimeout/670k_objects837=== PAUSE TestPendingClosureWriteTimeout/670k_objects838=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info839=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed840=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline841=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline842=== CONT TestPush_OverlappingRootsStoreOneRowPerKey8432026/11/06 06:52:58 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000844=== RUN TestIsValidUploadKey/narinfo845=== RUN TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed846=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed847=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost848=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost849=== PAUSE TestIsValidUploadKey/narinfo850=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info851=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal852=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed853=== RUN TestIsValidUploadKey/nar_zst854=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal855=== PAUSE TestIsValidUploadKey/nar_zst856=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key857=== RUN TestIsValidUploadKey/nar_xz858=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed859=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed860=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key861=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key862=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key863=== PAUSE TestIsValidUploadKey/nar_xz864=== RUN TestIsValidUploadKey/nar_plain865=== PAUSE TestIsValidUploadKey/nar_plain866=== RUN TestIsValidUploadKey/listing867=== PAUSE TestIsValidUploadKey/listing868=== RUN TestIsValidUploadKey/build_log869=== PAUSE TestIsValidUploadKey/build_log870=== RUN TestIsValidUploadKey/build_log_home-manager_file871=== PAUSE TestIsValidUploadKey/build_log_home-manager_file872=== RUN TestIsValidUploadKey/build_log_plus_in_name873=== PAUSE TestIsValidUploadKey/build_log_plus_in_name874=== RUN TestIsValidUploadKey/build_log_question_mark875=== PAUSE TestIsValidUploadKey/build_log_question_mark876=== RUN TestIsValidUploadKey/build_log_equals877=== PAUSE TestIsValidUploadKey/build_log_equals878=== CONT TestReadRedirectUsesPublicS3URL879=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed880=== RUN TestIsValidUploadKey/realisation881=== PAUSE TestIsValidUploadKey/realisation882=== CONT TestReadProxyRangeRequest883=== RUN TestIsValidUploadKey/realisation_plus_in_output884=== PAUSE TestIsValidUploadKey/realisation_plus_in_output885=== RUN TestIsValidUploadKey/nix-cache-info886=== PAUSE TestIsValidUploadKey/nix-cache-info887=== RUN TestIsValidUploadKey/index.html888=== PAUSE TestIsValidUploadKey/index.html889=== RUN TestIsValidUploadKey/narinfo_key,_nar_type890=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type891=== RUN TestIsValidUploadKey/nar_key,_narinfo_type892=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type893=== RUN TestIsValidUploadKey/listing_key,_narinfo_type894=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type895=== RUN TestIsValidUploadKey/traversal896=== PAUSE TestIsValidUploadKey/traversal897=== RUN TestIsValidUploadKey/traversal_nar898=== PAUSE TestIsValidUploadKey/traversal_nar899=== RUN TestIsValidUploadKey/absolute900=== PAUSE TestIsValidUploadKey/absolute901=== RUN TestIsValidUploadKey/empty_key902=== PAUSE TestIsValidUploadKey/empty_key903=== RUN TestIsValidUploadKey/unknown_type904=== PAUSE TestIsValidUploadKey/unknown_type905=== CONT TestReadRedirectKeepsNarinfoProxied906--- PASS: TestSkippedUploadsHandler (0.15s)907=== CONT TestReadRedirectNar908=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure909=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure910=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart911=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart912=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts913=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts914=== CONT TestReadProxyDisabled9152026/11/06 06:52:59 INFO Received uploads request method=POST path=/api/pending_closures9162026/11/06 06:52:59 INFO Received cleanup request method=DELETE path=/api/pending_closures9172026/11/06 06:52:59 INFO Aborted multipart uploads count=0 kept=09182026/11/06 06:52:59 INFO Received uploads request method=POST path=/api/pending_closures9192026/11/06 06:52:59 INFO Received push request method=POST path=/api/pushes9202026/11/06 06:52:59 INFO Received cleanup request method=DELETE path=/api/pending_closures9212026/11/06 06:52:59 INFO Aborted multipart uploads count=1 kept=09222026/11/06 06:52:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9232026/11/06 06:52:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9242026-11-06 06:52:59.390 UTC [450] ERROR: Closure does not exist: id=19252026-11-06 06:52:59.390 UTC [450] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9262026-11-06 06:52:59.390 UTC [450] STATEMENT: -- name: CommitPendingClosure :one927 SELECT commit_pending_closure($1::bigint)::bigint928 929--- PASS: TestService_cleanupPendingClosuresHandler (0.76s)930=== CONT TestReadProxyRootRedirectsToIndexHTML9312026/11/06 06:52:59 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst932--- PASS: TestCompleteMultipartUnregistered (0.76s)933=== CONT TestReadProxyConditionalGet9342026/11/06 06:52:59 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9352026/11/06 06:52:59 INFO Received uploads request method=POST path=/api/pending_closures936--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.77s)937=== CONT TestReadProxyOutlastsServerWriteTimeout938--- PASS: TestService_Rustfstest (0.77s)939=== CONT TestReadProxyHead9402026/11/06 06:52:59 INFO Received push request method=POST path=/api/pushes9412026/11/06 06:52:59 INFO Received push request method=POST path=/api/pushes9422026/11/06 06:52:59 INFO Received uploads request method=POST path=/api/pending_closures9432026/11/06 06:52:59 INFO Received complete push request method=POST path=/api/pushes/1/complete9442026-11-06 06:52:59.511 UTC [500] ERROR: could not obtain lock on row in relation "closures"9452026-11-06 06:52:59.511 UTC [500] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT946--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.87s)947=== CONT TestReadProxyInvalidPath9482026-11-06 06:52:59.512 UTC [500] ERROR: could not obtain lock on row in relation "closures"9492026-11-06 06:52:59.512 UTC [500] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9502026-11-06 06:52:59.512 UTC [500] ERROR: could not obtain lock on row in relation "closures"9512026-11-06 06:52:59.512 UTC [500] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9522026-11-06 06:52:59.512 UTC [500] ERROR: could not obtain lock on row in relation "closures"9532026-11-06 06:52:59.512 UTC [500] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9542026-11-06 06:52:59.513 UTC [500] ERROR: could not obtain lock on row in relation "closures"9552026-11-06 06:52:59.513 UTC [500] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT956--- PASS: TestPush_RootsAreLockedInByteOrder (0.86s)957=== CONT TestReadProxy4049582026/11/06 06:52:59 INFO Completed push id=1 objects=6 duration=18.747353ms9592026/11/06 06:52:59 INFO Received uploads request method=POST path=/api/pending_closures960--- PASS: TestPush_CompleteCommitsEveryRoot (0.88s)961=== CONT TestReadProxyNarStreaming9622026/11/06 06:52:59 INFO Received uploads request method=POST path=/api/pending_closures9632026/11/06 06:52:59 INFO Received push request method=POST path=/api/pushes9642026/11/06 06:52:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9652026/11/06 06:52:59 INFO Signed narinfos id=1 count=19662026/11/06 06:52:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9672026/11/06 06:52:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9682026/11/06 06:52:59 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"9692026/11/06 06:52:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9702026/11/06 06:52:59 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"9712026/11/06 06:52:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9722026/11/06 06:52:59 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=19732026/11/06 06:52:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9742026/11/06 06:52:59 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo975--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (1.01s)976=== CONT TestReadProxyContentNegotiation9772026/11/06 06:52:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9782026/11/06 06:52:59 INFO Received uploads request method=POST path=/api/pending_closures9792026/11/06 06:52:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9802026/11/06 06:52:59 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZDYyMjZkMWEtNDhkNy00NWRjLTkzYWUtYzZlYWRiOTE0MTZhLmMwNDI0MDA1LWMyNDktNDU0MS1hNTFlLTc5NWY3NThmMmExYngxNzkzOTQ3OTc5NTczOTI3MTk29812026-11-06 06:52:59.692 UTC [486] ERROR: Push does not exist: id=19822026-11-06 06:52:59.692 UTC [486] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE9832026-11-06 06:52:59.692 UTC [486] STATEMENT: SELECT commit_push($1)984=== CONT TestReadProxyNarinfoAlreadyDecompressed985--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.06s)9862026/11/06 06:52:59 INFO Received push request method=POST path=/api/pushes9872026/11/06 06:52:59 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZDYyMjZkMWEtNDhkNy00NWRjLTkzYWUtYzZlYWRiOTE0MTZhLmMwNDI0MDA1LWMyNDktNDU0MS1hNTFlLTc5NWY3NThmMmExYngxNzkzOTQ3OTc5NTczOTI3MTk2 parts=1988--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.07s)989=== CONT TestReadProxyNarinfo9902026/11/06 06:52:59 INFO Received complete push request method=POST path=/api/pushes/1/complete9912026/11/06 06:52:59 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"992--- PASS: TestService_AuthMiddleware (1.08s)993=== CONT TestIsValidCachePath994=== RUN TestIsValidCachePath/narinfo995=== PAUSE TestIsValidCachePath/narinfo996=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars997=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars998=== RUN TestIsValidCachePath/nar_zst999=== PAUSE TestIsValidCachePath/nar_zst1000=== RUN TestIsValidCachePath/nar_xz1001=== PAUSE TestIsValidCachePath/nar_xz1002=== RUN TestIsValidCachePath/nar_bz21003=== PAUSE TestIsValidCachePath/nar_bz21004=== RUN TestIsValidCachePath/nar_uncompressed1005=== PAUSE TestIsValidCachePath/nar_uncompressed1006=== RUN TestIsValidCachePath/ls1007=== PAUSE TestIsValidCachePath/ls1008=== RUN TestIsValidCachePath/log1009=== PAUSE TestIsValidCachePath/log1010=== RUN TestIsValidCachePath/realisation1011=== PAUSE TestIsValidCachePath/realisation1012=== RUN TestIsValidCachePath/nix-cache-info1013=== PAUSE TestIsValidCachePath/nix-cache-info1014=== RUN TestIsValidCachePath/index.html1015=== PAUSE TestIsValidCachePath/index.html1016=== RUN TestIsValidCachePath/traversal_parent1017=== PAUSE TestIsValidCachePath/traversal_parent1018=== RUN TestIsValidCachePath/traversal_in_middle1019=== PAUSE TestIsValidCachePath/traversal_in_middle1020=== RUN TestIsValidCachePath/invalid_char_e1021=== PAUSE TestIsValidCachePath/invalid_char_e1022=== RUN TestIsValidCachePath/invalid_char_u1023=== PAUSE TestIsValidCachePath/invalid_char_u1024=== RUN TestIsValidCachePath/random_path1025=== PAUSE TestIsValidCachePath/random_path1026=== RUN TestIsValidCachePath/empty1027=== PAUSE TestIsValidCachePath/empty1028=== RUN TestIsValidCachePath/leading_slash1029=== PAUSE TestIsValidCachePath/leading_slash1030=== RUN TestIsValidCachePath/wrong_extension1031=== PAUSE TestIsValidCachePath/wrong_extension1032=== RUN TestIsValidCachePath/short_hash1033=== PAUSE TestIsValidCachePath/short_hash1034=== CONT TestProxyWriteTimeout1035=== RUN TestProxyWriteTimeout/narinfo1036=== PAUSE TestProxyWriteTimeout/narinfo1037=== RUN TestProxyWriteTimeout/1_GiB_nar1038=== PAUSE TestProxyWriteTimeout/1_GiB_nar1039=== RUN TestProxyWriteTimeout/10_GiB_nar1040=== PAUSE TestProxyWriteTimeout/10_GiB_nar1041=== RUN TestProxyWriteTimeout/unknown_size1042=== PAUSE TestProxyWriteTimeout/unknown_size1043=== CONT TestParseSingleRange1044=== RUN TestParseSingleRange/none1045=== PAUSE TestParseSingleRange/none1046=== RUN TestParseSingleRange/unknown_unit1047=== PAUSE TestParseSingleRange/unknown_unit1048=== RUN TestParseSingleRange/multi-range_ignored1049=== PAUSE TestParseSingleRange/multi-range_ignored1050=== RUN TestParseSingleRange/malformed_no_dash1051=== PAUSE TestParseSingleRange/malformed_no_dash1052=== RUN TestParseSingleRange/malformed_both_empty1053=== PAUSE TestParseSingleRange/malformed_both_empty1054=== RUN TestParseSingleRange/malformed_end_before_start1055=== PAUSE TestParseSingleRange/malformed_end_before_start1056=== RUN TestParseSingleRange/closed1057=== PAUSE TestParseSingleRange/closed1058=== RUN TestParseSingleRange/open-ended1059=== PAUSE TestParseSingleRange/open-ended1060=== RUN TestParseSingleRange/end_clamped_to_size1061=== PAUSE TestParseSingleRange/end_clamped_to_size1062=== RUN TestParseSingleRange/suffix1063=== PAUSE TestParseSingleRange/suffix1064=== RUN TestParseSingleRange/suffix_exceeds_size1065=== PAUSE TestParseSingleRange/suffix_exceeds_size1066=== RUN TestParseSingleRange/single_byte1067=== PAUSE TestParseSingleRange/single_byte1068=== RUN TestParseSingleRange/start_past_EOF1069=== PAUSE TestParseSingleRange/start_past_EOF1070=== RUN TestParseSingleRange/start_far_past_EOF1071=== PAUSE TestParseSingleRange/start_far_past_EOF1072=== CONT TestPresentNotReportedWhileGCDeletesClosure1073=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1074=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1075=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1076=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1077=== CONT TestPresentRefreshesOnlyStaleClosures10782026/11/06 06:52:59 INFO Completed push id=1 objects=4 duration=24.037683ms10792026/11/06 06:52:59 INFO Received push request method=POST path=/api/pushes10802026/11/06 06:52:59 INFO Received push request method=POST path=/api/pushes1081--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.97s)1082=== CONT TestLeadEndsOnShutdown10832026/11/06 06:52:59 INFO Aborted multipart uploads count=0 kept=010842026/11/06 06:52:59 WARN Force mode enabled - objects will be deleted immediately without grace period1085=== RUN TestPush_RejectsBadRequests/no_roots1086=== PAUSE TestPush_RejectsBadRequests/no_roots1087=== RUN TestPush_RejectsBadRequests/no_objects1088=== PAUSE TestPush_RejectsBadRequests/no_objects1089=== RUN TestPush_RejectsBadRequests/bad_root1090=== PAUSE TestPush_RejectsBadRequests/bad_root1091=== RUN TestPush_RejectsBadRequests/root_not_in_objects1092=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1093=== CONT TestClientMultipleUploads10942026/11/06 06:52:59 INFO Received uploads request method=POST path=/api/pending_closures10952026/11/06 06:52:59 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=010962026/11/06 06:52:59 INFO Received uploads request method=POST path=/api/pending_closures10972026/11/06 06:52:59 INFO Vacuumed table table=pending_closures10982026/11/06 06:52:59 INFO Vacuumed table table=pending_objects10992026/11/06 06:52:59 INFO Vacuumed table table=multipart_uploads11002026/11/06 06:52:59 INFO Vacuumed table table=closures11012026/11/06 06:52:59 INFO Vacuumed table table=objects11022026/11/06 06:52:59 INFO Received complete push request method=POST path=/api/pushes/2/complete11032026/11/06 06:52:59 INFO Completed push id=2 objects=4 duration=10.928481ms1104--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (1.29s)1105=== CONT TestGCTaskStore_GetEmpty1106--- PASS: TestGCTaskStore_GetEmpty (0.00s)1107=== CONT TestLeadIncumbentAnnouncesAtOnce1108--- PASS: TestPresentReportsOnlyClosureRoots (1.03s)1109=== CONT TestGCTaskStore_ConflictDifferentParams1110--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1111=== CONT TestLeadElectsOneAndHandsOver11122026/11/06 06:52:59 INFO Received push request method=POST path=/api/pushes11132026/11/06 06:53:00 INFO Received complete push request method=POST path=/api/pushes/1/complete11142026/11/06 06:53:00 INFO Completed push id=1 objects=4 duration=19.183199ms1115--- PASS: TestPush_RepeatedRootCommitsOnce (1.29s)1116=== CONT TestGCTaskStore_DeduplicateSameParams1117--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1118=== CONT TestConnectWaitsForAPeerMigration1119--- PASS: TestReadRedirectNar (1.07s)1120=== CONT TestGCTaskStore_StartNew1121--- PASS: TestGCTaskStore_StartNew (0.00s)1122=== CONT TestResolveDBConnectionString1123=== RUN TestResolveDBConnectionString/flag_wins1124=== PAUSE TestResolveDBConnectionString/flag_wins1125=== RUN TestResolveDBConnectionString/file_when_flag_empty1126=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1127=== RUN TestResolveDBConnectionString/missing_file_is_an_error1128=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1129=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1130=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1131=== RUN TestResolveDBConnectionString/nothing_configured1132=== PAUSE TestResolveDBConnectionString/nothing_configured1133=== CONT TestGCEndsOnShutdown1134=== RUN TestGCEndsOnShutdown/before_the_run1135=== PAUSE TestGCEndsOnShutdown/before_the_run1136=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1137=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1138=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1139=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1140=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1141--- PASS: TestReadRedirectKeepsNarinfoProxied (1.08s)1142=== CONT TestCommitRacingPendingCleanupKeepsObjects1143--- PASS: TestReadProxyRangeRequest (1.14s)1144=== CONT TestDeleteClosuresRacingPins1145--- PASS: TestReadRedirectUsesPublicS3URL (1.20s)1146=== CONT TestPushWaitsForSweepHoldingRow1147--- PASS: TestReadProxyDisabled (1.12s)1148=== CONT TestClientFallsBackToClosures11492026/11/06 06:53:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1150--- PASS: TestReadProxyConditionalGet (0.86s)1151=== CONT TestSweepRechecksPendingAfterLocking11522026/11/06 06:53:00 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZDYyMjZkMWEtNDhkNy00NWRjLTkzYWUtYzZlYWRiOTE0MTZhLjg2YjZkYzAwLWQ2MGMtNDdlZS1iZmNhLWJmNzcwOWY4Y2ZlNXgxNzkzOTQ3OTc5NjcyNzg0MTc1 parts=1211532026/11/06 06:53:00 INFO Received uploads request method=POST path=/api/pending_closures1154--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.65s)1155=== CONT TestClientPushesUseOnePush1156--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.94s)1157=== CONT TestGetExistingObjectsLocksRows1158--- PASS: TestReadProxyHead (1.02s)1159=== CONT TestPinProtectsFromGC1160--- PASS: TestReadProxyNarStreaming (0.95s)1161=== CONT TestRegisterCompletedObjectNeedsPendingRow1162--- PASS: TestReadProxyInvalidPath (0.98s)1163=== CONT TestClientSharedPathCommittedMidPush11642026/11/06 06:53:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11652026/11/06 06:53:00 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZDYyMjZkMWEtNDhkNy00NWRjLTkzYWUtYzZlYWRiOTE0MTZhLmU5YzI2NDFhLTFiN2ItNDQyMC1hZTVjLTk3Y2ZlZWM1ZDg0MngxNzkzOTQ3OTc5ODgyNDI2MjIy parts=1211662026/11/06 06:53:00 INFO Received uploads request method=POST path=/api/pending_closures11672026/11/06 06:53:00 INFO Received uploads request method=POST path=/api/pending_closures1168--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.91s)1169=== CONT TestSweepSkipsRowsLockedByPush1170--- PASS: TestReadProxy404 (1.10s)1171=== CONT TestFailedS3DeleteKeepsTombstone1172--- PASS: TestReadProxyContentNegotiation (0.97s)1173=== CONT TestForceGCDuringPushOffersSweptObject1174=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1175=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1176=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1177=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1178=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1179--- PASS: TestPresentRefreshesOnlyStaleClosures (0.94s)1180=== CONT TestGCSweepDeliversEachKeyOnce11812026/11/06 06:53:00 INFO lead: acquired remote=192.0.2.1:123411822026/11/06 06:53:00 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1183--- PASS: TestReadProxyNarinfo (1.02s)1184=== CONT TestTombstonedObjectOfferedWithoutWaiting11852026/11/06 06:53:00 INFO lead: acquired remote=192.0.2.1:123411862026/11/06 06:53:00 INFO lead: released remote=192.0.2.1:12341187--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.86s)1188=== CONT TestClientWithDependencies11892026/11/06 06:53:00 INFO lead: acquired remote=192.0.2.1:12341190=== NAME TestClientMultipleUploads1191 client_integration_test.go:405: Created store path 0: /build/TestClientMultipleUploads1614293714/001/store/pz3alc72j1sq36m1spcnl52nm7c817lq-test-file-0.txt11922026/11/06 06:53:01 INFO Aborted multipart uploads count=0 kept=011932026/11/06 06:53:01 INFO Received uploads request method=POST path=/api/pending_closures11942026/11/06 06:53:01 WARN Force mode enabled - objects will be deleted immediately without grace period11952026/11/06 06:53:01 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=011962026/11/06 06:53:01 INFO Vacuumed table table=pending_closures11972026/11/06 06:53:01 INFO Vacuumed table table=pending_objects11982026/11/06 06:53:01 INFO Vacuumed table table=multipart_uploads11992026/11/06 06:53:01 INFO Vacuumed table table=closures12002026/11/06 06:53:01 INFO Vacuumed table table=objects12012026/11/06 06:53:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12022026/11/06 06:53:01 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZDYyMjZkMWEtNDhkNy00NWRjLTkzYWUtYzZlYWRiOTE0MTZhLjUwYjVmYTAxLTNhZjgtNDU4MC1hMDNhLTk4YzIyZWVmNjk5NHgxNzkzOTQ3OTgwNTU2NDk4NTI0 error="Get \"http://127.0.0.1:1/bucket20/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"12032026/11/06 06:53:01 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZDYyMjZkMWEtNDhkNy00NWRjLTkzYWUtYzZlYWRiOTE0MTZhLmRiODQyMzUzLTIzNmUtNGFlMi1iYzQxLTJkODk0YTljMGY4YXgxNzkzOTQ3OTgwNTQ0Mjc5OTkw parts=1212042026/11/06 06:53:01 INFO Received cleanup request method=DELETE path=/api/pending_closures12052026/11/06 06:53:01 INFO Aborted multipart uploads count=1 kept=01206--- PASS: TestRedundantMultipartUpload (2.35s)1207=== CONT TestGCSweepSkipsPendingObjects12082026/11/06 06:53:01 INFO Aborted multipart uploads count=0 kept=01209--- PASS: TestGetExistingObjectsLocksRows (0.85s)1210=== CONT TestService_createPendingClosureHandler12112026/11/06 06:53:01 WARN Force mode enabled - objects will be deleted immediately without grace period1212--- PASS: TestCommitRacingPendingCleanupKeepsObjects (1.13s)1213=== CONT TestDeduplicatedObjectsRecordedAsPending1214=== NAME TestClientMultipleUploads1215 client_integration_test.go:405: Created store path 1: /build/TestClientMultipleUploads1614293714/001/store/sva7yc1q0lrd5s84k42bnymf9r2m5bbr-test-file-1.txt12162026/11/06 06:53:01 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=012172026/11/06 06:53:01 INFO Vacuumed table table=pending_closures12182026/11/06 06:53:01 INFO Vacuumed table table=pending_objects12192026/11/06 06:53:01 INFO Vacuumed table table=multipart_uploads12202026/11/06 06:53:01 INFO Vacuumed table table=closures1221--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.77s)1222=== CONT TestPushDedupSurvivesConcurrentGC12232026/11/06 06:53:01 INFO Vacuumed table table=objects1224--- PASS: TestSweepRechecksPendingAfterLocking (1.00s)1225=== CONT TestMetricsCommit12262026/11/06 06:53:01 INFO Aborted multipart uploads count=0 kept=012272026/11/06 06:53:01 INFO Received uploads request method=POST path=/api/pending_closures12282026/11/06 06:53:01 INFO Received uploads request method=POST path=/api/pending_closures1229--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.37s)1230=== CONT TestGCMetrics12312026/11/06 06:53:01 WARN Force mode enabled - objects will be deleted immediately without grace period12322026/11/06 06:53:01 INFO Aborted multipart uploads count=0 kept=012332026/11/06 06:53:01 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=012342026/11/06 06:53:01 INFO Vacuumed table table=pending_closures12352026/11/06 06:53:01 INFO Vacuumed table table=pending_objects12362026/11/06 06:53:01 INFO Vacuumed table table=multipart_uploads12372026/11/06 06:53:01 INFO Vacuumed table table=closures12382026/11/06 06:53:01 INFO Vacuumed table table=objects12392026/11/06 06:53:01 INFO Aborted multipart uploads count=0 kept=012402026/11/06 06:53:01 INFO Aborted multipart uploads count=0 kept=012412026/11/06 06:53:01 INFO Received uploads request method=POST path=/api/pending_closures12422026/11/06 06:53:01 WARN Force mode enabled - objects will be deleted immediately without grace period1243--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.76s)1244=== CONT TestCreatePin_ReservedPins12452026/11/06 06:53:01 INFO Received uploads request method=POST path=/api/pending_closures12462026/11/06 06:53:01 INFO Aborted multipart uploads count=0 kept=012472026/11/06 06:53:01 INFO Received uploads request method=POST path=/api/pending_closures12482026/11/06 06:53:01 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=012492026/11/06 06:53:01 INFO Vacuumed table table=pending_closures1250--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.34s)1251=== CONT TestGCBugBareHashReferences12522026/11/06 06:53:01 INFO Vacuumed table table=pending_objects12532026/11/06 06:53:01 INFO Vacuumed table table=multipart_uploads12542026/11/06 06:53:01 INFO Vacuumed table table=closures12552026/11/06 06:53:01 INFO Vacuumed table table=objects1256--- PASS: TestGCSweepDeliversEachKeyOnce (0.85s)1257=== CONT TestOrphanedObjectsGCStressTest12582026/11/06 06:53:01 INFO Received uploads request method=POST path=/api/pending_closures12592026/11/06 06:53:01 INFO Received uploads request method=POST path=/api/pending_closures12602026/11/06 06:53:01 INFO Received uploads request method=POST path=/api/pending_closures12612026/11/06 06:53:01 WARN Force mode enabled - objects will be deleted immediately without grace period1262=== NAME TestPinProtectsFromGC1263 client_integration_test.go:778: Pinned store path: /build/TestPinProtectsFromGC3257052458/001/store/hpkg353lc0s0a0cbc8688hh7b03h6dvy-pinned-file.txt1264 client_integration_test.go:779: Unpinned store path: /build/TestPinProtectsFromGC3257052458/001/store/q1281n8ww1b535mp3h617qapmj5qb9bx-unpinned-file.txt12652026/11/06 06:53:01 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=012662026/11/06 06:53:01 INFO Vacuumed table table=pending_closures12672026/11/06 06:53:01 INFO Vacuumed table table=pending_objects12682026/11/06 06:53:01 INFO Vacuumed table table=multipart_uploads12692026/11/06 06:53:01 INFO Vacuumed table table=closures12702026/11/06 06:53:01 INFO Vacuumed table table=objects1271--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.95s)1272=== CONT TestGCAdvisoryLockBlocksConcurrentRun12732026/11/06 06:53:01 WARN Force mode enabled - objects will be deleted immediately without grace period1274--- PASS: TestGCSweepSkipsPendingObjects (0.43s)1275=== CONT TestOrphanedObjectsGC1276--- PASS: TestPushWaitsForSweepHoldingRow (1.43s)1277=== CONT TestObjectStatsUpdatedOncePerCommit12782026/11/06 06:53:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41239/oidc12792026/11/06 06:53:01 INFO Received push request method=POST path=/api/pushes12802026/11/06 06:53:01 WARN Force mode enabled - objects will be deleted immediately without grace period12812026/11/06 06:53:01 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12822026/11/06 06:53:01 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1283--- PASS: TestFailedS3DeleteKeepsTombstone (1.09s)1284=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded12852026/11/06 06:53:01 INFO Received complete push request method=POST path=/api/pushes/1/complete12862026/11/06 06:53:01 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=012872026/11/06 06:53:01 INFO Vacuumed table table=pending_closures12882026/11/06 06:53:01 INFO Vacuumed table table=pending_objects12892026/11/06 06:53:01 INFO Vacuumed table table=multipart_uploads12902026/11/06 06:53:01 INFO Vacuumed table table=closures12912026/11/06 06:53:01 INFO Vacuumed table table=objects1292--- PASS: TestSweepSkipsRowsLockedByPush (1.13s)1293=== CONT TestService_verifyS3Integrity12942026/11/06 06:53:01 INFO lead: released remote=192.0.2.1:12341295--- PASS: TestLeadEndsOnShutdown (1.95s)1296=== CONT TestObjectStatsTrigger12972026/11/06 06:53:01 INFO Completed push id=1 objects=4 duration=62.863704ms12982026/11/06 06:53:01 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12992026/11/06 06:53:01 INFO Completed upload id=2 objects=2 duration=3.108129ms1300--- PASS: TestMetricsCommit (0.54s)1301=== CONT TestPendingCleanupUsesOneCutoff1302=== NAME TestClientMultipleUploads1303 client_integration_test.go:405: Created store path 2: /build/TestClientMultipleUploads1614293714/001/store/2y23gr1q1fc1nlhy74vp8v2q64dmwnbb-test-file-2.txt13042026/11/06 06:53:01 INFO Aborted multipart uploads count=0 kept=013052026/11/06 06:53:01 INFO Received uploads request method=POST path=/api/pending_closures1306=== NAME TestClientWithDependencies1307 client_integration_test.go:660: Built derivation: /build/TestClientWithDependencies201785403/001/store/8gmh2r5cfmli66zlq7r7qb5qvjhplxsc-test-script13082026/11/06 06:53:01 WARN Force mode enabled - objects will be deleted immediately without grace period13092026/11/06 06:53:01 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=013102026/11/06 06:53:01 INFO Vacuumed table table=pending_closures13112026/11/06 06:53:01 INFO Vacuumed table table=pending_objects13122026/11/06 06:53:01 INFO Vacuumed table table=multipart_uploads13132026/11/06 06:53:01 INFO Vacuumed table table=closures13142026/11/06 06:53:01 INFO Vacuumed table table=objects1315--- PASS: TestGCMetrics (0.54s)1316=== CONT TestServerTLSConfig1317=== RUN TestServerTLSConfig/no_client_CA1318=== PAUSE TestServerTLSConfig/no_client_CA1319=== RUN TestServerTLSConfig/missing_CA_file1320=== PAUSE TestServerTLSConfig/missing_CA_file1321=== RUN TestServerTLSConfig/not_a_PEM_file1322=== PAUSE TestServerTLSConfig/not_a_PEM_file1323=== CONT TestService_NativeMTLS1324--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.28s)1325=== CONT TestMultipartCleanup1326=== NAME TestClientWithDependencies1327 client_integration_test.go:662: Found 1 dependencies (including self)13282026/11/06 06:53:02 INFO Received push request method=POST path=/api/pushes13292026/11/06 06:53:02 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"1330--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.44s)1331=== CONT TestService_ReadScope_PublicByDefault13322026/11/06 06:53:02 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13332026/11/06 06:53:02 INFO Uploading lqjap4f7x8fdh2vik88df8vg8gij9y1i-b (216B)13342026/11/06 06:53:02 INFO Uploading gimr204wyz1g5da0sbdpsh2hbzsj78mz-shared-dep (136B)13352026/11/06 06:53:02 INFO lead: released remote=192.0.2.1:123413362026/11/06 06:53:02 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13372026/11/06 06:53:02 WARN Refused reserved pin name=worker-x86_64-linux13382026/11/06 06:53:02 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13392026/11/06 06:53:02 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13402026/11/06 06:53:02 WARN Failed to register uploaded object key=jrrndh1w6qxsvlw2xk09his9n9psr2bw.ls error="server returned 404: 404 page not found\n"13412026/11/06 06:53:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13422026/11/06 06:53:02 WARN Failed to register uploaded object key=nar/1rxg7vby3q6bnv3xlrsrsnnnfxbgq84r9y0y2574nnqr8aanlzp1.nar.zst error="server returned 404: 404 page not found\n"13432026/11/06 06:53:02 INFO Received create pin request method=POST path=/api/pins/my-app13442026/11/06 06:53:02 WARN Failed to register uploaded object key=lqjap4f7x8fdh2vik88df8vg8gij9y1i.ls error="server returned 404: 404 page not found\n"13452026/11/06 06:53:02 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13462026/11/06 06:53:02 WARN Failed to register uploaded object key=gimr204wyz1g5da0sbdpsh2hbzsj78mz.ls error="server returned 404: 404 page not found\n"13472026/11/06 06:53:02 INFO Signed narinfos id=1 count=313482026/11/06 06:53:02 INFO Uploading 3 narinfos1349--- PASS: TestCreatePin_ReservedPins (0.58s)1350=== CONT TestService_ReadAuthMiddleware13512026/11/06 06:53:02 INFO lead: acquired remote=192.0.2.1:123413522026/11/06 06:53:02 WARN Failed to register uploaded object key=jrrndh1w6qxsvlw2xk09his9n9psr2bw.narinfo error="server returned 404: 404 page not found\n"13532026/11/06 06:53:02 INFO Received complete push request method=POST path=/api/pushes/1/complete13542026/11/06 06:53:02 WARN Failed to register uploaded object key=gimr204wyz1g5da0sbdpsh2hbzsj78mz.narinfo error="server returned 404: 404 page not found\n"13552026/11/06 06:53:02 WARN Failed to register uploaded object key=lqjap4f7x8fdh2vik88df8vg8gij9y1i.narinfo error="server returned 404: 404 page not found\n"13562026/11/06 06:53:02 INFO Completed push id=1 objects=8 duration=17.18906ms13572026/11/06 06:53:02 INFO Upload complete. (162ms)1358=== NAME TestClientPushesUseOnePush1359 client_pushes_test.go:97: Retrieved narinfo from S3:1360 StorePath: /build/TestClientPushesUseOnePush1691339805/001/store/gimr204wyz1g5da0sbdpsh2hbzsj78mz-shared-dep1361 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1362 Compression: zstd1363 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821364 NarSize: 1361365 References: 1366 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1367 client_pushes_test.go:97: Retrieved narinfo from S3:1368 StorePath: /build/TestClientPushesUseOnePush1691339805/001/store/jrrndh1w6qxsvlw2xk09his9n9psr2bw-a1369 URL: nar/1rxg7vby3q6bnv3xlrsrsnnnfxbgq84r9y0y2574nnqr8aanlzp1.nar.zst1370 Compression: zstd1371 NarHash: sha256:1rxg7vby3q6bnv3xlrsrsnnnfxbgq84r9y0y2574nnqr8aanlzp11372 NarSize: 2161373 References: /build/TestClientPushesUseOnePush1691339805/001/store/gimr204wyz1g5da0sbdpsh2hbzsj78mz-shared-dep1374 CA: text:sha256:1gxard3gspial3xs0c2p4hq0xm7zf70sbijh3f6d9izjgbxk4pln1375 client_pushes_test.go:97: Retrieved narinfo from S3:1376 StorePath: /build/TestClientPushesUseOnePush1691339805/001/store/lqjap4f7x8fdh2vik88df8vg8gij9y1i-b1377 URL: nar/1rxg7vby3q6bnv3xlrsrsnnnfxbgq84r9y0y2574nnqr8aanlzp1.nar.zst1378 Compression: zstd1379 NarHash: sha256:1rxg7vby3q6bnv3xlrsrsnnnfxbgq84r9y0y2574nnqr8aanlzp11380 NarSize: 2161381 References: /build/TestClientPushesUseOnePush1691339805/001/store/gimr204wyz1g5da0sbdpsh2hbzsj78mz-shared-dep1382 CA: text:sha256:1gxard3gspial3xs0c2p4hq0xm7zf70sbijh3f6d9izjgbxk4pln1383--- PASS: TestClientPushesUseOnePush (1.85s)1384=== CONT TestService_RequireScope_OIDC1385--- PASS: TestObjectStatsUpdatedOncePerCommit (0.62s)1386=== CONT TestClientIntegration13872026/11/06 06:53:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13882026/11/06 06:53:02 INFO Received uploads request method=POST path=/api/pending_closures13892026/11/06 06:53:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40255/oidc13902026/11/06 06:53:02 INFO Received uploads request method=POST path=/api/pending_closures13912026/11/06 06:53:02 INFO Received cleanup request method=DELETE path=/api/pending_closures13922026/11/06 06:53:02 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZDYyMjZkMWEtNDhkNy00NWRjLTkzYWUtYzZlYWRiOTE0MTZhLmE0YzVhYmUzLWE0MmEtNDk1Ny1iMTVjLTUwZTk5OWY0ZWZjYXgxNzkzOTQ3OTgxNTU4MjMzMzEw parts=1013932026/11/06 06:53:02 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13942026/11/06 06:53:02 INFO Completed upload id=1 objects=2 duration=5.292269ms13952026/11/06 06:53:02 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013962026/11/06 06:53:02 INFO Received uploads request method=POST path=/api/pending_closures13972026/11/06 06:53:02 INFO Starting cleanup of old closures method=DELETE path=/api/closures13982026/11/06 06:53:02 INFO Aborted multipart uploads count=0 kept=01399--- PASS: TestObjectStatsTrigger (0.73s)1400=== CONT TestService_AuthMiddleware_OIDC14012026/11/06 06:53:02 WARN mTLS auth: subject not in bound subjects subject="CN=reader"14022026/11/06 06:53:02 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1403--- PASS: TestService_NativeMTLS (0.60s)1404=== CONT TestClientErrorHandling1405=== RUN TestClientErrorHandling/InvalidStorePath1406=== PAUSE TestClientErrorHandling/InvalidStorePath1407=== RUN TestClientErrorHandling/InvalidAuthToken1408=== PAUSE TestClientErrorHandling/InvalidAuthToken1409=== RUN TestClientErrorHandling/ServerNotAvailable1410=== PAUSE TestClientErrorHandling/ServerNotAvailable1411=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1412--- PASS: TestService_ReadScope_PublicByDefault (0.60s)1413=== CONT TestService_AuthMiddleware_MTLSProxyHeader14142026/11/06 06:53:02 INFO Received uploads request method=POST path=/api/pending_closures14152026/11/06 06:53:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44905/oidc14162026/11/06 06:53:02 INFO Aborted multipart uploads count=0 kept=014172026/11/06 06:53:02 INFO Received uploads request method=POST path=/api/pending_closures1418--- PASS: TestService_ReadAuthMiddleware (0.74s)1419=== CONT TestClientCADerivations14202026/11/06 06:53:02 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=014212026/11/06 06:53:02 INFO Vacuumed table table=pending_closures14222026/11/06 06:53:02 INFO Received cleanup request method=DELETE path=/api/pending_closures14232026/11/06 06:53:02 INFO Vacuumed table table=pending_objects14242026/11/06 06:53:02 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket78/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""14252026/11/06 06:53:02 INFO Aborted multipart uploads count=0 kept=114262026/11/06 06:53:02 INFO Vacuumed table table=multipart_uploads14272026/11/06 06:53:02 INFO Vacuumed table table=closures14282026/11/06 06:53:02 INFO Vacuumed table table=objects14292026/11/06 06:53:02 INFO Received cleanup request method=DELETE path=/api/pending_closures14302026/11/06 06:53:02 INFO Aborted multipart uploads count=0 kept=014312026/11/06 06:53:02 WARN Force mode enabled - objects will be deleted immediately without grace period14322026/11/06 06:53:02 INFO Aborted multipart uploads count=1 kept=01433--- PASS: TestGCBugBareHashReferences (1.52s)1434=== CONT TestCacheStatsHandler14352026/11/06 06:53:03 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=014362026/11/06 06:53:03 INFO Vacuumed table table=pending_closures14372026/11/06 06:53:03 INFO Vacuumed table table=pending_objects14382026/11/06 06:53:03 INFO Vacuumed table table=multipart_uploads14392026/11/06 06:53:03 INFO Vacuumed table table=closures14402026/11/06 06:53:03 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=014412026/11/06 06:53:03 INFO Vacuumed table table=objects14422026/11/06 06:53:03 INFO Vacuumed table table=pending_closures14432026/11/06 06:53:03 INFO Received push request method=POST path=/api/pushes14442026/11/06 06:53:03 INFO Received push request method=POST path=/api/pushes14452026/11/06 06:53:03 INFO Vacuumed table table=pending_objects14462026/11/06 06:53:03 INFO Received uploads request method=POST path=/api/pending_closures14472026/11/06 06:53:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14482026/11/06 06:53:03 INFO Uploading hpkg353lc0s0a0cbc8688hh7b03h6dvy-pinned-file.txt (128B)14492026/11/06 06:53:03 INFO Vacuumed table table=multipart_uploads14502026/11/06 06:53:03 INFO Vacuumed table table=closures1451--- PASS: TestPushDedupSurvivesConcurrentGC (1.83s)1452=== CONT TestCacheConfigHandler1453=== RUN TestCacheConfigHandler/full_config,_no_issuer1454=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1455=== RUN TestCacheConfigHandler/no_cache_url_configured1456=== PAUSE TestCacheConfigHandler/no_cache_url_configured1457=== RUN TestCacheConfigHandler/no_signing_keys1458=== PAUSE TestCacheConfigHandler/no_signing_keys1459=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1460=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1461=== CONT TestService_readinessHandler1462=== NAME TestClientIntegration1463 client_integration_test.go:291: Created store path: /build/TestClientIntegration3556400557/002/store/7qyyl0ykj6rzy0hr0qci0kdri4r1f9cq-test-file.txt1464--- PASS: TestMultipartCleanup (1.09s)1465=== CONT TestCreatePendingClosureRejectsOversizedNAR14662026/11/06 06:53:03 INFO Received uploads request method=POST path=/api/pending_closures1467--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1468=== CONT TestCacheConfigHandlerMaxNarSize14692026/11/06 06:53:03 INFO Vacuumed table table=objects1470--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1471=== CONT TestGCTaskStore_Fail1472--- PASS: TestGCTaskStore_Fail (0.00s)1473=== CONT TestGenerateLandingPage14742026/11/06 06:53:03 WARN Failed to register uploaded object key=hpkg353lc0s0a0cbc8688hh7b03h6dvy.ls error="server returned 404: 404 page not found\n"14752026/11/06 06:53:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14762026/11/06 06:53:03 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14772026/11/06 06:53:03 INFO Signed narinfos id=1 count=114782026/11/06 06:53:03 INFO Uploading 1 narinfos1479--- PASS: TestGenerateLandingPage (0.01s)14802026/11/06 06:53:03 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001481=== CONT TestService_healthCheckHandler1482--- PASS: TestService_createPendingClosureHandler (1.91s)1483=== CONT TestMetricsInventory14842026/11/06 06:53:03 INFO Received complete push request method=POST path=/api/pushes/1/complete14852026/11/06 06:53:03 WARN Failed to register uploaded object key=hpkg353lc0s0a0cbc8688hh7b03h6dvy.narinfo error="server returned 404: 404 page not found\n"14862026/11/06 06:53:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14872026/11/06 06:53:03 INFO Uploading 8gmh2r5cfmli66zlq7r7qb5qvjhplxsc-test-script (136B)14882026/11/06 06:53:03 INFO Completed push id=1 objects=3 duration=11.721869ms14892026/11/06 06:53:03 INFO Received uploads request method=POST path=/api/pending_closures14902026/11/06 06:53:03 INFO Upload complete. (942ms)14912026/11/06 06:53:03 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14922026/11/06 06:53:03 INFO Uploading ml85pziqp734msx1y7i9ck3k60n6hbxv-a (216B)14932026/11/06 06:53:03 INFO Uploading s1px78zkb0mdy355jdgmlyqz308fawfa-shared-dep (136B)14942026/11/06 06:53:03 WARN Failed to register uploaded object key=8gmh2r5cfmli66zlq7r7qb5qvjhplxsc.ls error="server returned 404: 404 page not found\n"14952026/11/06 06:53:03 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"14962026/11/06 06:53:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14972026/11/06 06:53:03 WARN Failed to register uploaded object key=log/80460h5l11qi91iya90z1ffd2ipv1izk-test-script.drv error="server returned 404: 404 page not found\n"14982026/11/06 06:53:03 INFO Signed narinfos id=1 count=114992026/11/06 06:53:03 INFO Uploading 1 narinfos15002026/11/06 06:53:03 WARN Failed to register uploaded object key=ml85pziqp734msx1y7i9ck3k60n6hbxv.ls error="server returned 404: 404 page not found\n"15012026/11/06 06:53:03 WARN Failed to register uploaded object key=55699g68aw2vqdhrhkc5jmwgywd0f10q.ls error="server returned 404: 404 page not found\n"15022026/11/06 06:53:03 WARN Failed to register uploaded object key=s1px78zkb0mdy355jdgmlyqz308fawfa.ls error="server returned 404: 404 page not found\n"15032026/11/06 06:53:03 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15042026/11/06 06:53:03 INFO Received complete push request method=POST path=/api/pushes/1/complete15052026/11/06 06:53:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15062026/11/06 06:53:03 WARN Failed to register uploaded object key=8gmh2r5cfmli66zlq7r7qb5qvjhplxsc.narinfo error="server returned 404: 404 page not found\n"15072026/11/06 06:53:03 WARN Failed to register uploaded object key=nar/17dyf606wgzw6x95qpxqczvpy497hv1k3pd3fvd6fwk9h2yjnzwp.nar.zst error="server returned 404: 404 page not found\n"15082026/11/06 06:53:03 INFO Signed narinfos id=2 count=215092026/11/06 06:53:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15102026/11/06 06:53:03 INFO Signed narinfos id=1 count=215112026/11/06 06:53:03 INFO Uploading 4 narinfos15122026/11/06 06:53:03 WARN Failed to register uploaded object key=ml85pziqp734msx1y7i9ck3k60n6hbxv.narinfo error="server returned 404: 404 page not found\n"15132026/11/06 06:53:03 WARN Failed to register uploaded object key=55699g68aw2vqdhrhkc5jmwgywd0f10q.narinfo error="server returned 404: 404 page not found\n"15142026/11/06 06:53:03 WARN Failed to register uploaded object key=s1px78zkb0mdy355jdgmlyqz308fawfa.narinfo error="server returned 404: 404 page not found\n"15152026/11/06 06:53:03 INFO Completed push id=1 objects=4 duration=9.71129ms15162026/11/06 06:53:03 INFO Upload complete. (1.081s)15172026/11/06 06:53:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15182026/11/06 06:53:03 WARN Failed to register uploaded object key=s1px78zkb0mdy355jdgmlyqz308fawfa.narinfo error="server returned 404: 404 page not found\n"15192026/11/06 06:53:03 INFO Completed upload id=1 objects=6 duration=9.68733ms15202026/11/06 06:53:03 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1521=== NAME TestClientWithDependencies1522 client_integration_test.go:664: Skipping nix copy test - isolated store (/build/TestClientWithDependencies201785403/001/store) requires matching store prefix15232026/11/06 06:53:03 INFO Completed upload id=2 objects=6 duration=2.924507ms15242026/11/06 06:53:03 INFO Upload complete. (567ms)1525--- PASS: TestClientWithDependencies (2.38s)1526=== CONT TestGracefulShutdownDrainsInflight1527=== NAME TestClientFallsBackToClosures1528 client_pushes_test.go:112: Retrieved narinfo from S3:1529 StorePath: /build/TestClientFallsBackToClosures4286577524/001/store/s1px78zkb0mdy355jdgmlyqz308fawfa-shared-dep1530 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1531 Compression: zstd1532 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821533 NarSize: 1361534 References: 1535 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n15362026/11/06 06:53:03 INFO Starting HTTP server address=127.0.0.1:4390115372026/11/06 06:53:03 INFO Shutdown signal received, draining in-flight requests timeout=10s1538 client_pushes_test.go:112: Retrieved narinfo from S3:1539 StorePath: /build/TestClientFallsBackToClosures4286577524/001/store/ml85pziqp734msx1y7i9ck3k60n6hbxv-a1540 URL: nar/17dyf606wgzw6x95qpxqczvpy497hv1k3pd3fvd6fwk9h2yjnzwp.nar.zst1541 Compression: zstd1542 NarHash: sha256:17dyf606wgzw6x95qpxqczvpy497hv1k3pd3fvd6fwk9h2yjnzwp1543 NarSize: 2161544 References: /build/TestClientFallsBackToClosures4286577524/001/store/s1px78zkb0mdy355jdgmlyqz308fawfa-shared-dep1545 CA: text:sha256:0hysb9jjjyf6ggcjninijay9qikbj11whwvhk1vnxp7k82ic87fp1546 client_pushes_test.go:112: Retrieved narinfo from S3:1547 StorePath: /build/TestClientFallsBackToClosures4286577524/001/store/55699g68aw2vqdhrhkc5jmwgywd0f10q-b1548 URL: nar/17dyf606wgzw6x95qpxqczvpy497hv1k3pd3fvd6fwk9h2yjnzwp.nar.zst1549 Compression: zstd1550 NarHash: sha256:17dyf606wgzw6x95qpxqczvpy497hv1k3pd3fvd6fwk9h2yjnzwp1551 NarSize: 2161552 References: /build/TestClientFallsBackToClosures4286577524/001/store/s1px78zkb0mdy355jdgmlyqz308fawfa-shared-dep1553 CA: text:sha256:0hysb9jjjyf6ggcjninijay9qikbj11whwvhk1vnxp7k82ic87fp1554--- PASS: TestClientFallsBackToClosures (2.98s)1555=== CONT TestNARDeduplicationMetadataUploadBug1556=== NAME TestOrphanedObjectsGC1557 orphaned_objects_gc_test.go:287: GC Test Summary:1558 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1559 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1560 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1561 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1562 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1563--- PASS: TestOrphanedObjectsGC (1.60s)1564=== CONT TestGCTaskStore_CompletedAllowsNewTask1565--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1566=== CONT TestGCTaskStore_PhaseUpdates1567--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1568=== CONT TestPendingClosureWriteTimeout/empty1569=== CONT TestPendingClosureWriteTimeout/670k_objects1570=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline15712026/11/06 06:53:03 INFO lead: released remote=192.0.2.1:12341572--- PASS: TestLeadElectsOneAndHandsOver (3.26s)1573=== CONT TestPendingClosureWriteTimeout/400_objects1574=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info15752026/11/06 06:53:03 INFO Received uploads request method=POST path=/1576=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15772026/11/06 06:53:03 INFO Received complete multipart upload request method=POST path=/1578=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key15792026/11/06 06:53:03 INFO Received request for more parts method=POST path=/1580=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal15812026/11/06 06:53:03 INFO Received uploads request method=POST path=/1582--- PASS: TestUploadHandlersRejectInvalidKeys (0.23s)1583 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1584 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1585 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1586 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1587=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed1588=== RUN TestService_RequireScope_OIDC/builder_may_write1589=== PAUSE TestService_RequireScope_OIDC/builder_may_write1590=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1591=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1592=== RUN TestService_RequireScope_OIDC/ops_may_admin1593=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1594=== RUN TestService_RequireScope_OIDC/ops_may_not_write1595=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1596=== RUN TestService_RequireScope_OIDC/reader_may_not_write1597=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1598=== RUN TestService_RequireScope_OIDC/static_token_may_admin1599=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1600=== RUN TestService_RequireScope_OIDC/static_token_may_write1601=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1602=== RUN TestService_RequireScope_OIDC/reader_may_read1603=== PAUSE TestService_RequireScope_OIDC/reader_may_read1604=== RUN TestService_RequireScope_OIDC/writer_implies_read1605=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1606=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1607=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1608=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1609=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1610=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1611=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1612=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1613=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1614=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1615=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1616=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed1617--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1618=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed1619=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1620=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1621=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1622=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1623=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1624=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1625=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1626=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1627=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost16282026/11/06 06:53:03 INFO Received uploads request method=POST path=/api/pending_closures16292026/11/06 06:53:03 INFO Received push request method=POST path=/api/pushes16302026/11/06 06:53:03 INFO Received push request method=POST path=/api/pushes16312026/11/06 06:53:03 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)16322026/11/06 06:53:03 INFO Uploading 01vdpq520h5bpb67zqafl65wdh5bk1sj-shared-dep (136B)16332026/11/06 06:53:03 INFO Uploading 9778njmrz8w3kw34g9sjaj9i79afv622-top (224B)1634=== NAME TestClientCADerivations1635 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3639602922/001/store/f6wbb61jzgn8wsq552s4p6vs9jalq1a2-ca-test16362026/11/06 06:53:03 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)16372026/11/06 06:53:03 INFO Uploading pz3alc72j1sq36m1spcnl52nm7c817lq-test-file-0.txt (160B)16382026/11/06 06:53:03 INFO Uploading sva7yc1q0lrd5s84k42bnymf9r2m5bbr-test-file-1.txt (160B)16392026/11/06 06:53:03 INFO Uploading 2y23gr1q1fc1nlhy74vp8v2q64dmwnbb-test-file-2.txt (160B)16402026/11/06 06:53:03 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16412026/11/06 06:53:03 WARN mTLS auth: bound subjects configured but subject DN unavailable16422026/11/06 06:53:03 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1643--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.78s)1644=== CONT TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed16452026/11/06 06:53:03 WARN Failed to register uploaded object key=nar/1viy5q0i0kdh5glhy8sn5rcynmwyzj4hxsqi9l278c29z9q5a94k.nar.zst error="server returned 404: 404 page not found\n"16462026/11/06 06:53:03 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16472026/11/06 06:53:03 WARN Failed to register uploaded object key=9778njmrz8w3kw34g9sjaj9i79afv622.ls error="server returned 404: 404 page not found\n"16482026/11/06 06:53:03 WARN Failed to register uploaded object key=01vdpq520h5bpb67zqafl65wdh5bk1sj.ls error="server returned 404: 404 page not found\n"16492026/11/06 06:53:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16502026/11/06 06:53:03 INFO Signed narinfos id=1 count=216512026/11/06 06:53:03 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"16522026/11/06 06:53:03 INFO Uploading 2 narinfos16532026/11/06 06:53:03 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"16542026/11/06 06:53:03 WARN Failed to register uploaded object key=sva7yc1q0lrd5s84k42bnymf9r2m5bbr.ls error="server returned 404: 404 page not found\n"16552026/11/06 06:53:03 WARN Failed to register uploaded object key=pz3alc72j1sq36m1spcnl52nm7c817lq.ls error="server returned 404: 404 page not found\n"16562026/11/06 06:53:03 WARN Failed to register uploaded object key=2y23gr1q1fc1nlhy74vp8v2q64dmwnbb.ls error="server returned 404: 404 page not found\n"16572026/11/06 06:53:03 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"16582026/11/06 06:53:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16592026/11/06 06:53:03 INFO Signed narinfos id=1 count=316602026/11/06 06:53:03 INFO Uploading 3 narinfos16612026/11/06 06:53:03 WARN Failed to register uploaded object key=9778njmrz8w3kw34g9sjaj9i79afv622.narinfo error="server returned 404: 404 page not found\n"16622026/11/06 06:53:03 INFO Received complete push request method=POST path=/api/pushes/1/complete16632026/11/06 06:53:03 WARN Failed to register uploaded object key=01vdpq520h5bpb67zqafl65wdh5bk1sj.narinfo error="server returned 404: 404 page not found\n"16642026/11/06 06:53:03 WARN Failed to register uploaded object key=sva7yc1q0lrd5s84k42bnymf9r2m5bbr.narinfo error="server returned 404: 404 page not found\n"16652026/11/06 06:53:03 WARN Failed to register uploaded object key=pz3alc72j1sq36m1spcnl52nm7c817lq.narinfo error="server returned 404: 404 page not found\n"16662026/11/06 06:53:03 INFO Received complete push request method=POST path=/api/pushes/1/complete16672026/11/06 06:53:03 WARN Failed to register uploaded object key=2y23gr1q1fc1nlhy74vp8v2q64dmwnbb.narinfo error="server returned 404: 404 page not found\n"16682026/11/06 06:53:03 INFO Completed push id=1 objects=6 duration=12.761518ms16692026/11/06 06:53:03 INFO Upload complete. (305ms)1670=== NAME TestClientSharedPathCommittedMidPush1671 client_integration_test.go:727: Retrieved narinfo from S3:1672 StorePath: /build/TestClientSharedPathCommittedMidPush2622923996/001/store/01vdpq520h5bpb67zqafl65wdh5bk1sj-shared-dep1673 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1674 Compression: zstd1675 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821676 NarSize: 1361677 References: 1678 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n16792026/11/06 06:53:03 INFO Completed push id=1 objects=9 duration=11.649509ms16802026/11/06 06:53:03 INFO Upload complete. (1.387s)1681=== NAME TestClientMultipleUploads1682 client_integration_test.go:416: Uploaded 3 paths in 1.460141765s1683=== NAME TestClientSharedPathCommittedMidPush1684 client_integration_test.go:727: Retrieved narinfo from S3:1685 StorePath: /build/TestClientSharedPathCommittedMidPush2622923996/001/store/9778njmrz8w3kw34g9sjaj9i79afv622-top1686 URL: nar/1viy5q0i0kdh5glhy8sn5rcynmwyzj4hxsqi9l278c29z9q5a94k.nar.zst1687 Compression: zstd1688 NarHash: sha256:1viy5q0i0kdh5glhy8sn5rcynmwyzj4hxsqi9l278c29z9q5a94k1689 NarSize: 2241690 References: /build/TestClientSharedPathCommittedMidPush2622923996/001/store/01vdpq520h5bpb67zqafl65wdh5bk1sj-shared-dep1691 CA: text:sha256:1m3f45pnz09x0251majkhnvlbs4m187lmrk6s6qrhgrid1875f601692--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.77s)1693=== CONT TestIsValidUploadKey/narinfo1694=== CONT TestIsValidUploadKey/realisation_plus_in_output1695=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1696=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1697=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1698=== CONT TestIsValidUploadKey/index.html1699=== CONT TestIsValidUploadKey/traversal1700=== CONT TestIsValidUploadKey/nix-cache-info1701=== CONT TestIsValidUploadKey/build_log_home-manager_file1702=== CONT TestIsValidUploadKey/realisation1703=== CONT TestIsValidUploadKey/build_log_equals1704=== CONT TestIsValidUploadKey/build_log_question_mark1705=== CONT TestIsValidUploadKey/empty_key1706=== CONT TestIsValidUploadKey/unknown_type1707=== CONT TestIsValidUploadKey/absolute1708=== CONT TestIsValidUploadKey/traversal_nar1709=== CONT TestIsValidUploadKey/nar_plain1710=== CONT TestIsValidUploadKey/build_log1711=== CONT TestIsValidUploadKey/listing1712=== CONT TestIsValidUploadKey/nar_xz1713=== CONT TestIsValidUploadKey/nar_zst1714=== CONT TestIsValidUploadKey/build_log_plus_in_name1715--- PASS: TestIsValidUploadKey (0.15s)1716 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1717 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1718 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1719 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1720 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1721 --- PASS: TestIsValidUploadKey/index.html (0.00s)1722 --- PASS: TestIsValidUploadKey/traversal (0.00s)1723 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1724 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1725 --- PASS: TestIsValidUploadKey/realisation (0.00s)1726 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1727 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1728 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1729 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1730 --- PASS: TestIsValidUploadKey/absolute (0.00s)1731 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1732 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1733 --- PASS: TestIsValidUploadKey/build_log (0.00s)1734 --- PASS: TestIsValidUploadKey/listing (0.00s)1735 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1736 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1737 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1738=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17392026/11/06 06:53:03 INFO Received uploads request method=POST path=/1740--- PASS: TestClientSharedPathCommittedMidPush (2.89s)1741=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17422026/11/06 06:53:03 INFO Received request for more parts method=POST path=/1743--- PASS: TestClientMultipleUploads (3.55s)1744=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17452026/11/06 06:53:03 INFO Received complete multipart upload request method=POST path=/17462026/11/06 06:53:03 INFO Received push request method=POST path=/api/pushes17472026/11/06 06:53:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17482026/11/06 06:53:03 INFO Uploading q1281n8ww1b535mp3h617qapmj5qb9bx-unpinned-file.txt (128B)17492026/11/06 06:53:03 WARN Failed to register uploaded object key=q1281n8ww1b535mp3h617qapmj5qb9bx.ls error="server returned 404: 404 page not found\n"17502026/11/06 06:53:03 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17512026/11/06 06:53:03 INFO Signed narinfos id=2 count=117522026/11/06 06:53:03 INFO Uploading 1 narinfos17532026/11/06 06:53:03 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"17542026/11/06 06:53:03 INFO Received push request method=POST path=/api/pushes17552026/11/06 06:53:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17562026/11/06 06:53:03 INFO Uploading 7qyyl0ykj6rzy0hr0qci0kdri4r1f9cq-test-file.txt (152B)17572026/11/06 06:53:03 INFO Received complete push request method=POST path=/api/pushes/2/complete17582026/11/06 06:53:03 WARN Failed to register uploaded object key=q1281n8ww1b535mp3h617qapmj5qb9bx.narinfo error="server returned 404: 404 page not found\n"17592026/11/06 06:53:03 INFO Completed push id=2 objects=3 duration=3.626294ms17602026/11/06 06:53:03 INFO Upload complete. (113ms)17612026/11/06 06:53:03 WARN Failed to register uploaded object key=7qyyl0ykj6rzy0hr0qci0kdri4r1f9cq.ls error="server returned 404: 404 page not found\n"17622026/11/06 06:53:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17632026/11/06 06:53:03 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17642026/11/06 06:53:03 INFO Signed narinfos id=1 count=117652026/11/06 06:53:03 INFO Uploading 1 narinfos1766--- PASS: TestCacheStatsHandler (0.38s)1767=== CONT TestIsValidCachePath/narinfo17682026/11/06 06:53:03 INFO Received complete push request method=POST path=/api/pushes/1/complete1769=== CONT TestProxyWriteTimeout/narinfo1770=== CONT TestIsValidCachePath/short_hash1771=== CONT TestIsValidCachePath/wrong_extension1772=== CONT TestIsValidCachePath/leading_slash1773=== CONT TestIsValidCachePath/empty1774=== CONT TestIsValidCachePath/random_path1775=== CONT TestIsValidCachePath/invalid_char_u1776=== CONT TestIsValidCachePath/invalid_char_e1777=== CONT TestIsValidCachePath/traversal_in_middle1778=== CONT TestIsValidCachePath/traversal_parent1779=== CONT TestIsValidCachePath/index.html1780=== CONT TestIsValidCachePath/nix-cache-info1781=== CONT TestIsValidCachePath/realisation1782=== CONT TestIsValidCachePath/log1783=== CONT TestIsValidCachePath/ls1784=== CONT TestIsValidCachePath/nar_uncompressed1785=== CONT TestIsValidCachePath/nar_bz21786=== CONT TestIsValidCachePath/nar_xz1787=== CONT TestIsValidCachePath/nar_zst1788=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1789=== CONT TestParseSingleRange/none17902026/11/06 06:53:03 WARN Failed to register uploaded object key=7qyyl0ykj6rzy0hr0qci0kdri4r1f9cq.narinfo error="server returned 404: 404 page not found\n"1791--- PASS: TestIsValidCachePath (0.00s)1792 --- PASS: TestIsValidCachePath/narinfo (0.00s)1793 --- PASS: TestIsValidCachePath/short_hash (0.00s)1794 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1795 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1796 --- PASS: TestIsValidCachePath/empty (0.00s)1797 --- PASS: TestIsValidCachePath/random_path (0.00s)1798 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1799 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1800 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1801 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1802 --- PASS: TestIsValidCachePath/index.html (0.00s)1803 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1804 --- PASS: TestIsValidCachePath/realisation (0.00s)1805 --- PASS: TestIsValidCachePath/log (0.00s)1806 --- PASS: TestIsValidCachePath/ls (0.00s)1807 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1808 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1809 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1810 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1811 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1812=== CONT TestProxyWriteTimeout/unknown_size1813=== CONT TestProxyWriteTimeout/10_GiB_nar1814=== CONT TestProxyWriteTimeout/1_GiB_nar1815--- PASS: TestProxyWriteTimeout (0.00s)1816 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1817 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1818 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1819 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1820=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale18212026/11/06 06:53:03 INFO Completed push id=1 objects=3 duration=6.831424ms18222026/11/06 06:53:03 INFO Upload complete. (118ms)1823=== CONT TestParseSingleRange/start_far_past_EOF1824=== CONT TestParseSingleRange/start_past_EOF1825=== CONT TestParseSingleRange/single_byte1826=== CONT TestParseSingleRange/suffix_exceeds_size1827=== CONT TestParseSingleRange/suffix1828=== CONT TestParseSingleRange/end_clamped_to_size1829=== CONT TestParseSingleRange/open-ended1830=== CONT TestParseSingleRange/closed1831=== CONT TestParseSingleRange/malformed_end_before_start1832=== CONT TestParseSingleRange/malformed_both_empty1833=== CONT TestParseSingleRange/malformed_no_dash1834=== CONT TestParseSingleRange/multi-range_ignored1835=== CONT TestParseSingleRange/unknown_unit1836--- PASS: TestParseSingleRange (0.00s)1837 --- PASS: TestParseSingleRange/none (0.00s)1838 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1839 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1840 --- PASS: TestParseSingleRange/single_byte (0.00s)1841 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1842 --- PASS: TestParseSingleRange/suffix (0.00s)1843 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1844 --- PASS: TestParseSingleRange/open-ended (0.00s)1845 --- PASS: TestParseSingleRange/closed (0.00s)1846 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1847 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1848 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1849 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1850 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1851=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh18522026/11/06 06:53:03 WARN readiness check failed error="closed pool"1853--- PASS: TestService_readinessHandler (0.37s)1854=== CONT TestPush_RejectsBadRequests/no_roots18552026/11/06 06:53:03 INFO Received push request method=POST path=/api/pushes1856=== CONT TestPush_RejectsBadRequests/bad_root18572026/11/06 06:53:03 INFO Received push request method=POST path=/api/pushes1858=== CONT TestPush_RejectsBadRequests/root_not_in_objects18592026/11/06 06:53:03 INFO Received push request method=POST path=/api/pushes1860=== CONT TestPush_RejectsBadRequests/no_objects18612026/11/06 06:53:03 INFO Received push request method=POST path=/api/pushes1862--- PASS: TestPush_RejectsBadRequests (1.01s)1863 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1864 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1865 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1866 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1867=== CONT TestResolveDBConnectionString/flag_wins1868=== CONT TestResolveDBConnectionString/missing_file_is_an_error1869=== CONT TestResolveDBConnectionString/file_when_flag_empty1870=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1871=== CONT TestResolveDBConnectionString/nothing_configured1872=== CONT TestGCEndsOnShutdown/before_the_run1873--- PASS: TestResolveDBConnectionString (0.00s)1874 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1875 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1876 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1877 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1878 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1879=== NAME TestClientCADerivations1880 client_ca_test.go:139: Found 1 dependencies (including self)1881=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete18822026/11/06 06:53:03 INFO Starting cleanup of old closures method=DELETE path=/api/closures18832026/11/06 06:53:03 INFO Garbage collection started1884--- PASS: TestMetricsInventory (0.42s)1885=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark18862026/11/06 06:53:03 INFO Aborted multipart uploads count=0 kept=01887--- PASS: TestService_healthCheckHandler (0.43s)1888=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows18892026/11/06 06:53:03 WARN Force mode enabled - objects will be deleted immediately without grace period18902026/11/06 06:53:03 INFO Received uploads request method=POST path=/api/pending_closures18912026/11/06 06:53:03 INFO Received uploads request method=POST path=/api/pending_closures18922026/11/06 06:53:03 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=018932026/11/06 06:53:03 INFO All 1 paths already cached1894=== NAME TestClientIntegration1895 client_integration_test.go:317: Retrieved narinfo from S3:1896 StorePath: /build/TestClientIntegration3556400557/002/store/7qyyl0ykj6rzy0hr0qci0kdri4r1f9cq-test-file.txt1897 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1898 Compression: zstd1899 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11900 NarSize: 1521901 References: 1902 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk119032026/11/06 06:53:03 INFO Vacuumed table table=pending_closures1904 client_integration_test.go:318: Retrieved .ls file from S3 (compressed size: 77 bytes)1905 client_integration_test.go:318: Decompressed .ls content (64 bytes):1906 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}19072026/11/06 06:53:03 INFO Vacuumed table table=pending_objects19082026/11/06 06:53:03 INFO Vacuumed table table=multipart_uploads19092026/11/06 06:53:03 INFO Vacuumed table table=closures19102026/11/06 06:53:03 INFO Vacuumed table table=objects19112026/11/06 06:53:03 INFO Received uploads request method=POST path=/api/pending_closures19122026/11/06 06:53:03 INFO Received uploads request method=POST path=/api/pending_closures1913=== NAME TestNARDeduplicationMetadataUploadBug1914 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug864548123/001/store/kfhik09lrk6002xqwcfwpa6jrvmlzy5d-file1.txt19152026/11/06 06:53:03 INFO Received uploads request method=POST path=/api/pending_closures19162026/11/06 06:53:03 INFO Received push request method=POST path=/api/pushes19172026/11/06 06:53:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19182026/11/06 06:53:03 INFO Uploading f6wbb61jzgn8wsq552s4p6vs9jalq1a2-ca-test (144B)19192026/11/06 06:53:03 WARN Failed to register uploaded object key=f6wbb61jzgn8wsq552s4p6vs9jalq1a2.ls error="server returned 404: 404 page not found\n"19202026/11/06 06:53:03 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"19212026/11/06 06:53:03 WARN Failed to register uploaded object key=log/nbmx1yyby56gi9fmq743nbp2bvjnl858-ca-test.drv error="server returned 404: 404 page not found\n"19222026/11/06 06:53:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19232026/11/06 06:53:03 INFO Signed narinfos id=1 count=119242026/11/06 06:53:03 INFO Uploading 1 narinfos19252026/11/06 06:53:03 INFO Received uploads request method=POST path=/api/pending_closures19262026/11/06 06:53:03 INFO Received complete push request method=POST path=/api/pushes/1/complete19272026/11/06 06:53:03 WARN Failed to register uploaded object key=f6wbb61jzgn8wsq552s4p6vs9jalq1a2.narinfo error="server returned 404: 404 page not found\n"19282026/11/06 06:53:03 INFO Completed push id=1 objects=4 duration=6.968725ms19292026/11/06 06:53:03 INFO Upload complete. (169ms)19302026/11/06 06:53:03 INFO Received push request method=POST path=/api/pushes1931=== NAME TestClientCADerivations1932 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3639602922/001/store/f6wbb61jzgn8wsq552s4p6vs9jalq1a2-ca-test1933 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1934 Compression: zstd1935 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1936 NarSize: 1441937 References: 1938 Deriver: /build/TestClientCADerivations3639602922/001/store/nbmx1yyby56gi9fmq743nbp2bvjnl858-ca-test.drv1939 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1940 client_ca_test.go:185: Checking for realisation files in S3...19412026/11/06 06:53:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19422026/11/06 06:53:03 INFO Object in database but missing from S3 key=7qyyl0ykj6rzy0hr0qci0kdri4r1f9cq.ls19432026/11/06 06:53:03 WARN Found objects in DB but missing from S3, will re-upload count=119442026/11/06 06:53:03 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19452026/11/06 06:53:03 INFO Received complete push request method=POST path=/api/pushes/2/complete19462026/11/06 06:53:03 WARN Failed to register uploaded object key=7qyyl0ykj6rzy0hr0qci0kdri4r1f9cq.ls error="server returned 404: 404 page not found\n"19472026/11/06 06:53:03 INFO Completed push id=2 objects=3 duration=1.751616ms19482026/11/06 06:53:03 INFO Upload complete. (88ms)1949=== NAME TestClientIntegration1950 client_integration_test.go:335: Retrieved .ls file from S3 (compressed size: 62 bytes)1951 client_integration_test.go:335: Decompressed .ls content (49 bytes):1952 {"version":1,"root":{"type":"regular","size":39}}1953=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check19542026/11/06 06:53:03 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZDYyMjZkMWEtNDhkNy00NWRjLTkzYWUtYzZlYWRiOTE0MTZhLmEwMjA0YmI5LThjYTQtNDA0ZS1iYTRmLTYxMzQwODdmMWJmOHgxNzkzOTQ3OTgzMzIzNjY4NjEx parts=1019552026/11/06 06:53:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1956=== 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 06:53:03 INFO Completed upload id=1 objects=2 duration=3.23031ms19602026/11/06 06:53:03 INFO Received uploads request method=POST path=/api/pending_closures19612026/11/06 06:53:03 INFO Received uploads request method=POST path=/api/pending_closures19622026/11/06 06:53:03 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo19632026/11/06 06:53:03 WARN Found objects in DB but missing from S3, will re-upload count=11964--- PASS: TestService_verifyS3Integrity (2.05s)1965=== CONT TestServerTLSConfig/no_client_CA1966=== CONT TestServerTLSConfig/missing_CA_file1967=== CONT TestServerTLSConfig/not_a_PEM_file1968--- PASS: TestServerTLSConfig (0.00s)1969 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1970 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1971 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1972=== CONT TestClientErrorHandling/InvalidStorePath1973--- PASS: TestDeleteClosuresRacingPins (3.69s)1974=== CONT TestClientErrorHandling/ServerNotAvailable19752026/11/06 06:53:03 INFO Received push request method=POST path=/api/pushes19762026/11/06 06:53:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19772026/11/06 06:53:03 INFO Uploading kfhik09lrk6002xqwcfwpa6jrvmlzy5d-file1.txt (160B)19782026/11/06 06:53:03 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"19792026/11/06 06:53:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19802026/11/06 06:53:03 WARN Failed to register uploaded object key=kfhik09lrk6002xqwcfwpa6jrvmlzy5d.ls error="server returned 404: 404 page not found\n"19812026/11/06 06:53:03 INFO Signed narinfos id=1 count=119822026/11/06 06:53:03 INFO Uploading 1 narinfos19832026/11/06 06:53:03 WARN Failed to register uploaded object key=kfhik09lrk6002xqwcfwpa6jrvmlzy5d.narinfo error="server returned 404: 404 page not found\n"19842026/11/06 06:53:03 INFO Received complete push request method=POST path=/api/pushes/1/complete19852026/11/06 06:53:03 INFO Aborted multipart uploads count=0 kept=019862026/11/06 06:53:03 INFO Completed push id=1 objects=3 duration=13.106461ms19872026/11/06 06:53:03 INFO Upload complete. (165ms)1988=== NAME TestNARDeduplicationMetadataUploadBug1989 metadata_upload_test.go:54: Retrieved narinfo from S3:1990 StorePath: /build/TestNARDeduplicationMetadataUploadBug864548123/001/store/kfhik09lrk6002xqwcfwpa6jrvmlzy5d-file1.txt1991 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1992 Compression: zstd1993 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1994 NarSize: 1601995 References: 1996 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf19972026/11/06 06:53:03 WARN Force mode enabled - objects will be deleted immediately without grace period1998 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1999 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2000 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}20012026/11/06 06:53:03 INFO Received push request method=POST path=/api/pushes20022026/11/06 06:53:03 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)20032026/11/06 06:53:03 INFO Received uploads request method=POST path=/api/pending_closures20042026/11/06 06:53:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20052026/11/06 06:53:03 INFO Aborted multipart uploads count=0 kept=020062026/11/06 06:53:03 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst upload_id=ZDYyMjZkMWEtNDhkNy00NWRjLTkzYWUtYzZlYWRiOTE0MTZhLmU0NGU0N2JkLTdjMGItNDlhYy1iZmE3LWFmYzRmZTE0MzVjMngxNzkzOTQ3OTgzNTYwMjg3NzY4 parts=1020072026/11/06 06:53:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20082026/11/06 06:53:03 WARN Rate limiter enabled after throttle name=s3-test rate=520092026/11/06 06:53:03 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2010=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2011 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102012 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002013--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.36s)2014=== CONT TestClientErrorHandling/InvalidAuthToken20152026/11/06 06:53:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20162026/11/06 06:53:03 INFO Completed upload id=1 objects=3 duration=2.717385ms20172026/11/06 06:53:04 WARN Force mode enabled - objects will be deleted immediately without grace period20182026/11/06 06:53:04 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst upload_id=ZDYyMjZkMWEtNDhkNy00NWRjLTkzYWUtYzZlYWRiOTE0MTZhLjQyNDgzM2NjLWRjYmYtNDFkNS05NmY5LTlhZWIyYWNmNWRiY3gxNzkzOTQ3OTgzNTg3NTMxNjYy parts=1020192026/11/06 06:53:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20202026/11/06 06:53:04 INFO Completed upload id=1 objects=3 duration=5.368949ms20212026/11/06 06:53:04 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=020222026/11/06 06:53:04 INFO Vacuumed table table=pending_closures20232026/11/06 06:53:04 INFO Vacuumed table table=pending_objects20242026/11/06 06:53:04 INFO Vacuumed table table=multipart_uploads20252026/11/06 06:53:04 INFO Vacuumed table table=closures20262026/11/06 06:53:04 INFO Received uploads request method=POST path=/api/pending_closures20272026/11/06 06:53:04 INFO Vacuumed table table=objects20282026/11/06 06:53:04 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst20292026/11/06 06:53:04 WARN Found objects in DB but missing from S3, will re-upload count=12030=== CONT TestCacheConfigHandler/full_config,_no_issuer2031=== CONT TestCacheConfigHandler/no_signing_keys2032=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2033=== CONT TestCacheConfigHandler/no_cache_url_configured2034--- PASS: TestCacheConfigHandler (0.00s)2035 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2036 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2037 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2038 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2039=== CONT TestService_RequireScope_OIDC/builder_may_write2040=== CONT TestService_RequireScope_OIDC/reader_may_read2041=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2042=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read20432026/11/06 06:53:04 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]2044=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2045=== CONT TestService_RequireScope_OIDC/writer_implies_read2046=== CONT TestService_RequireScope_OIDC/reader_may_not_write2047=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2048=== CONT TestService_RequireScope_OIDC/static_token_may_write2049=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2050=== CONT TestService_RequireScope_OIDC/static_token_may_admin2051=== CONT TestService_RequireScope_OIDC/ops_may_admin2052=== CONT TestService_RequireScope_OIDC/ops_may_not_write2053=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2054=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2055--- PASS: TestService_RequireScope_OIDC (1.08s)2056 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2057 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2058 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2059 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2060 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2061 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2062 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2063 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2064 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2065 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2066 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2067 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2068 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2069 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)20702026/11/06 06:53:04 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/present2071=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20722026/11/06 06:53:04 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]2073=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured20742026/11/06 06:53:04 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:44017/bucket100/?delete=\": context canceled"2075=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20762026/11/06 06:53:04 WARN Authentication failed token_preview=eyJhbGciOi...7M0Tni-oVg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2077--- PASS: TestService_AuthMiddleware_OIDC (0.77s)2078 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2079 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2080 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2081 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)20822026/11/06 06:53:04 INFO Received uploads request method=POST path=/api/pending_closures20832026/11/06 06:53:04 INFO Received complete push request method=POST path=/api/pushes/3/complete20842026/11/06 06:53:04 WARN Failed to register uploaded object key=7qyyl0ykj6rzy0hr0qci0kdri4r1f9cq.ls error="server returned 404: 404 page not found\n"20852026/11/06 06:53:04 INFO Completed push id=3 objects=3 duration=3.798735ms20862026/11/06 06:53:04 INFO Upload complete. (185ms)2087=== NAME TestClientIntegration2088 client_integration_test.go:352: Retrieved .ls file from S3 (compressed size: 62 bytes)2089 client_integration_test.go:352: Decompressed .ls content (49 bytes):2090 {"version":1,"root":{"type":"regular","size":39}}2091 client_integration_test.go:363: Testing garbage collection...20922026/11/06 06:53:04 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst20932026/11/06 06:53:04 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0001.narinfo20942026/11/06 06:53:04 INFO Aborted multipart uploads count=0 kept=020952026/11/06 06:53:04 WARN Force mode enabled - objects will be deleted immediately without grace period20962026/11/06 06:53:04 INFO Received uploads request method=POST path=/api/pending_closures20972026/11/06 06:53:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20982026/11/06 06:53:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2099=== NAME TestNARDeduplicationMetadataUploadBug2100 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug864548123/001/store/shin9vr1lqxxpkrqhv0r7k8nxv4wxwn0-file2.txt21012026/11/06 06:53:04 INFO Aborted multipart uploads count=0 kept=021022026/11/06 06:53:04 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst upload_id=ZDYyMjZkMWEtNDhkNy00NWRjLTkzYWUtYzZlYWRiOTE0MTZhLjQ1NGY2YzlhLTAyMzMtNDVmNy05NTZlLWQ1ZTA5NzM0NDRkM3gxNzkzOTQ3OTgzNjc5NjQ5Nzc3 parts=1021032026/11/06 06:53:04 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst upload_id=ZDYyMjZkMWEtNDhkNy00NWRjLTkzYWUtYzZlYWRiOTE0MTZhLmI2NmU5MTFhLTNiZjQtNDA0MC05MTBlLTRmODFhOGI1MWU0NHgxNzkzOTQ3OTgzNzExMjg4MjUx parts=102104--- PASS: TestGCEndsOnShutdown (0.00s)2105 --- PASS: TestGCEndsOnShutdown/before_the_run (0.31s)2106 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.58s)2107 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.63s)21082026/11/06 06:53:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21092026/11/06 06:53:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21102026/11/06 06:53:04 INFO Completed upload id=1 objects=3 duration=3.356411ms21112026/11/06 06:53:04 INFO Received uploads request method=POST path=/api/pending_closures21122026/11/06 06:53:04 INFO Completed upload id=1 objects=3 duration=5.34649ms21132026/11/06 06:53:04 INFO Received uploads request method=POST path=/api/pending_closures21142026/11/06 06:53:04 INFO Starting cleanup of old closures method=DELETE path=/api/closures21152026/11/06 06:53:04 INFO Garbage collection started21162026/11/06 06:53:04 WARN Request failed, retrying attempt=2 backoff=207.689524ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21172026/11/06 06:53:04 INFO Aborted multipart uploads count=0 kept=021182026/11/06 06:53:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21192026/11/06 06:53:04 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000200000000000000000000.nar.zst upload_id=ZDYyMjZkMWEtNDhkNy00NWRjLTkzYWUtYzZlYWRiOTE0MTZhLjE3ODlkNDI0LWJhNTktNDM5ZS04NmUzLWRmYTU5OWU1NmVjZXgxNzkzOTQ3OTgzNzM0NjQ1OTQ4 parts=1021202026/11/06 06:53:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21212026/11/06 06:53:04 INFO Completed upload id=1 objects=3 duration=4.427321ms21222026/11/06 06:53:04 INFO Received uploads request method=POST path=/api/pending_closures21232026/11/06 06:53:04 WARN Force mode enabled - objects will be deleted immediately without grace period21242026/11/06 06:53:04 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=021252026/11/06 06:53:04 INFO Vacuumed table table=pending_closures21262026/11/06 06:53:04 INFO Vacuumed table table=pending_objects21272026/11/06 06:53:04 INFO Vacuumed table table=multipart_uploads21282026/11/06 06:53:04 INFO Vacuumed table table=closures21292026/11/06 06:53:04 INFO Vacuumed table table=objects2130--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2131 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.54s)2132 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.49s)21332026/11/06 06:53:04 WARN Force mode enabled - objects will be deleted immediately without grace period21342026/11/06 06:53:04 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=021352026/11/06 06:53:04 INFO Vacuumed table table=pending_closures21362026/11/06 06:53:04 INFO Received push request method=POST path=/api/pushes21372026/11/06 06:53:04 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)21382026/11/06 06:53:04 INFO Vacuumed table table=pending_objects21392026/11/06 06:53:04 INFO Vacuumed table table=multipart_uploads21402026/11/06 06:53:04 INFO Vacuumed table table=closures2141--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2142 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.87s)2143 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.90s)21442026/11/06 06:53:04 INFO Vacuumed table table=objects21452026/11/06 06:53:04 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign21462026/11/06 06:53:04 WARN Failed to register uploaded object key=shin9vr1lqxxpkrqhv0r7k8nxv4wxwn0.ls error="server returned 404: 404 page not found\n"21472026/11/06 06:53:04 INFO Signed narinfos id=2 count=121482026/11/06 06:53:04 INFO Uploading 1 narinfos21492026/11/06 06:53:04 INFO Received complete push request method=POST path=/api/pushes/2/complete21502026/11/06 06:53:04 WARN Failed to register uploaded object key=shin9vr1lqxxpkrqhv0r7k8nxv4wxwn0.narinfo error="server returned 404: 404 page not found\n"21512026/11/06 06:53:04 INFO Completed push id=2 objects=3 duration=1.997659ms21522026/11/06 06:53:04 INFO Upload complete. (142ms)2153=== NAME TestNARDeduplicationMetadataUploadBug2154 metadata_upload_test.go:76: Retrieved narinfo from S3:2155 StorePath: /build/TestNARDeduplicationMetadataUploadBug864548123/001/store/shin9vr1lqxxpkrqhv0r7k8nxv4wxwn0-file2.txt2156 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2157 Compression: zstd2158 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2159 NarSize: 1602160 References: 2161 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2162 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2163 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2164 {"version":1,"root":{"type":"regular","size":44}}2165--- PASS: TestNARDeduplicationMetadataUploadBug (1.19s)21662026/11/06 06:53:04 WARN Request failed, retrying attempt=3 backoff=401.147067ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2167--- PASS: TestUploadHandlersRejectOversizedBody (0.24s)2168 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)2169 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.10s)2170 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.99s)2171--- PASS: TestPendingClosureWriteTimeout (0.02s)2172 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2173 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2174 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2175 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.27s)21762026/11/06 06:53:04 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21772026/11/06 06:53:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21782026/11/06 06:53:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21792026/11/06 06:53:04 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100400000000000000000000.nar.zst upload_id=ZDYyMjZkMWEtNDhkNy00NWRjLTkzYWUtYzZlYWRiOTE0MTZhLjZiYzA4NzNlLWQ1NTYtNDE1OS1iNWFmLTc2MTIxZWUyNTNmMHgxNzkzOTQ3OTg0MTUwNzUxMjk0 parts=1021802026/11/06 06:53:04 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21812026/11/06 06:53:04 INFO Completed upload id=2 objects=3 duration=1.442134ms21822026/11/06 06:53:04 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100300000000000000000000.nar.zst upload_id=ZDYyMjZkMWEtNDhkNy00NWRjLTkzYWUtYzZlYWRiOTE0MTZhLmU3YzhlNThjLThmYzItNDYxMS1iMzM3LWQ4Y2E0MGMyMjdmY3gxNzkzOTQ3OTg0MTUxOTMyMzY1 parts=1021832026/11/06 06:53:04 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21842026/11/06 06:53:04 INFO Completed upload id=2 objects=3 duration=2.593544ms21852026/11/06 06:53:04 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21862026/11/06 06:53:04 INFO Received uploads request method=POST path=/api/pending_closures21872026/11/06 06:53:04 INFO Received uploads request method=POST path=/api/pending_closures21882026/11/06 06:53:04 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst21892026/11/06 06:53:04 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0003.narinfo21902026/11/06 06:53:04 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst21912026/11/06 06:53:04 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0004.narinfo2192--- PASS: TestService_verifyS3ReuploadsStaleNarinfo (0.34s)2193 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed (0.84s)2194 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed (0.89s)2195 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed (0.89s)2196 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed (1.35s)2197 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost (1.32s)2198--- PASS: TestReadProxyOutlastsServerWriteTimeout (5.20s)21992026/11/06 06:53:04 WARN Request failed, retrying attempt=4 backoff=854.345172ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2200=== NAME TestOrphanedObjectsGCStressTest2201 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains22022026/11/06 06:53:05 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=022032026/11/06 06:53:05 INFO Received create pin request method=POST path=/api/pins/myapp22042026/11/06 06:53:05 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3257052458/001/store/hpkg353lc0s0a0cbc8688hh7b03h6dvy-pinned-file.txt narinfo_key=hpkg353lc0s0a0cbc8688hh7b03h6dvy.narinfo22052026/11/06 06:53:05 INFO Starting cleanup of old closures method=DELETE path=/api/closures22062026/11/06 06:53:05 INFO Garbage collection started22072026/11/06 06:53:05 INFO Aborted multipart uploads count=0 kept=02208 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion22092026/11/06 06:53:05 WARN Request failed, retrying attempt=5 backoff=1.57361822s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22102026/11/06 06:53:05 WARN Force mode enabled - objects will be deleted immediately without grace period2211--- PASS: TestConnectWaitsForAPeerMigration (5.64s)22122026/11/06 06:53:05 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=022132026/11/06 06:53:05 INFO Vacuumed table table=pending_closures22142026/11/06 06:53:05 INFO Vacuumed table table=pending_objects22152026/11/06 06:53:05 INFO Vacuumed table table=multipart_uploads22162026/11/06 06:53:05 INFO Vacuumed table table=closures22172026/11/06 06:53:05 INFO Vacuumed table table=objects22182026/11/06 06:53:06 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02219=== NAME TestClientIntegration2220 client_integration_test.go:370: Objects in database after GC:2221 client_integration_test.go:370: Successfully deleted all objects with GC --force2222--- PASS: TestClientIntegration (3.94s)2223=== NAME TestOrphanedObjectsGCStressTest2224 orphaned_objects_gc_test.go:503: Stress test completed successfully:2225 orphaned_objects_gc_test.go:504: - Active objects preserved: 202226 orphaned_objects_gc_test.go:505: - Objects deleted: 2102227 orphaned_objects_gc_test.go:506: - Total GC'd: 2102228--- PASS: TestOrphanedObjectsGCStressTest (4.79s)2229=== NAME TestClientCADerivations2230 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2231 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2232 error: binary cache 's3://bucket80?endpoint=http://localhost:44017®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3639602922/001/store'2233 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12234--- PASS: TestClientCADerivations (3.65s)22352026/11/06 06:53:07 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-config2236=== NAME TestPinProtectsFromGC2237 client_integration_test.go:887: Pin successfully protected closure from garbage collection2238--- PASS: TestPinProtectsFromGC (7.15s)22392026/11/06 06:53:07 WARN Request failed, retrying attempt=2 backoff=184.568164ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22402026/11/06 06:53:07 WARN Request failed, retrying attempt=3 backoff=365.108043ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22412026/11/06 06:53:08 WARN Request failed, retrying attempt=4 backoff=776.289305ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22422026/11/06 06:53:08 INFO Aborted multipart uploads count=1 kept=022432026/11/06 06:53:08 INFO Received cleanup request method=DELETE path=/api/pending_closures22442026/11/06 06:53:08 INFO Aborted multipart uploads count=1 kept=02245--- PASS: TestPendingCleanupUsesOneCutoff (6.72s)22462026/11/06 06:53:08 WARN Request failed, retrying attempt=5 backoff=1.55678399s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22472026/11/06 06:53:10 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"22482026/11/06 06:53:10 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-config22492026/11/06 06:53:10 WARN Request failed, retrying attempt=2 backoff=201.667201ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22502026/11/06 06:53:10 WARN Request failed, retrying attempt=3 backoff=421.447105ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22512026/11/06 06:53:11 WARN Request failed, retrying attempt=4 backoff=845.821864ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22522026/11/06 06:53:12 WARN Request failed, retrying attempt=5 backoff=1.509385604s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22532026/11/06 06:53:13 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_closures22542026/11/06 06:53:13 WARN Request failed, retrying attempt=2 backoff=199.256331ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22552026/11/06 06:53:13 WARN Request failed, retrying attempt=3 backoff=394.122416ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22562026/11/06 06:53:14 WARN Request failed, retrying attempt=4 backoff=859.05757ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22572026/11/06 06:53:15 WARN Request failed, retrying attempt=5 backoff=1.482485406s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2258--- PASS: TestClientErrorHandling (0.00s)2259 --- PASS: TestClientErrorHandling/InvalidStorePath (0.48s)2260 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.57s)2261 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.83s)2262PASS2263{"timestamp":"2026-11-06T06:53:16.653370824Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:33280","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(206)"}2264{"timestamp":"2026-11-06T06:53:16.653367304Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:33246","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(207)"}2265{"timestamp":"2026-11-06T06:53:16.653366844Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:33352","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(194)"}22662026-11-06 06:53:17.111 UTC [131] LOG: received smart shutdown request22672026-11-06 06:53:17.125 UTC [131] LOG: background worker "logical replication launcher" (PID 141) exited with exit code 122682026-11-06 06:53:17.135 UTC [136] LOG: shutting down22692026-11-06 06:53:17.136 UTC [136] LOG: checkpoint starting: shutdown immediate22702026-11-06 06:53:17.987 UTC [136] LOG: checkpoint complete: wrote 10830 buffers (66.1%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.293 s, sync=0.517 s, total=0.852 s; sync files=35726, longest=0.014 s, average=0.001 s; distance=516945 kB, estimate=516945 kB; lsn=0/2103A210, redo lsn=0/2103A21022712026-11-06 06:53:18.188 UTC [131] LOG: database system is shut down2272Running OIDC tests...2273=== RUN TestAudienceForIssuer2274=== PAUSE TestAudienceForIssuer2275=== RUN TestGlobMatch2276=== PAUSE TestGlobMatch2277=== RUN TestValidateToken_ValidToken2278=== PAUSE TestValidateToken_ValidToken2279=== RUN TestValidateToken_WrongAudience2280=== PAUSE TestValidateToken_WrongAudience2281=== RUN TestValidateToken_Expired2282=== PAUSE TestValidateToken_Expired2283=== RUN TestValidateToken_BoundClaimsMismatch2284=== PAUSE TestValidateToken_BoundClaimsMismatch2285=== RUN TestValidateToken_BoundSubjectMismatch2286=== PAUSE TestValidateToken_BoundSubjectMismatch2287=== RUN TestValidateToken_MultipleProviders2288=== PAUSE TestValidateToken_MultipleProviders2289=== RUN TestValidateToken_NoMatchingProvider2290=== PAUSE TestValidateToken_NoMatchingProvider2291=== RUN TestValidateToken_KubernetesServiceAccount2292=== PAUSE TestValidateToken_KubernetesServiceAccount2293=== RUN TestNewValidator_KubernetesRequiresCA2294=== PAUSE TestNewValidator_KubernetesRequiresCA2295=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2296=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2297=== RUN TestPins_ReservedForMatchingRule2298=== PAUSE TestPins_ReservedForMatchingRule2299=== RUN TestPins_TopLevelShorthand2300=== PAUSE TestPins_TopLevelShorthand2301=== RUN TestPins_ConfigValidation2302=== PAUSE TestPins_ConfigValidation2303=== RUN TestScopes_LegacyProviderDefaultsToWrite2304=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2305=== RUN TestScopes_Rules2306=== PAUSE TestScopes_Rules2307=== RUN TestScopes_ConfigValidation2308=== PAUSE TestScopes_ConfigValidation2309=== CONT TestAudienceForIssuer2310=== CONT TestPins_ConfigValidation2311--- PASS: TestAudienceForIssuer (0.00s)2312=== CONT TestValidateToken_Expired2313=== CONT TestValidateToken_KubernetesServiceAccount2314=== CONT TestValidateToken_BoundClaimsMismatch2315--- PASS: TestPins_ConfigValidation (0.00s)2316=== CONT TestScopes_ConfigValidation2317--- PASS: TestScopes_ConfigValidation (0.00s)2318=== CONT TestScopes_Rules2319=== CONT TestScopes_LegacyProviderDefaultsToWrite2320=== CONT TestPins_TopLevelShorthand2321=== CONT TestPins_ReservedForMatchingRule2322=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2323=== CONT TestNewValidator_KubernetesRequiresCA2324=== CONT TestValidateToken_WrongAudience2325=== CONT TestValidateToken_ValidToken2326=== CONT TestValidateToken_NoMatchingProvider2327=== CONT TestValidateToken_MultipleProviders2328=== CONT TestGlobMatch2329=== CONT TestValidateToken_BoundSubjectMismatch2330=== RUN TestGlobMatch/foo_foo2331=== PAUSE TestGlobMatch/foo_foo2332=== RUN TestGlobMatch/foo_bar2333=== PAUSE TestGlobMatch/foo_bar2334=== RUN TestGlobMatch/*_2335=== PAUSE TestGlobMatch/*_2336=== RUN TestGlobMatch/*_anything2337=== PAUSE TestGlobMatch/*_anything2338=== RUN TestGlobMatch/foo*_foo2339=== PAUSE TestGlobMatch/foo*_foo2340=== RUN TestGlobMatch/foo*_foobar2341=== PAUSE TestGlobMatch/foo*_foobar2342=== RUN TestGlobMatch/foo*_bar2343=== PAUSE TestGlobMatch/foo*_bar2344=== RUN TestGlobMatch/*bar_bar2345=== PAUSE TestGlobMatch/*bar_bar2346=== RUN TestGlobMatch/*bar_foobar2347=== PAUSE TestGlobMatch/*bar_foobar2348=== RUN TestGlobMatch/*bar_foo2349=== PAUSE TestGlobMatch/*bar_foo2350=== RUN TestGlobMatch/foo*bar_foobar2351=== PAUSE TestGlobMatch/foo*bar_foobar2352=== RUN TestGlobMatch/foo*bar_foo123bar2353=== PAUSE TestGlobMatch/foo*bar_foo123bar2354=== RUN TestGlobMatch/foo*bar_foobarbaz2355=== PAUSE TestGlobMatch/foo*bar_foobarbaz2356=== RUN TestGlobMatch/*/*_foo/bar2357=== PAUSE TestGlobMatch/*/*_foo/bar2358=== RUN TestGlobMatch/*/*_foo2359=== PAUSE TestGlobMatch/*/*_foo2360=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2361=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2362=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02363=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02364=== RUN TestGlobMatch/refs/*/main_refs/heads/main2365=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2366=== RUN TestGlobMatch/fo?_foo2367=== PAUSE TestGlobMatch/fo?_foo2368=== RUN TestGlobMatch/fo?_fo2369=== PAUSE TestGlobMatch/fo?_fo2370=== RUN TestGlobMatch/fo?_fooo2371=== PAUSE TestGlobMatch/fo?_fooo2372=== RUN TestGlobMatch/?oo_foo2373=== PAUSE TestGlobMatch/?oo_foo2374=== RUN TestGlobMatch/?oo_boo2375=== PAUSE TestGlobMatch/?oo_boo2376=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2377=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2378=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2379=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2380=== CONT TestGlobMatch/foo_foo2381=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2382=== CONT TestGlobMatch/foo*bar_foo123bar2383=== CONT TestGlobMatch/foo*bar_foobar2384=== CONT TestGlobMatch/*bar_foo2385=== CONT TestGlobMatch/*bar_foobar2386=== CONT TestGlobMatch/*bar_bar2387=== CONT TestGlobMatch/foo*_bar2388=== CONT TestGlobMatch/foo*_foobar2389=== CONT TestGlobMatch/foo*_foo2390=== CONT TestGlobMatch/*_anything2391=== CONT TestGlobMatch/*_2392=== CONT TestGlobMatch/foo_bar2393=== CONT TestGlobMatch/fo?_foo2394=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2395=== CONT TestGlobMatch/?oo_boo2396=== CONT TestGlobMatch/?oo_foo2397=== CONT TestGlobMatch/fo?_fooo2398=== CONT TestGlobMatch/fo?_fo2399=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2400=== CONT TestGlobMatch/refs/*/main_refs/heads/main2401=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02402=== CONT TestGlobMatch/*/*_foo2403=== CONT TestGlobMatch/*/*_foo/bar24042026/11/06 06:53:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44163/oidc24052026/11/06 06:53:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43717/oidc2406=== CONT TestGlobMatch/foo*bar_foobarbaz2407--- PASS: TestGlobMatch (0.00s)2408 --- PASS: TestGlobMatch/foo_foo (0.00s)2409 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2410 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2411 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2412 --- PASS: TestGlobMatch/*bar_foo (0.00s)2413 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2414 --- PASS: TestGlobMatch/*bar_bar (0.00s)2415 --- PASS: TestGlobMatch/foo*_bar (0.00s)2416 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2417 --- PASS: TestGlobMatch/foo*_foo (0.00s)2418 --- PASS: TestGlobMatch/*_anything (0.00s)2419 --- PASS: TestGlobMatch/*_ (0.00s)2420 --- PASS: TestGlobMatch/foo_bar (0.00s)2421 --- PASS: TestGlobMatch/fo?_foo (0.00s)2422 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2423 --- PASS: TestGlobMatch/?oo_boo (0.00s)2424 --- PASS: TestGlobMatch/?oo_foo (0.00s)2425 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2426 --- PASS: TestGlobMatch/fo?_fo (0.00s)2427 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2428 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2429 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2430 --- PASS: TestGlobMatch/*/*_foo (0.00s)2431 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2432 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2433--- PASS: TestScopes_LegacyProviderDefaultsToWrite (2.63s)2434--- PASS: TestScopes_Rules (2.88s)24352026/11/06 06:53:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44867/oidc2436--- PASS: TestPins_TopLevelShorthand (3.33s)24372026/11/06 06:53:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34575/oidc24382026/11/06 06:53:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38273/oidc2439--- PASS: TestValidateToken_WrongAudience (2.57s)2440--- PASS: TestValidateToken_BoundClaimsMismatch (3.36s)24412026/11/06 06:53:24 http: TLS handshake error from 127.0.0.1:60898: remote error: tls: bad certificate2442--- PASS: TestNewValidator_KubernetesRequiresCA (2.58s)24432026/11/06 06:53:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43399/oidc2444--- PASS: TestPins_ReservedForMatchingRule (3.33s)24452026/11/06 06:53:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41999/oidc24462026/11/06 06:53:24 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:368872447--- PASS: TestValidateToken_ValidToken (2.25s)2448--- PASS: TestValidateToken_KubernetesServiceAccount (3.40s)24492026/11/06 06:53:24 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232450--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (3.34s)24512026/11/06 06:53:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39369/oidc2452--- PASS: TestValidateToken_BoundSubjectMismatch (0.78s)24532026/11/06 06:53:24 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:36951/oidc24542026/11/06 06:53:24 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:41449/oidc2455--- PASS: TestValidateToken_MultipleProviders (0.90s)24562026/11/06 06:53:24 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:42599/oidc2457--- PASS: TestValidateToken_NoMatchingProvider (0.98s)24582026/11/06 06:53:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39347/oidc2459--- PASS: TestValidateToken_Expired (3.65s)2460PASS2461Running hook tests...2462=== RUN TestSendPathsEmpty2463=== PAUSE TestSendPathsEmpty2464=== RUN TestQueueEnqueueAndFetch2465=== PAUSE TestQueueEnqueueAndFetch2466=== RUN TestQueueDeduplication2467=== PAUSE TestQueueDeduplication2468=== RUN TestQueueRemove2469=== PAUSE TestQueueRemove2470=== RUN TestQueueFetchBatchLimit2471=== PAUSE TestQueueFetchBatchLimit2472=== RUN TestQueueRetryMovesToBack2473=== PAUSE TestQueueRetryMovesToBack2474=== RUN TestQueueFetchRemoveLifecycle2475=== PAUSE TestQueueFetchRemoveLifecycle2476=== RUN TestQueueConcurrentWriters2477=== PAUSE TestQueueConcurrentWriters2478=== RUN TestQueueRemoveLargeClosure2479=== PAUSE TestQueueRemoveLargeClosure2480=== RUN TestServerClientIntegration2481--- PASS: TestServerClientIntegration (0.01s)2482=== RUN TestServerQueueError24832026/11/06 06:53:24 ERROR Failed to queue paths error="permission denied" count=12484--- PASS: TestServerQueueError (0.00s)2485=== RUN TestGetListenerSocketActivation2486 server_test.go:218: === RUN TestGetListenerSocketActivation2487 --- PASS: TestGetListenerSocketActivation (0.00s)2488 PASS2489 2490--- PASS: TestGetListenerSocketActivation (0.24s)2491=== RUN TestServerStalledClientDoesNotBlockShutdown2492=== PAUSE TestServerStalledClientDoesNotBlockShutdown2493=== RUN TestServerBacksOffOnAcceptErrors2494=== PAUSE TestServerBacksOffOnAcceptErrors2495=== RUN TestDrainIsolatesPoisonPath2496=== PAUSE TestDrainIsolatesPoisonPath2497=== RUN TestRunNotBlockedByPoisonHead2498=== PAUSE TestRunNotBlockedByPoisonHead2499=== RUN TestDrainGivesUpWhenServerDown2500=== PAUSE TestDrainGivesUpWhenServerDown2501=== RUN TestFailedPathPrunedByLaterClosure2502=== PAUSE TestFailedPathPrunedByLaterClosure2503=== RUN TestWorkerUploadsAndRemoves2504=== PAUSE TestWorkerUploadsAndRemoves2505=== RUN TestWorkerSkipsGCdPaths2506=== PAUSE TestWorkerSkipsGCdPaths2507=== RUN TestWorkerPrunesClosureDeps2508=== PAUSE TestWorkerPrunesClosureDeps2509=== RUN TestDrainTimeout2510=== PAUSE TestDrainTimeout2511=== RUN TestWorkerRemoveFailureIsNotProgress2512=== PAUSE TestWorkerRemoveFailureIsNotProgress2513=== RUN TestWorkerKeepsPathItCannotStat2514=== PAUSE TestWorkerKeepsPathItCannotStat2515=== CONT TestSendPathsEmpty2516--- PASS: TestSendPathsEmpty (0.00s)2517=== CONT TestServerStalledClientDoesNotBlockShutdown2518=== CONT TestWorkerRemoveFailureIsNotProgress2519=== CONT TestServerBacksOffOnAcceptErrors2520=== CONT TestQueueFetchBatchLimit25212026/11/06 06:53:25 ERROR Accept failed error="too many open files"2522=== CONT TestDrainTimeout2523=== CONT TestQueueRetryMovesToBack2524=== CONT TestWorkerKeepsPathItCannotStat2525=== CONT TestQueueRemoveLargeClosure2526=== CONT TestQueueRemove2527=== CONT TestQueueDeduplication2528=== CONT TestQueueFetchRemoveLifecycle2529=== CONT TestQueueEnqueueAndFetch2530=== CONT TestQueueConcurrentWriters2531=== CONT TestFailedPathPrunedByLaterClosure2532=== CONT TestRunNotBlockedByPoisonHead2533=== CONT TestWorkerPrunesClosureDeps2534=== CONT TestWorkerSkipsGCdPaths2535=== CONT TestDrainGivesUpWhenServerDown2536=== CONT TestWorkerUploadsAndRemoves2537=== CONT TestDrainIsolatesPoisonPath25382026/11/06 06:53:25 ERROR Accept failed error="too many open files"2539--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2540--- PASS: TestQueueEnqueueAndFetch (0.02s)25412026/11/06 06:53:25 ERROR Accept failed error="too many open files"2542--- PASS: TestQueueFetchBatchLimit (0.03s)25432026/11/06 06:53:25 INFO Upload queue status pending=32544--- PASS: TestQueueDeduplication (0.03s)25452026/11/06 06:53:25 INFO Uploading batch count=125462026/11/06 06:53:25 ERROR Upload failed error="upload failed" count=125472026/11/06 06:53:25 INFO Upload queue status pending=225482026/11/06 06:53:25 INFO Uploading batch count=12549--- PASS: TestQueueRemove (0.03s)25502026/11/06 06:53:25 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat606227630/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat606227630/002/locked/aaa: permission denied"25512026/11/06 06:53:25 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat606227630/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat606227630/002/locked/aaa: permission denied"25522026/11/06 06:53:25 INFO Uploading batch count=225532026/11/06 06:53:25 ERROR Accept failed error="too many open files"25542026/11/06 06:53:25 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat606227630/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat606227630/002/locked/aaa: permission denied"25552026/11/06 06:53:25 ERROR Drain finished with paths left in queue remaining=12556--- PASS: TestWorkerKeepsPathItCannotStat (0.04s)2557--- PASS: TestQueueRetryMovesToBack (0.04s)25582026/11/06 06:53:25 INFO Uploading batch count=125592026/11/06 06:53:25 ERROR Upload failed error="upload failed" count=125602026/11/06 06:53:25 INFO Uploading batch count=125612026/11/06 06:53:25 INFO Uploading batch count=225622026/11/06 06:53:25 ERROR Upload failed error="upload failed" count=225632026/11/06 06:53:25 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown463287846/002/a25642026/11/06 06:53:25 INFO Uploading batch count=125652026/11/06 06:53:25 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown463287846/002/b25662026/11/06 06:53:25 INFO Uploading batch count=225672026/11/06 06:53:25 ERROR Upload failed error="upload failed" count=225682026/11/06 06:53:25 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown463287846/002/c25692026/11/06 06:53:25 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown463287846/002/d25702026/11/06 06:53:25 INFO Uploading batch count=225712026/11/06 06:53:25 ERROR Upload failed error="upload failed" count=225722026/11/06 06:53:25 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown463287846/002/e25732026/11/06 06:53:25 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown463287846/002/f25742026/11/06 06:53:25 INFO Upload queue status pending=225752026/11/06 06:53:25 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2253626489/002/nonexistent25762026/11/06 06:53:25 ERROR Drain finished with paths left in queue remaining=1025772026/11/06 06:53:25 INFO Uploading batch count=125782026/11/06 06:53:25 INFO Uploading batch count=425792026/11/06 06:53:25 ERROR Upload failed error="upload failed" count=42580--- PASS: TestDrainGivesUpWhenServerDown (0.05s)2581--- PASS: TestFailedPathPrunedByLaterClosure (0.05s)2582--- PASS: TestWorkerPrunesClosureDeps (0.05s)25832026/11/06 06:53:25 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3993262077/002/bbb25842026/11/06 06:53:25 INFO Uploading batch count=125852026/11/06 06:53:25 ERROR Upload failed error="upload failed" count=125862026/11/06 06:53:25 INFO Uploading batch count=125872026/11/06 06:53:25 ERROR Upload failed error="upload failed" count=125882026/11/06 06:53:25 INFO Uploading batch count=125892026/11/06 06:53:25 ERROR Upload failed error="upload failed" count=125902026/11/06 06:53:25 ERROR Drain finished with paths left in queue remaining=12591--- PASS: TestDrainIsolatesPoisonPath (0.06s)25922026/11/06 06:53:25 ERROR Accept failed error="too many open files"25932026/11/06 06:53:25 ERROR Upload failed error="context deadline exceeded" count=225942026/11/06 06:53:25 ERROR Drain finished with paths left in queue remaining=425952026/11/06 06:53:25 ERROR Failed to decode request error="read unix /build/hook3173950700/test.sock->@: i/o timeout"25962026/11/06 06:53:25 ERROR Failed to write response error="write unix /build/hook3173950700/test.sock->@: i/o timeout"2597--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.71s)25982026/11/06 06:53:25 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress1657916368/002/nonexistent25992026/11/06 06:53:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=126002026/11/06 06:53:25 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress1657916368/002/nonexistent26012026/11/06 06:53:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=12602--- PASS: TestDrainTimeout (0.71s)26032026/11/06 06:53:25 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress1657916368/002/nonexistent26042026/11/06 06:53:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=12605--- PASS: TestWorkerSkipsGCdPaths (0.71s)26062026/11/06 06:53:25 INFO Upload queue status pending=226072026/11/06 06:53:25 ERROR Drain finished with paths left in queue remaining=126082026/11/06 06:53:25 INFO Uploading batch count=22609--- PASS: TestWorkerRemoveFailureIsNotProgress (0.71s)2610--- PASS: TestWorkerUploadsAndRemoves (0.73s)26112026/11/06 06:53:26 ERROR Accept failed error="too many open files"26122026/11/06 06:53:26 INFO Uploading batch count=126132026/11/06 06:53:26 INFO Uploading batch count=126142026/11/06 06:53:26 INFO Uploading batch count=126152026/11/06 06:53:26 ERROR Upload failed error="upload failed" count=126162026/11/06 06:53:26 INFO Uploading batch count=126172026/11/06 06:53:26 ERROR Upload failed error="upload failed" count=126182026/11/06 06:53:26 INFO Uploading batch count=126192026/11/06 06:53:26 ERROR Upload failed error="upload failed" count=126202026/11/06 06:53:26 INFO Uploading batch count=126212026/11/06 06:53:26 ERROR Upload failed error="upload failed" count=126222026/11/06 06:53:26 ERROR Drain finished with paths left in queue remaining=12623--- PASS: TestRunNotBlockedByPoisonHead (1.26s)2624--- PASS: TestQueueConcurrentWriters (1.29s)2625--- PASS: TestQueueRemoveLargeClosure (1.30s)26262026/11/06 06:53:26 ERROR Accept failed error="too many open files"26272026/11/06 06:53:26 ERROR Accept failed error="too many open files"2628--- PASS: TestServerBacksOffOnAcceptErrors (1.72s)2629PASS2630Running signing tests...2631=== RUN TestExternalSigner2632=== PAUSE TestExternalSigner2633=== RUN TestExternalSignerWrongPublicKey2634=== PAUSE TestExternalSignerWrongPublicKey2635=== RUN TestExternalSignerErrors2636=== PAUSE TestExternalSignerErrors2637=== RUN TestExternalSignerRestartsAfterCrash2638=== PAUSE TestExternalSignerRestartsAfterCrash2639=== RUN TestExternalSignerProgramErrorKeepsProcess2640=== PAUSE TestExternalSignerProgramErrorKeepsProcess2641=== RUN TestExternalSignerClose2642=== PAUSE TestExternalSignerClose2643=== RUN TestExternalSignerRejectsInvalidPublicKey2644=== PAUSE TestExternalSignerRejectsInvalidPublicKey2645=== RUN TestExternalSignerCancellation2646=== PAUSE TestExternalSignerCancellation2647=== RUN TestGenerateFingerprint2648=== PAUSE TestGenerateFingerprint2649=== RUN TestParseSigningKey2650=== PAUSE TestParseSigningKey2651=== RUN TestSign2652=== PAUSE TestSign2653=== RUN TestSignBatch2654=== PAUSE TestSignBatch2655=== RUN TestNilKeyPublicKey2656=== PAUSE TestNilKeyPublicKey2657=== RUN TestSignErrors2658=== PAUSE TestSignErrors2659=== CONT TestExternalSigner2660=== CONT TestSignBatch2661=== CONT TestExternalSignerCancellation2662=== CONT TestExternalSignerProgramErrorKeepsProcess2663=== CONT TestSign2664=== CONT TestParseSigningKey2665=== RUN TestParseSigningKey/valid_32-byte_key2666=== PAUSE TestParseSigningKey/valid_32-byte_key2667=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2668=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2669=== RUN TestParseSigningKey/no_colon2670=== PAUSE TestParseSigningKey/no_colon2671=== RUN TestParseSigningKey/empty_name2672=== CONT TestExternalSignerRejectsInvalidPublicKey2673=== RUN TestExternalSignerRejectsInvalidPublicKey/#002674=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002675=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2676=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2677=== PAUSE TestParseSigningKey/empty_name2678=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2679=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2680=== CONT TestGenerateFingerprint2681=== CONT TestSignErrors2682=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2683=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2684=== RUN TestSignErrors/nil_key2685=== CONT TestExternalSignerClose2686=== PAUSE TestSignErrors/nil_key2687=== RUN TestSignErrors/nil_narinfo2688=== PAUSE TestSignErrors/nil_narinfo2689=== RUN TestSignErrors/invalid_narinfo2690=== PAUSE TestSignErrors/invalid_narinfo2691=== RUN TestSignErrors/canceled2692=== PAUSE TestSignErrors/canceled2693=== CONT TestSignErrors/nil_key2694=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2695=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2696=== CONT TestExternalSignerErrors2697=== CONT TestExternalSignerRestartsAfterCrash2698=== CONT TestExternalSignerWrongPublicKey2699=== CONT TestNilKeyPublicKey2700=== CONT TestSignErrors/invalid_narinfo2701=== RUN TestExternalSignerErrors/null_signatures2702=== CONT TestSignErrors/canceled2703=== CONT TestExternalSignerRejectsInvalidPublicKey/#002704=== CONT TestSignErrors/nil_narinfo2705=== RUN TestGenerateFingerprint/basic_with_references2706=== PAUSE TestGenerateFingerprint/basic_with_references2707=== RUN TestGenerateFingerprint/no_references2708=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2709--- PASS: TestSignBatch (0.00s)2710=== PAUSE TestGenerateFingerprint/no_references2711=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2712=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2713=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2714=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2715=== RUN TestGenerateFingerprint/invalid_nar_hash_length2716=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2717=== RUN TestGenerateFingerprint/invalid_store_path_prefix2718=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2719=== RUN TestGenerateFingerprint/invalid_reference_prefix2720=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2721=== CONT TestGenerateFingerprint/basic_with_references2722=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2723=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2724=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2725=== RUN TestParseSigningKey/invalid_base642726=== PAUSE TestParseSigningKey/invalid_base642727=== RUN TestParseSigningKey/wrong_length2728=== PAUSE TestParseSigningKey/wrong_length2729=== CONT TestGenerateFingerprint/invalid_store_path_prefix2730=== CONT TestGenerateFingerprint/invalid_reference_prefix2731=== CONT TestParseSigningKey/valid_32-byte_key2732=== PAUSE TestExternalSignerErrors/null_signatures2733=== RUN TestExternalSignerErrors/unrequested_key2734=== PAUSE TestExternalSignerErrors/unrequested_key2735=== RUN TestExternalSignerErrors/program_error2736=== PAUSE TestExternalSignerErrors/program_error2737=== RUN TestExternalSignerErrors/exit_at_startup2738=== PAUSE TestExternalSignerErrors/exit_at_startup2739=== RUN TestExternalSignerErrors/exit_on_request2740=== PAUSE TestExternalSignerErrors/exit_on_request2741=== RUN TestExternalSignerErrors/null2742=== PAUSE TestExternalSignerErrors/null2743=== RUN TestExternalSignerErrors/missing_signature_name2744=== PAUSE TestExternalSignerErrors/missing_signature_name2745=== RUN TestExternalSignerErrors/invalid_JSON2746=== PAUSE TestExternalSignerErrors/invalid_JSON2747=== RUN TestExternalSignerErrors/too_few_signatures2748=== PAUSE TestExternalSignerErrors/too_few_signatures2749=== RUN TestExternalSignerErrors/invalid_signature_base642750=== PAUSE TestExternalSignerErrors/invalid_signature_base642751=== RUN TestExternalSignerErrors/wrong_signature_length2752=== PAUSE TestExternalSignerErrors/wrong_signature_length2753=== RUN TestExternalSignerErrors/wrong_signatures_shape2754=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2755=== RUN TestExternalSignerErrors/wrong_signature_name2756=== PAUSE TestExternalSignerErrors/wrong_signature_name2757=== RUN TestExternalSignerErrors/wrong_shape2758=== PAUSE TestExternalSignerErrors/wrong_shape2759=== RUN TestExternalSignerErrors/wrong_id2760=== PAUSE TestExternalSignerErrors/wrong_id2761=== RUN TestExternalSignerErrors/missing_signatures2762=== PAUSE TestExternalSignerErrors/missing_signatures2763=== CONT TestExternalSignerErrors/null_signatures2764=== CONT TestGenerateFingerprint/invalid_nar_hash_length2765=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2766=== CONT TestGenerateFingerprint/no_references2767--- PASS: TestNilKeyPublicKey (0.00s)2768=== CONT TestExternalSignerErrors/missing_signatures2769=== CONT TestExternalSignerErrors/invalid_JSON2770=== CONT TestExternalSignerErrors/exit_at_startup2771=== CONT TestParseSigningKey/invalid_base642772=== CONT TestExternalSignerErrors/wrong_shape2773=== CONT TestParseSigningKey/empty_name2774=== CONT TestParseSigningKey/no_colon2775=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2776=== CONT TestExternalSignerErrors/missing_signature_name2777=== CONT TestExternalSignerErrors/wrong_signature_name2778=== CONT TestExternalSignerErrors/null2779=== CONT TestExternalSignerErrors/invalid_signature_base642780=== CONT TestExternalSignerErrors/exit_on_request2781=== CONT TestExternalSignerErrors/unrequested_key2782=== CONT TestExternalSignerErrors/program_error2783=== CONT TestParseSigningKey/wrong_length2784=== CONT TestExternalSignerErrors/wrong_signature_length2785=== CONT TestExternalSignerErrors/wrong_signatures_shape2786=== CONT TestExternalSignerErrors/wrong_id2787--- PASS: TestSignErrors (0.00s)2788 --- PASS: TestSignErrors/nil_key (0.00s)2789 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2790 --- PASS: TestSignErrors/canceled (0.00s)2791 --- PASS: TestSignErrors/nil_narinfo (0.00s)2792--- PASS: TestSign (0.00s)2793=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2794--- PASS: TestExternalSignerClose (0.01s)2795--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2796 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2797 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2798 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2799 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2800 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2801--- PASS: TestGenerateFingerprint (0.00s)2802 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2803 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2804 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2805 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2806 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2807 --- PASS: TestGenerateFingerprint/no_references (0.00s)2808 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2809=== CONT TestExternalSignerErrors/too_few_signatures2810--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.01s)2811--- PASS: TestParseSigningKey (0.00s)2812 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2813 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2814 --- PASS: TestParseSigningKey/no_colon (0.00s)2815 --- PASS: TestParseSigningKey/wrong_length (0.00s)2816 --- PASS: TestParseSigningKey/empty_name (0.00s)2817 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2818--- PASS: TestExternalSignerWrongPublicKey (0.01s)2819--- PASS: TestExternalSigner (0.02s)2820--- PASS: TestExternalSignerCancellation (0.02s)2821--- PASS: TestExternalSignerRestartsAfterCrash (0.02s)2822--- PASS: TestExternalSignerErrors (0.00s)2823 --- PASS: TestExternalSignerErrors/null (0.01s)2824 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2825 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2826 --- PASS: TestExternalSignerErrors/missing_signatures (0.02s)2827 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2828 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2829 --- PASS: TestExternalSignerErrors/program_error (0.01s)2830 --- PASS: TestExternalSignerErrors/missing_signature_name (0.02s)2831 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2832 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2833 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.02s)2834 --- PASS: TestExternalSignerErrors/wrong_shape (0.02s)2835 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.02s)2836 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2837 --- PASS: TestExternalSignerErrors/invalid_JSON (0.02s)2838 --- PASS: TestExternalSignerErrors/null_signatures (0.02s)2839PASS2840Running OpenBao signer tests...2841=== RUN TestSign2842=== PAUSE TestSign2843=== RUN TestSignErrors2844=== PAUSE TestSignErrors2845=== RUN TestServe2846=== PAUSE TestServe2847=== RUN TestServeRejectsGarbage2848=== PAUSE TestServeRejectsGarbage2849=== CONT TestSign2850=== CONT TestServeRejectsGarbage2851--- PASS: TestServeRejectsGarbage (0.00s)2852=== CONT TestServe2853--- PASS: TestServe (0.00s)2854=== CONT TestSignErrors2855=== RUN TestSignErrors/http_error2856=== PAUSE TestSignErrors/http_error2857=== RUN TestSignErrors/invalid_json2858=== PAUSE TestSignErrors/invalid_json2859=== RUN TestSignErrors/no_prefix2860=== PAUSE TestSignErrors/no_prefix2861=== RUN TestSignErrors/invalid_base642862=== PAUSE TestSignErrors/invalid_base642863=== CONT TestSignErrors/http_error2864=== CONT TestSignErrors/invalid_base642865=== CONT TestSignErrors/no_prefix2866=== CONT TestSignErrors/invalid_json2867--- PASS: TestSign (3.99s)2868--- PASS: TestSignErrors (0.00s)2869 --- PASS: TestSignErrors/no_prefix (3.98s)2870 --- PASS: TestSignErrors/invalid_json (3.98s)2871 --- PASS: TestSignErrors/invalid_base64 (3.98s)2872 --- PASS: TestSignErrors/http_error (3.98s)2873PASS