niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #439
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestUploadMultipart_PartsInParallel18=== PAUSE TestUploadMultipart_PartsInParallel19=== RUN TestUploadMultipart_FailedPartBufferNotReused20=== PAUSE TestUploadMultipart_FailedPartBufferNotReused21=== RUN TestPartSizeForNAR22=== PAUSE TestPartSizeForNAR23=== RUN TestUploadMultipart_SupersededByPeer24=== PAUSE TestUploadMultipart_SupersededByPeer25=== RUN TestDumpPathCaseHackMatchesNix26--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)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 TestSetClientTLS117=== CONT TestStreamPushReportsSignatures118=== CONT TestDoWithRetry_BodyReplayedViaGetBody119=== CONT TestStreamPushBatchesUnderLoad120=== CONT TestStreamPushReportsEveryPath121=== CONT TestShellSplitErrors122=== CONT TestShellSplit123--- PASS: TestShellSplitErrors (0.00s)124=== CONT TestDumpPathWriterError125=== CONT TestDoWithRetry_FinalResponseBodyReadable126=== CONT TestStreamPushIsolatesFailures127=== CONT TestStreamPushStopsWhenCanceled128=== CONT TestClientSignaturesByStorePath129=== CONT TestPathInfoHashCompatibility130=== CONT TestStreamPushRequestLine131=== CONT TestRetryTimeoutOutlastsMaxRetries132=== CONT TestStreamPushGivesUpOnDeadServer1332026/10/27 08:15:51 ERROR Upload failed error="bad path" count=3134=== CONT TestScriptTokenNoExpiryRerunsEveryCall135=== CONT TestScriptTokenEmptyCommand136=== CONT TestFileTokenReadsAndCaches137=== CONT TestScriptTokenScriptFails138=== CONT TestFileTokenEmpty139=== CONT TestScriptTokenBadJSON140=== CONT TestScriptTokenEmptyToken141=== CONT TestFileTokenMissing142=== CONT TestScriptTokenCachesUntilRefresh143--- PASS: TestShellSplit (0.00s)144=== CONT TestResolveStorePath145=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer1462026/10/27 08:15:51 ERROR Upload failed error=boom count=1147=== CONT TestPathInfoCACompatibility1482026/10/27 08:15:51 ERROR Upload failed error="connection refused" count=20149=== RUN TestPathInfoCACompatibility/null_ca_field1502026/10/27 08:15:51 ERROR Server seems unavailable, giving up on batch untried=17151--- PASS: TestStreamPushReportsEveryPath (0.00s)152--- PASS: TestStreamPushStopsWhenCanceled (0.00s)153--- PASS: TestClientSignaturesByStorePath (0.00s)154=== CONT TestParsePathInfoJSONMultiplePaths155=== CONT TestParsePathInfoJSON156=== CONT TestGetStorePathHash157--- PASS: TestStreamPushIsolatesFailures (0.00s)158--- PASS: TestStreamPushReportsSignatures (0.00s)159--- PASS: TestScriptTokenEmptyCommand (0.00s)160--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)161=== CONT TestConvertHashToNix321622026/10/27 08:15:51 ERROR Upload failed error=boom count=1163--- PASS: TestFileTokenReadsAndCaches (0.00s)164=== CONT TestEncodeNixBase32165=== PAUSE TestPathInfoCACompatibility/null_ca_field166--- PASS: TestResolveStorePath (0.00s)167=== CONT TestEncodeNixBase32WithRealHash168--- PASS: TestEncodeNixBase32WithRealHash (0.00s)169=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess170=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)1712026/10/27 08:15:51 WARN Rate limiter enabled after throttle name=server-test rate=5172=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths173=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths174=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths175=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths176=== RUN TestConvertHashToNix32/SRI_format_to_Nix32177=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32178=== CONT TestUploadMultipart_PartsInParallel1792026/10/27 08:15:51 WARN Rate limiter enabled after throttle name=server-test rate=5180--- PASS: TestFileTokenEmpty (0.00s)181--- PASS: TestScriptTokenScriptFails (0.00s)182=== CONT TestDumpPathSingleFile183=== CONT TestUploadMultipart_SupersededByPeer184=== CONT TestDumpPathMatchesNix185=== RUN TestEncodeNixBase32/test_string_hash1862026/10/27 08:15:51 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:35739187=== RUN TestGetStorePathHash/valid_store_path188=== CONT TestSupersededNARStillUploadsListing1892026/10/27 08:15:51 WARN Rate limiter enabled after throttle name=server-test rate=5190--- PASS: TestDoServerRequestAttachesToken (0.01s)1912026/10/27 08:15:51 WARN Rate limiter backed off name=server-test rate=5192=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)1932026/10/27 08:15:51 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:357391942026/10/27 08:15:51 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:38633195=== PAUSE TestEncodeNixBase32/test_string_hash196=== RUN TestEncodeNixBase32/empty_input197=== RUN TestParsePathInfoJSON/Nix_format198=== PAUSE TestGetStorePathHash/valid_store_path1992026/10/27 08:15:51 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:46077200=== RUN TestConvertHashToNix32/already_Nix32_format201=== RUN TestGetStorePathHash/basename_without_hyphen_should_error202=== RUN TestPathInfoCACompatibility/old_string_format_-_text203=== RUN TestUploadMultipart_SupersededByPeer/exists204=== RUN TestSupersededNARStillUploadsListing/small_NAR205--- PASS: TestScriptTokenBadJSON (0.00s)206=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon207=== CONT TestPartSizeForNAR208=== RUN TestPartSizeForNAR/zero_stays_at_minimum209=== CONT TestStreamPushReportsSkippedPaths210=== PAUSE TestParsePathInfoJSON/Nix_format211=== PAUSE TestConvertHashToNix32/already_Nix32_format212=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error213=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error214--- PASS: TestScriptTokenEmptyToken (0.01s)215--- PASS: TestFileTokenMissing (0.01s)216=== RUN TestConvertHashToNix32/invalid_format217=== RUN TestParsePathInfoJSON/Lix_format218=== RUN TestSetClientTLS/rejects_connection_without_client_cert219=== PAUSE TestEncodeNixBase32/empty_input220=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text221=== CONT TestUploadMultipart_FailedPartBufferNotReused222=== PAUSE TestSupersededNARStillUploadsListing/small_NAR223=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon224=== RUN TestSupersededNARStillUploadsListing/dump_cut_short2252026/10/27 08:15:51 WARN Rate limiter backed off name=server-test rate=5226=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error227=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive228=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum229=== PAUSE TestUploadMultipart_SupersededByPeer/exists230--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.05s)231--- PASS: TestStreamPushReportsSkippedPaths (0.04s)232=== RUN TestUploadMultipart_SupersededByPeer/missing233=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI234=== CONT TestStaticToken235=== PAUSE TestConvertHashToNix32/invalid_format236=== PAUSE TestParsePathInfoJSON/Lix_format237=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert238=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error239=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short240=== RUN TestPartSizeForNAR/small_stays_at_minimum241=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive242=== CONT TestSetClientTLSErrors243=== RUN TestPathInfoCACompatibility/new_structured_format_-_text244=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI245--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.05s)246--- PASS: TestDumpPathSingleFile (0.04s)247--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)248=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails249=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun250=== PAUSE TestUploadMultipart_SupersededByPeer/missing251--- PASS: TestStaticToken (0.00s)252=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica253=== CONT TestRegisterUploadedObjectReusesConnections254=== CONT TestSetClientTLSDoesNotMutateDefaultTransport2552026/10/27 08:15:51 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:38633256=== RUN TestParsePathInfoJSON/empty_input257=== PAUSE TestParsePathInfoJSON/empty_input258=== RUN TestParsePathInfoJSON/whitespace_only259=== PAUSE TestParsePathInfoJSON/whitespace_only260=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error261=== CONT TestFilterOversizedClosures262=== RUN TestFilterOversizedClosures/no_limit_keeps_everything263=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything264=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped265=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped266=== RUN TestFilterOversizedClosures/all_closures_skipped267=== PAUSE TestFilterOversizedClosures/all_closures_skipped268=== RUN TestParsePathInfoJSON/invalid_JSON269=== PAUSE TestParsePathInfoJSON/invalid_JSON270=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry2712026/10/27 08:15:51 INFO Garbage collection started2722026/10/27 08:15:51 INFO Garbage collection started273=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA274=== CONT TestEncodeNixBase32/test_string_hash275=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA276--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.07s)277=== PAUSE TestPartSizeForNAR/small_stays_at_minimum2782026/10/27 08:15:51 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:38633279=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum280=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum281=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts282=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts283=== RUN TestPartSizeForNAR/1_TiB284=== PAUSE TestPartSizeForNAR/1_TiB285=== RUN TestPartSizeForNAR/5_TiB_S3_max_object286=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object287=== RUN TestPartSizeForNAR/capped_at_5_GiB288=== PAUSE TestPartSizeForNAR/capped_at_5_GiB289=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths290=== CONT TestConvertHashToNix32/invalid_format291=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths292=== CONT TestConvertHashToNix32/already_Nix32_format293=== CONT TestUploadMultipart_SupersededByPeer/exists294=== CONT TestUploadMultipart_SupersededByPeer/missing295=== CONT TestRateLimiterFeedback296=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails297=== RUN TestSetClientTLS/preserves_debug_logging_transport298=== PAUSE TestSetClientTLS/preserves_debug_logging_transport299--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)300=== CONT TestEncodeNixBase32/empty_input301--- PASS: TestEncodeNixBase32 (0.04s)302 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)303 --- PASS: TestEncodeNixBase32/empty_input (0.00s)304=== CONT TestFilterOversizedClosures/all_closures_skipped305=== CONT TestGetStorePathHash/valid_store_path3062026/10/27 08:15:51 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50307=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error308=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error3092026/10/27 08:15:51 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=0310=== CONT TestParsePathInfoJSON/invalid_JSON311=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3122026/10/27 08:15:51 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000313=== CONT TestParsePathInfoJSON/empty_input314=== CONT TestParsePathInfoJSON/whitespace_only315=== CONT TestPartSizeForNAR/zero_stays_at_minimum316=== CONT TestParsePathInfoJSON/Lix_format3172026/10/27 08:15:51 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:38633318=== CONT TestPartSizeForNAR/capped_at_5_GiB319=== CONT TestSupersededNARStillUploadsListing/small_NAR320--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)321=== CONT TestCaseHackSuffix322=== RUN TestRateLimiterFeedback/429_enables_limiter3232026/10/27 08:15:51 INFO Uploading abc-hello (1.0GB)324=== PAUSE TestRateLimiterFeedback/429_enables_limiter325=== RUN TestSetClientTLSErrors/missing_cert_file326=== CONT TestConvertHashToNix32/SRI_format_to_Nix32327=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512328=== CONT TestFilterOversizedClosures/no_limit_keeps_everything329=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text330=== CONT TestParsePathInfoJSON/Nix_format331=== CONT TestGetStorePathHash/basename_without_hyphen_should_error332--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)333 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)334 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)335=== CONT TestPartSizeForNAR/5_TiB_S3_max_object336=== CONT TestSetClientTLS/rejects_connection_without_client_cert3372026/10/27 08:15:51 WARN Garbage collection finished on another replica. Its statistics are not available here338=== CONT TestSetClientTLS/preserves_debug_logging_transport3392026/10/27 08:15:51 WARN Rate limiter enabled after throttle name=s3-test rate=53402026/10/27 08:15:51 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:45417341=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA3422026/10/27 08:15:51 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:38633343=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails344=== CONT TestPartSizeForNAR/1_TiB345=== RUN TestRateLimiterFeedback/503_enables_limiter346=== PAUSE TestSetClientTLSErrors/missing_cert_file347=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts348=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512349=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method350=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum351=== CONT TestPartSizeForNAR/small_stays_at_minimum352--- PASS: TestParsePathInfoJSON (0.07s)353 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)354 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)355 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)356 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)357 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)358=== CONT TestSupersededNARStillUploadsListing/dump_cut_short359=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)3602026/10/27 08:15:51 INFO Uploading abc-hello (1.0GB)361--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)362--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.00s)3632026/10/27 08:15:51 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:38633364=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method365=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI366=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon367=== CONT TestPathInfoCACompatibility/null_ca_field368=== PAUSE TestRateLimiterFeedback/503_enables_limiter369=== RUN TestSetClientTLSErrors/missing_key_file370=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method371--- PASS: TestPartSizeForNAR (0.07s)372 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)373 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)374 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)375 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)376 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)377 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)378 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)379=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512380=== CONT TestPathInfoCACompatibility/new_structured_format_-_text381=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive382--- PASS: TestUploadMultipart_SupersededByPeer (0.07s)383 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)384 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)385--- PASS: TestConvertHashToNix32 (0.04s)386 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)387 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)388 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)389--- PASS: TestFilterOversizedClosures (0.00s)390 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)391 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)392 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)393--- PASS: TestGetStorePathHash (0.07s)394 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)395 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)396 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)397 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)398=== CONT TestPathInfoCACompatibility/old_string_format_-_text399=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter4002026/10/27 08:15:51 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:38633401=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter402=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter403=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter404=== CONT TestRateLimiterFeedback/429_enables_limiter405--- PASS: TestPathInfoCACompatibility (0.09s)406 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.14s)407 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.14s)408 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)409 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)410 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)411--- PASS: TestPathInfoHashCompatibility (0.08s)412 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)413 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.14s)414 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.14s)415 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)416=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter4172026/10/27 08:15:51 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:38633418=== CONT TestRateLimiterFeedback/503_enables_limiter4192026/10/27 08:15:51 WARN Rate limiter enabled after throttle name=server-test rate=54202026/10/27 08:15:51 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:36381421=== PAUSE TestSetClientTLSErrors/missing_key_file422=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter4232026/10/27 08:15:51 WARN Rate limiter backed off name=server-test rate=5424=== RUN TestSetClientTLSErrors/missing_ca_file4252026/10/27 08:15:51 WARN Rate limiter enabled after throttle name=server-test rate=5426=== PAUSE TestSetClientTLSErrors/missing_ca_file4272026/10/27 08:15:51 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:46379428=== RUN TestSetClientTLSErrors/invalid_ca_file4292026/10/27 08:15:51 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:38633430=== PAUSE TestSetClientTLSErrors/invalid_ca_file431=== CONT TestSetClientTLSErrors/missing_cert_file432=== CONT TestSetClientTLSErrors/missing_ca_file4332026/10/27 08:15:51 WARN Rate limiter backed off name=server-test rate=5434--- PASS: TestRateLimiterFeedback (0.16s)435 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)436 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)437 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)438 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)439=== CONT TestSetClientTLSErrors/invalid_ca_file440=== CONT TestSetClientTLSErrors/missing_key_file4412026/10/27 08:15:51 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:38633442--- PASS: TestSetClientTLSErrors (0.16s)443 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)444 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)445 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)446 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)447--- PASS: TestStreamPushBatchesUnderLoad (0.24s)448--- PASS: TestCaseHackSuffix (0.16s)4492026/10/27 08:15:51 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:386334502026/10/27 08:15:51 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:386334512026/10/27 08:15:51 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:386334522026/10/27 08:15:51 http: TLS handshake error from 127.0.0.1:44904: remote error: tls: bad certificate4532026/10/27 08:15:51 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:38633454--- PASS: TestSetClientTLS (0.08s)455 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.16s)456 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.16s)457 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.17s)4582026/10/27 08:15:51 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:386334592026/10/27 08:15:51 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:386334602026/10/27 08:15:51 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:38633461--- PASS: TestStreamPushRequestLine (0.25s)4622026/10/27 08:15:51 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:386334632026/10/27 08:15:51 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:38633464--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.25s)4652026/10/27 08:15:51 INFO Uploading abc-hello (1.0GB)466--- PASS: TestRegisterUploadedObjectReusesConnections (0.18s)4672026/10/27 08:15:51 WARN Rate limiter enabled after throttle name=s3-test rate=5468--- PASS: TestDumpPathWriterError (0.26s)4692026/10/27 08:15:52 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:42571/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:42571/part/24702026/10/27 08:15:52 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"471--- PASS: TestDumpPathMatchesNix (0.31s)472--- PASS: TestSupersededNARStillUploadsListing (0.07s)473 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.16s)474 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.16s)475 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.71s)476--- PASS: TestUploadMultipart_FailedPartBufferNotReused (0.76s)477--- PASS: TestUploadMultipart_PartsInParallel (0.83s)4782026/10/27 08:15:52 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:37527/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:37527/api/uploads/complete4792026/10/27 08:15:52 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4802026/10/27 08:15:52 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:37527/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:37527/api/uploads/complete4812026/10/27 08:15:52 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4822026/10/27 08:15:52 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:37527/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:37527/api/uploads/complete4832026/10/27 08:15:52 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"484--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)485--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)486PASS487Running server tests...488The files belonging to this database system will be owned by user "nixbld".489This user must also own the server process.490491The database cluster will be initialized with locale "C".492The default database encoding has accordingly been set to "SQL_ASCII".493The default text search configuration will be set to "english".494495Data page checksums are enabled.496497creating directory /build/postgres766301995/data ... ok498creating subdirectories ... ok499selecting dynamic shared memory implementation ... posix500selecting default "max_connections" ... 100501selecting default "shared_buffers" ... 128MB502selecting default time zone ... UTC503creating configuration files ... ok504running bootstrap script ... ok505performing post-bootstrap initialization ... ok506syncing data to disk ... ok507508initdb: warning: enabling "trust" authentication for local connections509initdb: 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.510511Success. You can now start the database server using:512513 pg_ctl -D /build/postgres766301995/data -l logfile start514515/build/postgres766301995:5432 - no response5162026-10-27 08:15:53.565 UTC [128] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit5172026-10-27 08:15:53.566 UTC [128] LOG: listening on Unix socket "/build/postgres766301995/.s.PGSQL.5432"5182026-10-27 08:15:53.570 UTC [135] LOG: database system was shut down at 2026-10-27 08:15:53 UTC5192026-10-27 08:15:53.574 UTC [128] LOG: database system is ready to accept connections520/build/postgres766301995:5432 - accepting connections521=== RUN TestService_AuthMiddleware522=== PAUSE TestService_AuthMiddleware523=== RUN TestService_AuthMiddleware_MTLSProxyHeader524=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader525=== RUN TestService_AuthMiddleware_MTLSBoundSubjects526=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects527=== RUN TestService_ReadAuthMiddleware528=== PAUSE TestService_ReadAuthMiddleware529=== RUN TestService_AuthMiddleware_OIDC530=== PAUSE TestService_AuthMiddleware_OIDC531=== RUN TestService_RequireScope_OIDC532=== PAUSE TestService_RequireScope_OIDC533=== RUN TestService_ReadScope_PublicByDefault534=== PAUSE TestService_ReadScope_PublicByDefault535=== RUN TestCacheConfigHandler536=== PAUSE TestCacheConfigHandler537=== RUN TestCacheStatsHandler538=== PAUSE TestCacheStatsHandler539=== RUN TestClientCADerivations540=== PAUSE TestClientCADerivations541=== RUN TestClientErrorHandling542=== PAUSE TestClientErrorHandling543=== RUN TestClientIntegration544=== PAUSE TestClientIntegration545=== RUN TestClientMultipleUploads546=== PAUSE TestClientMultipleUploads547=== RUN TestClientWithDependencies548=== PAUSE TestClientWithDependencies549=== RUN TestClientSharedPathCommittedMidPush550=== PAUSE TestClientSharedPathCommittedMidPush551=== RUN TestPinProtectsFromGC552=== PAUSE TestPinProtectsFromGC553=== RUN TestClientPushesUseOnePush554=== PAUSE TestClientPushesUseOnePush555=== RUN TestClientFallsBackToClosures556=== PAUSE TestClientFallsBackToClosures557=== RUN TestDeleteClosuresRacingPins558=== PAUSE TestDeleteClosuresRacingPins559=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock560=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock561=== RUN TestResolveDBConnectionString562=== PAUSE TestResolveDBConnectionString563=== RUN TestConnectWaitsForAPeerMigration564=== PAUSE TestConnectWaitsForAPeerMigration565=== RUN TestLeadElectsOneAndHandsOver566=== PAUSE TestLeadElectsOneAndHandsOver567=== RUN TestLeadIncumbentWinsAfterRestart5682026/10/27 08:15:54 INFO lead: acquired remote=192.0.2.1:12345692026/10/27 08:15:54 INFO lead: released remote=192.0.2.1:12345702026/10/27 08:15:54 INFO lead: acquired remote=192.0.2.1:12345712026/10/27 08:15:55 INFO lead: released remote=192.0.2.1:1234572--- PASS: TestLeadIncumbentWinsAfterRestart (1.90s)573=== RUN TestLeadIncumbentAnnouncesAtOnce574=== PAUSE TestLeadIncumbentAnnouncesAtOnce575=== RUN TestLeadEndsOnShutdown576=== PAUSE TestLeadEndsOnShutdown577=== RUN TestLeadEndsWhenItsConnectionHangs5782026/10/27 08:15:56 INFO lead: acquired remote=192.0.2.1:12345792026-10-27 08:15:57.399 UTC [575] FATAL: terminating connection due to administrator command5802026/10/27 08:15:57 INFO lead: acquired remote=192.0.2.1:12345812026/10/27 08:15:58 WARN lead: lock connection lost error="timeout: context deadline exceeded"5822026/10/27 08:15:58 INFO lead: released remote=192.0.2.1:12345832026/10/27 08:15:58 INFO lead: released remote=192.0.2.1:1234584--- PASS: TestLeadEndsWhenItsConnectionHangs (2.92s)585=== RUN TestGCAdvisoryLockBlocksConcurrentRun586=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun587=== RUN TestGCBugBareHashReferences588=== PAUSE TestGCBugBareHashReferences589=== RUN TestGCMetrics590=== PAUSE TestGCMetrics591=== RUN TestPushDedupSurvivesConcurrentGC592=== PAUSE TestPushDedupSurvivesConcurrentGC593=== RUN TestDeduplicatedObjectsRecordedAsPending594=== PAUSE TestDeduplicatedObjectsRecordedAsPending595=== RUN TestGCSweepSkipsPendingObjects596=== PAUSE TestGCSweepSkipsPendingObjects597=== RUN TestTombstonedObjectOfferedWithoutWaiting598=== PAUSE TestTombstonedObjectOfferedWithoutWaiting599=== RUN TestGCSweepDeliversEachKeyOnce600=== PAUSE TestGCSweepDeliversEachKeyOnce601=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection602=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection603=== RUN TestForceGCDuringPushOffersSweptObject604=== PAUSE TestForceGCDuringPushOffersSweptObject605=== RUN TestFailedS3DeleteKeepsTombstone606=== PAUSE TestFailedS3DeleteKeepsTombstone607=== RUN TestSweepSkipsRowsLockedByPush608=== PAUSE TestSweepSkipsRowsLockedByPush609=== RUN TestRegisterCompletedObjectNeedsPendingRow610=== PAUSE TestRegisterCompletedObjectNeedsPendingRow611=== RUN TestGetExistingObjectsLocksRows612=== PAUSE TestGetExistingObjectsLocksRows613=== RUN TestSweepRechecksPendingAfterLocking614=== PAUSE TestSweepRechecksPendingAfterLocking615=== RUN TestPushWaitsForSweepHoldingRow616=== PAUSE TestPushWaitsForSweepHoldingRow617=== RUN TestCommitRacingPendingCleanupKeepsObjects618=== PAUSE TestCommitRacingPendingCleanupKeepsObjects619=== RUN TestGCEndsOnShutdown620=== PAUSE TestGCEndsOnShutdown621=== RUN TestGCTaskStore_StartNew622=== PAUSE TestGCTaskStore_StartNew623=== RUN TestGCTaskStore_DeduplicateSameParams624=== PAUSE TestGCTaskStore_DeduplicateSameParams625=== RUN TestGCTaskStore_ConflictDifferentParams626=== PAUSE TestGCTaskStore_ConflictDifferentParams627=== RUN TestGCTaskStore_GetEmpty628=== PAUSE TestGCTaskStore_GetEmpty629=== RUN TestGCTaskStore_GetReturnsLatest630=== PAUSE TestGCTaskStore_GetReturnsLatest631=== RUN TestGCTaskStore_CompletedAllowsNewTask632=== PAUSE TestGCTaskStore_CompletedAllowsNewTask633=== RUN TestGCTaskStore_PhaseUpdates634=== PAUSE TestGCTaskStore_PhaseUpdates635=== RUN TestGCTaskStore_Fail636=== PAUSE TestGCTaskStore_Fail637=== RUN TestGracefulShutdownDrainsInflight638=== PAUSE TestGracefulShutdownDrainsInflight639=== RUN TestService_healthCheckHandler640=== PAUSE TestService_healthCheckHandler641=== RUN TestService_readinessHandler642=== PAUSE TestService_readinessHandler643=== RUN TestGenerateLandingPage644=== PAUSE TestGenerateLandingPage645=== RUN TestCacheConfigHandlerMaxNarSize646=== PAUSE TestCacheConfigHandlerMaxNarSize647=== RUN TestCreatePendingClosureRejectsOversizedNAR648=== PAUSE TestCreatePendingClosureRejectsOversizedNAR649=== RUN TestNARDeduplicationMetadataUploadBug650=== PAUSE TestNARDeduplicationMetadataUploadBug651=== RUN TestMetricsInventory652=== PAUSE TestMetricsInventory653=== RUN TestMetricsCommit654=== PAUSE TestMetricsCommit655=== RUN TestService_NativeMTLS656=== PAUSE TestService_NativeMTLS657=== RUN TestServerTLSConfig658=== PAUSE TestServerTLSConfig659=== RUN TestMultipartCleanup660=== PAUSE TestMultipartCleanup661=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded662=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded663=== RUN TestPendingCleanupUsesOneCutoff664=== PAUSE TestPendingCleanupUsesOneCutoff665=== RUN TestObjectStatsTrigger666=== PAUSE TestObjectStatsTrigger667=== RUN TestObjectStatsUpdatedOncePerCommit668=== PAUSE TestObjectStatsUpdatedOncePerCommit669=== RUN TestOrphanedObjectsGC670=== PAUSE TestOrphanedObjectsGC671=== RUN TestOrphanedObjectsGCStressTest672=== PAUSE TestOrphanedObjectsGCStressTest673=== RUN TestCreatePin_ReservedPins674=== PAUSE TestCreatePin_ReservedPins675=== RUN TestPresentReportsOnlyClosureRoots676=== PAUSE TestPresentReportsOnlyClosureRoots677=== RUN TestPresentRefreshesOnlyStaleClosures678=== PAUSE TestPresentRefreshesOnlyStaleClosures679=== RUN TestPresentNotReportedWhileGCDeletesClosure680=== PAUSE TestPresentNotReportedWhileGCDeletesClosure681=== RUN TestParseSingleRange682=== PAUSE TestParseSingleRange683=== RUN TestProxyHeadersOnlyTrustedOnSocket6842026/10/27 08:15:58 INFO Starting HTTP server address=127.0.0.1:328716852026/10/27 08:15:58 INFO Starting HTTP server address=proxy.sock6862026/10/27 08:15:58 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6872026/10/27 08:15:58 INFO Shutdown signal received, draining in-flight requests timeout=10s688--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.11s)689=== RUN TestIsValidCachePath690=== PAUSE TestIsValidCachePath691=== RUN TestReadProxyNarinfo692=== PAUSE TestReadProxyNarinfo693=== RUN TestReadProxyNarinfoAlreadyDecompressed694=== PAUSE TestReadProxyNarinfoAlreadyDecompressed695=== RUN TestReadProxyContentNegotiation696=== PAUSE TestReadProxyContentNegotiation697=== RUN TestReadProxyNarStreaming698=== PAUSE TestReadProxyNarStreaming699=== RUN TestReadProxy404700=== PAUSE TestReadProxy404701=== RUN TestReadProxyInvalidPath702=== PAUSE TestReadProxyInvalidPath703=== RUN TestReadProxyHead704=== PAUSE TestReadProxyHead705=== RUN TestReadProxyOutlastsServerWriteTimeout706=== PAUSE TestReadProxyOutlastsServerWriteTimeout707=== RUN TestReadProxyConditionalGet708=== PAUSE TestReadProxyConditionalGet709=== RUN TestReadProxyRootRedirectsToIndexHTML710=== PAUSE TestReadProxyRootRedirectsToIndexHTML711=== RUN TestReadProxyDisabled712=== PAUSE TestReadProxyDisabled713=== RUN TestReadRedirectNar714=== PAUSE TestReadRedirectNar715=== RUN TestReadRedirectKeepsNarinfoProxied716=== PAUSE TestReadRedirectKeepsNarinfoProxied717=== RUN TestReadProxyRangeRequest718=== PAUSE TestReadProxyRangeRequest719=== RUN TestReadRedirectUsesPublicS3URL720=== PAUSE TestReadRedirectUsesPublicS3URL721=== RUN TestPush_OverlappingRootsStoreOneRowPerKey722=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey723=== RUN TestPush_CompleteCommitsEveryRoot724=== PAUSE TestPush_CompleteCommitsEveryRoot725=== RUN TestPush_RepeatedRootCommitsOnce726=== PAUSE TestPush_RepeatedRootCommitsOnce727=== RUN TestPush_CompleteWaitsForCleanupOfThePush728=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush729=== RUN TestPush_RootsAreLockedInByteOrder730=== PAUSE TestPush_RootsAreLockedInByteOrder731=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit732=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit733=== RUN TestPush_RejectsBadRequests734=== PAUSE TestPush_RejectsBadRequests735=== RUN TestPush_SignsNarinfosOfItsPendingObjects736=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects737=== RUN TestRedundantMultipartUpload738=== PAUSE TestRedundantMultipartUpload739=== RUN TestCompleteMultipartUpload_ErrorButObjectExists740=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists741=== RUN TestCompletedNarNotReofferedAcrossClosures742=== PAUSE TestCompletedNarNotReofferedAcrossClosures743=== RUN TestPresignedUploadRegisteredBeforeCommit744=== PAUSE TestPresignedUploadRegisteredBeforeCommit745=== RUN TestService_Rustfstest746=== PAUSE TestService_Rustfstest747=== RUN TestParseSize748=== PAUSE TestParseSize749=== RUN TestSkippedUploadsHandler750=== PAUSE TestSkippedUploadsHandler751=== RUN TestSystemdListenerNotActivated752--- PASS: TestSystemdListenerNotActivated (0.00s)753=== RUN TestWatchdogBeatsWhenHealthy754--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)755=== RUN TestWatchdogSkipsWhenUnhealthy7562026/10/27 08:15:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7572026/10/27 08:15:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7582026/10/27 08:15:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7592026/10/27 08:15:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7602026/10/27 08:15:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7612026/10/27 08:15:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7622026/10/27 08:15:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7632026/10/27 08:15:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7642026/10/27 08:15:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7652026/10/27 08:15:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"766--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)767=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle768=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle769=== RUN TestProxyWriteTimeout770=== PAUSE TestProxyWriteTimeout771=== RUN TestPendingClosureWriteTimeout772=== PAUSE TestPendingClosureWriteTimeout773=== RUN TestIsValidUploadKey774=== PAUSE TestIsValidUploadKey775=== RUN TestUploadHandlersRejectInvalidKeys776=== PAUSE TestUploadHandlersRejectInvalidKeys777=== RUN TestUploadHandlersRejectOversizedBody778=== PAUSE TestUploadHandlersRejectOversizedBody779=== RUN TestService_cleanupPendingClosuresHandler780=== PAUSE TestService_cleanupPendingClosuresHandler781=== RUN TestService_createPendingClosureHandler782=== PAUSE TestService_createPendingClosureHandler783=== RUN TestService_verifyS3Integrity784=== PAUSE TestService_verifyS3Integrity785=== RUN TestCompleteMultipartUnregistered786=== PAUSE TestCompleteMultipartUnregistered787=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT788=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT789=== CONT TestService_AuthMiddleware790=== CONT TestMetricsInventory791=== CONT TestGCTaskStore_DeduplicateSameParams792--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)793=== CONT TestUploadHandlersRejectInvalidKeys794=== CONT TestCompleteMultipartUnregistered795=== CONT TestNARDeduplicationMetadataUploadBug796=== CONT TestCreatePendingClosureRejectsOversizedNAR797=== CONT TestCacheConfigHandlerMaxNarSize798=== CONT TestGenerateLandingPage7992026/10/27 08:15:59 INFO Received uploads request method=POST path=/api/pending_closures800=== CONT TestService_readinessHandler801=== CONT TestService_healthCheckHandler802=== CONT TestGracefulShutdownDrainsInflight803=== CONT TestGCTaskStore_Fail804=== CONT TestProxyWriteTimeout805=== CONT TestGCTaskStore_PhaseUpdates806=== CONT TestGCTaskStore_CompletedAllowsNewTask807=== CONT TestGCTaskStore_GetReturnsLatest808=== CONT TestGCTaskStore_GetEmpty809=== CONT TestReadRedirectKeepsNarinfoProxied810=== CONT TestGCTaskStore_ConflictDifferentParams811=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT812=== CONT TestService_verifyS3Integrity813=== CONT TestService_createPendingClosureHandler814=== CONT TestService_cleanupPendingClosuresHandler815=== CONT TestUploadHandlersRejectOversizedBody816=== CONT TestDeduplicatedObjectsRecordedAsPending8172026/10/27 08:15:59 INFO Starting HTTP server address=127.0.0.1:44619818=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info819--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)820=== CONT TestIsValidUploadKey821=== CONT TestPendingClosureWriteTimeout822=== RUN TestProxyWriteTimeout/narinfo823=== PAUSE TestProxyWriteTimeout/narinfo824=== RUN TestProxyWriteTimeout/1_GiB_nar825=== PAUSE TestProxyWriteTimeout/1_GiB_nar826=== RUN TestProxyWriteTimeout/10_GiB_nar827=== PAUSE TestProxyWriteTimeout/10_GiB_nar828=== RUN TestProxyWriteTimeout/unknown_size829=== PAUSE TestProxyWriteTimeout/unknown_size830=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle831=== RUN TestIsValidUploadKey/narinfo832=== CONT TestPresignedUploadRegisteredBeforeCommit833=== CONT TestSkippedUploadsHandler834=== CONT TestParseSize835=== CONT TestService_Rustfstest836--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)837=== CONT TestCompletedNarNotReofferedAcrossClosures8382026/10/27 08:15:59 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000839--- PASS: TestGCTaskStore_Fail (0.00s)8402026/10/27 08:15:59 INFO Shutdown signal received, draining in-flight requests timeout=10s841--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)842=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info843=== RUN TestPendingClosureWriteTimeout/empty844=== CONT TestCompleteMultipartUpload_ErrorButObjectExists845=== PAUSE TestIsValidUploadKey/narinfo846=== CONT TestRedundantMultipartUpload847--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)848--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)849--- PASS: TestGCTaskStore_GetEmpty (0.00s)850--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)851--- PASS: TestParseSize (0.00s)852--- PASS: TestGenerateLandingPage (0.01s)853=== RUN TestIsValidUploadKey/nar_zst854=== PAUSE TestIsValidUploadKey/nar_zst855--- PASS: TestSkippedUploadsHandler (0.02s)856=== CONT TestPush_SignsNarinfosOfItsPendingObjects857=== PAUSE TestPendingClosureWriteTimeout/empty858=== RUN TestPendingClosureWriteTimeout/400_objects859=== PAUSE TestPendingClosureWriteTimeout/400_objects860=== RUN TestPendingClosureWriteTimeout/670k_objects861=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal862=== RUN TestIsValidUploadKey/nar_xz863--- PASS: TestGracefulShutdownDrainsInflight (0.09s)864=== CONT TestPush_RejectsBadRequests865=== PAUSE TestPendingClosureWriteTimeout/670k_objects866=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal867=== PAUSE TestIsValidUploadKey/nar_xz868=== RUN TestIsValidUploadKey/nar_plain869=== PAUSE TestIsValidUploadKey/nar_plain870=== RUN TestIsValidUploadKey/listing871=== PAUSE TestIsValidUploadKey/listing872=== RUN TestIsValidUploadKey/build_log873=== PAUSE TestIsValidUploadKey/build_log874=== RUN TestIsValidUploadKey/build_log_home-manager_file875=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline876=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline877=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key878=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key879=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key880=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key881=== PAUSE TestIsValidUploadKey/build_log_home-manager_file882=== RUN TestIsValidUploadKey/build_log_plus_in_name883=== PAUSE TestIsValidUploadKey/build_log_plus_in_name884=== RUN TestIsValidUploadKey/build_log_question_mark885=== PAUSE TestIsValidUploadKey/build_log_question_mark886=== RUN TestIsValidUploadKey/build_log_equals887=== PAUSE TestIsValidUploadKey/build_log_equals888=== RUN TestIsValidUploadKey/realisation889=== PAUSE TestIsValidUploadKey/realisation890=== RUN TestIsValidUploadKey/realisation_plus_in_output891=== PAUSE TestIsValidUploadKey/realisation_plus_in_output892=== RUN TestIsValidUploadKey/nix-cache-info893=== PAUSE TestIsValidUploadKey/nix-cache-info894=== RUN TestIsValidUploadKey/index.html895=== PAUSE TestIsValidUploadKey/index.html896=== RUN TestIsValidUploadKey/narinfo_key,_nar_type897=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type898=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit899=== CONT TestPush_RootsAreLockedInByteOrder900=== RUN TestIsValidUploadKey/nar_key,_narinfo_type901=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type902=== RUN TestIsValidUploadKey/listing_key,_narinfo_type903=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type904=== RUN TestIsValidUploadKey/traversal905=== PAUSE TestIsValidUploadKey/traversal906=== RUN TestIsValidUploadKey/traversal_nar907=== PAUSE TestIsValidUploadKey/traversal_nar908=== RUN TestIsValidUploadKey/absolute909=== PAUSE TestIsValidUploadKey/absolute910=== RUN TestIsValidUploadKey/empty_key911=== PAUSE TestIsValidUploadKey/empty_key912=== RUN TestIsValidUploadKey/unknown_type913=== PAUSE TestIsValidUploadKey/unknown_type914=== CONT TestPush_CompleteWaitsForCleanupOfThePush915=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts916=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts917=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure918=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure919=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart920=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart921=== CONT TestPush_RepeatedRootCommitsOnce9222026/10/27 08:15:59 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"923--- PASS: TestService_AuthMiddleware (0.53s)924=== CONT TestPush_CompleteCommitsEveryRoot925--- PASS: TestMetricsInventory (0.60s)926=== CONT TestPush_OverlappingRootsStoreOneRowPerKey9272026/10/27 08:15:59 INFO Received cleanup request method=DELETE path=/api/pending_closures9282026/10/27 08:15:59 INFO Aborted multipart uploads count=0 kept=0929=== NAME TestNARDeduplicationMetadataUploadBug930 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3410757164/001/store/467n512rcyny28rmkmllxkyarydl4m9m-file1.txt9312026/10/27 08:15:59 INFO Received uploads request method=POST path=/api/pending_closures9322026/10/27 08:15:59 INFO Received cleanup request method=DELETE path=/api/pending_closures9332026/10/27 08:15:59 INFO Received uploads request method=POST path=/api/pending_closures9342026/10/27 08:15:59 INFO Received uploads request method=POST path=/api/pending_closures9352026/10/27 08:15:59 INFO Received uploads request method=POST path=/api/pending_closures9362026/10/27 08:15:59 INFO Aborted multipart uploads count=1 kept=09372026/10/27 08:15:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9382026-10-27 08:15:59.773 UTC [649] ERROR: Closure does not exist: id=19392026-10-27 08:15:59.773 UTC [649] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9402026-10-27 08:15:59.773 UTC [649] STATEMENT: -- name: CommitPendingClosure :one941 SELECT commit_pending_closure($1::bigint)::bigint942 943--- PASS: TestService_cleanupPendingClosuresHandler (0.63s)944=== CONT TestReadRedirectUsesPublicS3URL945--- PASS: TestService_Rustfstest (0.65s)946=== CONT TestReadProxyRangeRequest9472026/10/27 08:15:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9482026/10/27 08:15:59 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst949--- PASS: TestCompleteMultipartUnregistered (0.68s)950=== CONT TestPinProtectsFromGC9512026/10/27 08:15:59 INFO Received push request method=POST path=/api/pushes9522026/10/27 08:15:59 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9532026/10/27 08:15:59 INFO Uploading 467n512rcyny28rmkmllxkyarydl4m9m-file1.txt (160B)9542026/10/27 08:15:59 WARN Failed to register uploaded object key=467n512rcyny28rmkmllxkyarydl4m9m.ls error="server returned 404: 404 page not found\n"9552026/10/27 08:15:59 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"9562026/10/27 08:15:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9572026/10/27 08:15:59 INFO Signed narinfos id=1 count=19582026/10/27 08:15:59 INFO Uploading 1 narinfos9592026/10/27 08:15:59 INFO Received complete push request method=POST path=/api/pushes/1/complete9602026/10/27 08:15:59 WARN Failed to register uploaded object key=467n512rcyny28rmkmllxkyarydl4m9m.narinfo error="server returned 404: 404 page not found\n"9612026/10/27 08:15:59 INFO Completed push id=1 objects=3 duration=9.294546ms9622026/10/27 08:15:59 INFO Upload complete. (77ms)963--- PASS: TestReadRedirectKeepsNarinfoProxied (0.72s)964=== CONT TestPushDedupSurvivesConcurrentGC965=== NAME TestNARDeduplicationMetadataUploadBug966 metadata_upload_test.go:54: Retrieved narinfo from S3:967 StorePath: /build/TestNARDeduplicationMetadataUploadBug3410757164/001/store/467n512rcyny28rmkmllxkyarydl4m9m-file1.txt968 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst969 Compression: zstd970 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf971 NarSize: 160972 References: 973 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf974 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)975 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):976 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}9772026/10/27 08:15:59 INFO Received uploads request method=POST path=/api/pending_closures978--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.74s)979=== CONT TestGCMetrics9802026/10/27 08:15:59 INFO Received uploads request method=POST path=/api/pending_closures981=== NAME TestNARDeduplicationMetadataUploadBug982 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3410757164/001/store/l2zjyss42dd1r63kdfzy0lzkbqxyrp57-file2.txt9832026/10/27 08:15:59 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9842026/10/27 08:15:59 INFO Received uploads request method=POST path=/api/pending_closures9852026/10/27 08:15:59 WARN readiness check failed error="closed pool"986--- PASS: TestService_readinessHandler (0.79s)987=== CONT TestGCBugBareHashReferences988--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.78s)989=== CONT TestGCAdvisoryLockBlocksConcurrentRun9902026/10/27 08:15:59 INFO Received uploads request method=POST path=/api/pending_closures9912026/10/27 08:15:59 INFO Received push request method=POST path=/api/pushes9922026/10/27 08:15:59 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)9932026/10/27 08:15:59 INFO Received uploads request method=POST path=/api/pending_closures9942026/10/27 08:15:59 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign9952026/10/27 08:15:59 WARN Failed to register uploaded object key=l2zjyss42dd1r63kdfzy0lzkbqxyrp57.ls error="server returned 404: 404 page not found\n"9962026/10/27 08:15:59 INFO Signed narinfos id=2 count=19972026/10/27 08:15:59 INFO Uploading 1 narinfos9982026/10/27 08:15:59 INFO Received complete push request method=POST path=/api/pushes/2/complete9992026/10/27 08:15:59 WARN Failed to register uploaded object key=l2zjyss42dd1r63kdfzy0lzkbqxyrp57.narinfo error="server returned 404: 404 page not found\n"10002026/10/27 08:15:59 INFO Completed push id=2 objects=3 duration=2.603189ms10012026/10/27 08:15:59 INFO Upload complete. (60ms)1002=== NAME TestNARDeduplicationMetadataUploadBug1003 metadata_upload_test.go:76: Retrieved narinfo from S3:1004 StorePath: /build/TestNARDeduplicationMetadataUploadBug3410757164/001/store/l2zjyss42dd1r63kdfzy0lzkbqxyrp57-file2.txt1005 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1006 Compression: zstd1007 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1008 NarSize: 1601009 References: 1010 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1011 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1012 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1013 {"version":1,"root":{"type":"regular","size":44}}1014--- PASS: TestNARDeduplicationMetadataUploadBug (0.87s)1015=== CONT TestLeadEndsOnShutdown1016--- PASS: TestService_healthCheckHandler (0.87s)1017=== CONT TestLeadIncumbentAnnouncesAtOnce10182026/10/27 08:16:00 INFO Received uploads request method=POST path=/api/pending_closures10192026/10/27 08:16:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10202026/10/27 08:16:00 INFO Received uploads request method=POST path=/api/pending_closures10212026/10/27 08:16:00 INFO Received uploads request method=POST path=/api/pending_closures1022--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.97s)1023=== CONT TestLeadElectsOneAndHandsOver10242026/10/27 08:16:00 INFO Received uploads request method=POST path=/api/pending_closures10252026/10/27 08:16:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10262026/10/27 08:16:00 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YjMxMDdhNDMtODViNy00N2I1LWE5YmMtYzNkZDM3MzNiODA1LmQyM2JhNmEzLTc4NDItNDA0OC1iNjI3LWU0NWJjNDNkNDVkOHgxNzkzMDg4OTYwMDgxNjYzMjU410272026/10/27 08:16:00 INFO Received uploads request method=POST path=/api/pending_closures10282026/10/27 08:16:00 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YjMxMDdhNDMtODViNy00N2I1LWE5YmMtYzNkZDM3MzNiODA1LmQyM2JhNmEzLTc4NDItNDA0OC1iNjI3LWU0NWJjNDNkNDVkOHgxNzkzMDg4OTYwMDgxNjYzMjU4 parts=11029--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.99s)1030=== CONT TestConnectWaitsForAPeerMigration10312026/10/27 08:16:00 INFO Received push request method=POST path=/api/pushes1032=== RUN TestPush_RejectsBadRequests/no_roots1033=== PAUSE TestPush_RejectsBadRequests/no_roots1034=== RUN TestPush_RejectsBadRequests/no_objects1035=== PAUSE TestPush_RejectsBadRequests/no_objects1036=== RUN TestPush_RejectsBadRequests/bad_root1037=== PAUSE TestPush_RejectsBadRequests/bad_root1038=== RUN TestPush_RejectsBadRequests/root_not_in_objects1039=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1040=== CONT TestResolveDBConnectionString1041=== RUN TestResolveDBConnectionString/flag_wins1042=== PAUSE TestResolveDBConnectionString/flag_wins1043=== RUN TestResolveDBConnectionString/file_when_flag_empty1044=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1045=== RUN TestResolveDBConnectionString/missing_file_is_an_error1046=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1047=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1048=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1049=== RUN TestResolveDBConnectionString/nothing_configured1050=== PAUSE TestResolveDBConnectionString/nothing_configured1051=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock10522026/10/27 08:16:00 INFO Received push request method=POST path=/api/pushes10532026/10/27 08:16:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10542026/10/27 08:16:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10552026/10/27 08:16:00 INFO Signed narinfos id=1 count=110562026/10/27 08:16:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10572026/10/27 08:16:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10582026/10/27 08:16:00 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"10592026/10/27 08:16:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10602026/10/27 08:16:00 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"10612026/10/27 08:16:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10622026/10/27 08:16:00 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=110632026/10/27 08:16:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10642026/10/27 08:16:00 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1065--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (1.06s)1066=== CONT TestDeleteClosuresRacingPins10672026/10/27 08:16:00 INFO Received push request method=POST path=/api/pushes10682026/10/27 08:16:00 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YjMxMDdhNDMtODViNy00N2I1LWE5YmMtYzNkZDM3MzNiODA1LjNiYjRhZDBkLTUzZmUtNGMyMi1hNGFmLWE4ZGRkNzRhZjUyZHgxNzkzMDg4OTU5Nzc4MDY1NDg1 parts=1010692026/10/27 08:16:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10702026/10/27 08:16:00 INFO Completed upload id=1 objects=2 duration=4.703278ms10712026/10/27 08:16:00 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010722026/10/27 08:16:00 INFO Received uploads request method=POST path=/api/pending_closures10732026/10/27 08:16:00 INFO Starting cleanup of old closures method=DELETE path=/api/closures10742026/10/27 08:16:00 INFO Aborted multipart uploads count=0 kept=010752026/10/27 08:16:00 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=010762026/10/27 08:16:00 INFO Received push request method=POST path=/api/pushes10772026/10/27 08:16:00 INFO Vacuumed table table=pending_closures10782026/10/27 08:16:00 INFO Vacuumed table table=pending_objects10792026-10-27 08:16:00.278 UTC [845] ERROR: could not obtain lock on row in relation "closures"10802026-10-27 08:16:00.278 UTC [845] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10812026-10-27 08:16:00.278 UTC [845] ERROR: could not obtain lock on row in relation "closures"10822026-10-27 08:16:00.278 UTC [845] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10832026-10-27 08:16:00.278 UTC [845] ERROR: could not obtain lock on row in relation "closures"10842026-10-27 08:16:00.278 UTC [845] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10852026-10-27 08:16:00.279 UTC [845] ERROR: could not obtain lock on row in relation "closures"10862026-10-27 08:16:00.279 UTC [845] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10872026-10-27 08:16:00.279 UTC [845] ERROR: could not obtain lock on row in relation "closures"10882026-10-27 08:16:00.279 UTC [845] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10892026/10/27 08:16:00 INFO Vacuumed table table=multipart_uploads10902026/10/27 08:16:00 INFO Vacuumed table table=closures10912026/10/27 08:16:00 INFO Vacuumed table table=objects1092--- PASS: TestPush_RootsAreLockedInByteOrder (1.02s)1093=== CONT TestClientFallsBackToClosures10942026/10/27 08:16:00 INFO Received complete push request method=POST path=/api/pushes/1/complete10952026/10/27 08:16:00 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001096--- PASS: TestService_createPendingClosureHandler (1.15s)1097=== CONT TestClientPushesUseOnePush10982026/10/27 08:16:00 INFO Received push request method=POST path=/api/pushes10992026/10/27 08:16:00 INFO Completed push id=1 objects=4 duration=11.725386ms11002026/10/27 08:16:00 INFO Received push request method=POST path=/api/pushes11012026/10/27 08:16:00 INFO Received complete push request method=POST path=/api/pushes/1/complete11022026/10/27 08:16:00 INFO Received push request method=POST path=/api/pushes11032026/10/27 08:16:00 INFO Completed push id=1 objects=4 duration=8.670037ms1104--- PASS: TestPush_RepeatedRootCommitsOnce (1.00s)1105=== CONT TestCacheStatsHandler11062026/10/27 08:16:00 INFO Received complete push request method=POST path=/api/pushes/1/complete11072026/10/27 08:16:00 INFO Aborted multipart uploads count=0 kept=011082026/10/27 08:16:00 INFO Received push request method=POST path=/api/pushes11092026/10/27 08:16:00 WARN Force mode enabled - objects will be deleted immediately without grace period11102026/10/27 08:16:00 INFO Completed push id=1 objects=6 duration=10.774496ms1111--- PASS: TestPush_CompleteCommitsEveryRoot (0.70s)1112=== CONT TestClientSharedPathCommittedMidPush1113--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.65s)1114=== CONT TestClientWithDependencies11152026/10/27 08:16:00 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=011162026/10/27 08:16:00 INFO Vacuumed table table=pending_closures11172026/10/27 08:16:00 INFO Vacuumed table table=pending_objects11182026/10/27 08:16:00 INFO Vacuumed table table=multipart_uploads1119--- PASS: TestReadRedirectUsesPublicS3URL (0.64s)1120=== CONT TestClientMultipleUploads11212026/10/27 08:16:00 INFO Vacuumed table table=closures11222026/10/27 08:16:00 INFO Vacuumed table table=objects11232026/10/27 08:16:00 INFO Received complete push request method=POST path=/api/pushes/2/complete11242026/10/27 08:16:00 INFO Completed push id=2 objects=4 duration=3.260399ms1125--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (1.16s)1126=== CONT TestClientIntegration1127--- PASS: TestReadProxyRangeRequest (0.65s)1128=== CONT TestClientErrorHandling1129=== RUN TestClientErrorHandling/InvalidStorePath1130=== PAUSE TestClientErrorHandling/InvalidStorePath1131=== RUN TestClientErrorHandling/InvalidAuthToken1132=== PAUSE TestClientErrorHandling/InvalidAuthToken1133=== RUN TestClientErrorHandling/ServerNotAvailable1134=== PAUSE TestClientErrorHandling/ServerNotAvailable1135=== CONT TestClientCADerivations11362026-10-27 08:16:00.470 UTC [815] ERROR: Push does not exist: id=111372026-10-27 08:16:00.470 UTC [815] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE11382026-10-27 08:16:00.470 UTC [815] STATEMENT: SELECT commit_push($1)1139--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.21s)1140=== CONT TestObjectStatsUpdatedOncePerCommit11412026/10/27 08:16:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11422026/10/27 08:16:00 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YjMxMDdhNDMtODViNy00N2I1LWE5YmMtYzNkZDM3MzNiODA1LjYzNDZlMjMzLTczNDAtNGRkZi05NjA4LWRlNDUyNWE4NmI4ZXgxNzkzMDg4OTYwMDUxMTk1ODIw parts=1011432026/10/27 08:16:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11442026/10/27 08:16:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11452026/10/27 08:16:00 INFO Completed upload id=1 objects=2 duration=5.032679ms11462026/10/27 08:16:00 INFO Received uploads request method=POST path=/api/pending_closures11472026/10/27 08:16:00 INFO Received uploads request method=POST path=/api/pending_closures11482026/10/27 08:16:00 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo11492026/10/27 08:16:00 WARN Found objects in DB but missing from S3, will re-upload count=11150--- PASS: TestService_verifyS3Integrity (1.39s)1151=== CONT TestPresentNotReportedWhileGCDeletesClosure1152=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1153=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1154=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1155=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1156=== CONT TestPresentRefreshesOnlyStaleClosures11572026/10/27 08:16:00 INFO Received uploads request method=POST path=/api/pending_closures11582026/10/27 08:16:00 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YjMxMDdhNDMtODViNy00N2I1LWE5YmMtYzNkZDM3MzNiODA1LjM4NTdkNjc4LTEwYTgtNDQyNS1iYzFmLTczMDg2NGM2ZjFjMngxNzkzMDg4OTU5OTkzNzMyNzgy parts=1211592026/10/27 08:16:00 INFO Received uploads request method=POST path=/api/pending_closures11602026/10/27 08:16:00 INFO Aborted multipart uploads count=0 kept=01161--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.40s)1162=== CONT TestPresentReportsOnlyClosureRoots11632026/10/27 08:16:00 WARN Force mode enabled - objects will be deleted immediately without grace period11642026/10/27 08:16:00 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=011652026/10/27 08:16:00 INFO Vacuumed table table=pending_closures11662026/10/27 08:16:00 INFO Vacuumed table table=pending_objects11672026/10/27 08:16:00 INFO Vacuumed table table=multipart_uploads11682026/10/27 08:16:00 INFO Vacuumed table table=closures11692026/10/27 08:16:00 INFO Vacuumed table table=objects1170--- PASS: TestGCMetrics (0.68s)1171=== CONT TestCreatePin_ReservedPins1172=== NAME TestPinProtectsFromGC1173 client_integration_test.go:778: Pinned store path: /build/TestPinProtectsFromGC3596638313/001/store/n6drdad2nbh4zin60krsfx4l58q73gl1-pinned-file.txt1174 client_integration_test.go:779: Unpinned store path: /build/TestPinProtectsFromGC3596638313/001/store/hwvdcz4cfszh8wnhrsimgpyjhnlpn6nf-unpinned-file.txt11752026/10/27 08:16:00 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"1176--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.64s)1177=== CONT TestParseSingleRange1178=== RUN TestParseSingleRange/none1179=== PAUSE TestParseSingleRange/none1180=== RUN TestParseSingleRange/unknown_unit1181=== PAUSE TestParseSingleRange/unknown_unit1182=== RUN TestParseSingleRange/multi-range_ignored1183=== PAUSE TestParseSingleRange/multi-range_ignored1184=== RUN TestParseSingleRange/malformed_no_dash1185=== PAUSE TestParseSingleRange/malformed_no_dash1186=== RUN TestParseSingleRange/malformed_both_empty1187=== PAUSE TestParseSingleRange/malformed_both_empty1188=== RUN TestParseSingleRange/malformed_end_before_start1189=== PAUSE TestParseSingleRange/malformed_end_before_start1190=== RUN TestParseSingleRange/closed1191=== PAUSE TestParseSingleRange/closed1192=== RUN TestParseSingleRange/open-ended1193=== PAUSE TestParseSingleRange/open-ended1194=== RUN TestParseSingleRange/end_clamped_to_size1195=== PAUSE TestParseSingleRange/end_clamped_to_size1196=== RUN TestParseSingleRange/suffix1197=== PAUSE TestParseSingleRange/suffix1198=== RUN TestParseSingleRange/suffix_exceeds_size1199=== PAUSE TestParseSingleRange/suffix_exceeds_size1200=== RUN TestParseSingleRange/single_byte1201=== PAUSE TestParseSingleRange/single_byte1202=== RUN TestParseSingleRange/start_past_EOF1203=== PAUSE TestParseSingleRange/start_past_EOF1204=== RUN TestParseSingleRange/start_far_past_EOF1205=== PAUSE TestParseSingleRange/start_far_past_EOF1206=== CONT TestOrphanedObjectsGCStressTest12072026/10/27 08:16:00 INFO Aborted multipart uploads count=0 kept=012082026/10/27 08:16:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46375/oidc12092026/10/27 08:16:00 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=012102026/10/27 08:16:00 INFO Vacuumed table table=pending_closures12112026/10/27 08:16:00 INFO Vacuumed table table=pending_objects12122026/10/27 08:16:00 INFO Vacuumed table table=multipart_uploads12132026/10/27 08:16:00 INFO Vacuumed table table=closures12142026/10/27 08:16:00 INFO Vacuumed table table=objects12152026/10/27 08:16:00 INFO Aborted multipart uploads count=0 kept=012162026/10/27 08:16:00 WARN Force mode enabled - objects will be deleted immediately without grace period12172026/10/27 08:16:00 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=012182026/10/27 08:16:00 INFO lead: acquired remote=192.0.2.1:123412192026/10/27 08:16:00 INFO lead: released remote=192.0.2.1:12341220--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.63s)1221=== CONT TestOrphanedObjectsGC12222026/10/27 08:16:00 INFO Vacuumed table table=pending_closures12232026/10/27 08:16:00 INFO Received push request method=POST path=/api/pushes12242026/10/27 08:16:00 INFO Vacuumed table table=pending_objects12252026/10/27 08:16:00 INFO Vacuumed table table=multipart_uploads12262026/10/27 08:16:00 INFO Vacuumed table table=closures12272026/10/27 08:16:00 INFO Vacuumed table table=objects1228--- PASS: TestPushDedupSurvivesConcurrentGC (0.79s)1229=== CONT TestReadProxyInvalidPath12302026/10/27 08:16:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12312026/10/27 08:16:00 INFO Uploading n6drdad2nbh4zin60krsfx4l58q73gl1-pinned-file.txt (128B)12322026/10/27 08:16:00 WARN Failed to register uploaded object key=n6drdad2nbh4zin60krsfx4l58q73gl1.ls error="server returned 404: 404 page not found\n"12332026/10/27 08:16:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12342026/10/27 08:16:00 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"12352026/10/27 08:16:00 INFO Signed narinfos id=1 count=112362026/10/27 08:16:00 INFO Uploading 1 narinfos12372026/10/27 08:16:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12382026/10/27 08:16:00 INFO Received complete push request method=POST path=/api/pushes/1/complete12392026/10/27 08:16:00 WARN Failed to register uploaded object key=n6drdad2nbh4zin60krsfx4l58q73gl1.narinfo error="server returned 404: 404 page not found\n"12402026/10/27 08:16:00 INFO lead: acquired remote=192.0.2.1:123412412026/10/27 08:16:00 INFO Completed push id=1 objects=3 duration=10.309966ms12422026/10/27 08:16:00 INFO Upload complete. (80ms)12432026/10/27 08:16:00 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YjMxMDdhNDMtODViNy00N2I1LWE5YmMtYzNkZDM3MzNiODA1LjE5MTdkMDI0LTM1NDgtNGRkYi1iMDZkLWM5NTU0MTlkNzllZngxNzkzMDg4OTYwMTI4NTU2MDEw parts=1212442026/10/27 08:16:00 INFO Received uploads request method=POST path=/api/pending_closures12452026/10/27 08:16:00 INFO lead: acquired remote=192.0.2.1:123412462026/10/27 08:16:00 INFO Received uploads request method=POST path=/api/pending_closures12472026/10/27 08:16:00 INFO Received push request method=POST path=/api/pushes12482026/10/27 08:16:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12492026/10/27 08:16:00 INFO Uploading hwvdcz4cfszh8wnhrsimgpyjhnlpn6nf-unpinned-file.txt (128B)12502026/10/27 08:16:00 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12512026/10/27 08:16:00 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"12522026/10/27 08:16:00 INFO Signed narinfos id=2 count=112532026/10/27 08:16:00 WARN Failed to register uploaded object key=hwvdcz4cfszh8wnhrsimgpyjhnlpn6nf.ls error="server returned 404: 404 page not found\n"12542026/10/27 08:16:00 INFO Uploading 1 narinfos12552026/10/27 08:16:00 INFO Received complete push request method=POST path=/api/pushes/2/complete12562026/10/27 08:16:00 WARN Failed to register uploaded object key=hwvdcz4cfszh8wnhrsimgpyjhnlpn6nf.narinfo error="server returned 404: 404 page not found\n"12572026/10/27 08:16:00 INFO Completed push id=2 objects=3 duration=2.497999ms12582026/10/27 08:16:00 INFO Upload complete. (55ms)12592026/10/27 08:16:00 INFO Starting cleanup of old closures method=DELETE path=/api/closures12602026/10/27 08:16:00 INFO Garbage collection started12612026/10/27 08:16:00 INFO Aborted multipart uploads count=0 kept=012622026/10/27 08:16:00 WARN Force mode enabled - objects will be deleted immediately without grace period1263--- PASS: TestGCBugBareHashReferences (0.92s)1264=== CONT TestReadRedirectNar1265--- PASS: TestCacheStatsHandler (0.54s)1266=== CONT TestReadProxyDisabled12672026/10/27 08:16:00 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=012682026/10/27 08:16:00 INFO Vacuumed table table=pending_closures12692026/10/27 08:16:00 INFO Vacuumed table table=pending_objects12702026/10/27 08:16:00 INFO Vacuumed table table=multipart_uploads12712026/10/27 08:16:00 INFO Vacuumed table table=closures12722026/10/27 08:16:00 INFO Vacuumed table table=objects1273--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.76s)1274=== CONT TestReadProxyRootRedirectsToIndexHTML12752026/10/27 08:16:00 INFO Received push request method=POST path=/api/pushes12762026/10/27 08:16:00 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12772026/10/27 08:16:00 INFO Uploading 7dpqx889f2psvzai9acbrnsswnbfvghq-shared-dep (136B)12782026/10/27 08:16:00 INFO Uploading 7dp24y2lximkhrpmiwdn53l0zhqdwa1p-b (216B)1279=== NAME TestClientMultipleUploads1280 client_integration_test.go:405: Created store path 0: /build/TestClientMultipleUploads3252805345/001/store/mizi92f47s36061rr75vvb8839kkgqk9-test-file-0.txt12812026/10/27 08:16:01 WARN Failed to register uploaded object key=w6gkjzxv9vkn9kz44pk1zw0nyq5dp25h.ls error="server returned 404: 404 page not found\n"12822026/10/27 08:16:01 WARN Failed to register uploaded object key=7dp24y2lximkhrpmiwdn53l0zhqdwa1p.ls error="server returned 404: 404 page not found\n"12832026/10/27 08:16:01 WARN Failed to register uploaded object key=nar/1x0hp8hrm27r062y0092nph065q9fdby864lklq6zadybiyd7fzc.nar.zst error="server returned 404: 404 page not found\n"12842026/10/27 08:16:01 WARN Failed to register uploaded object key=7dpqx889f2psvzai9acbrnsswnbfvghq.ls error="server returned 404: 404 page not found\n"12852026/10/27 08:16:01 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12862026/10/27 08:16:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12872026/10/27 08:16:01 INFO Signed narinfos id=1 count=312882026/10/27 08:16:01 INFO Uploading 3 narinfos12892026/10/27 08:16:01 WARN Failed to register uploaded object key=7dp24y2lximkhrpmiwdn53l0zhqdwa1p.narinfo error="server returned 404: 404 page not found\n"12902026/10/27 08:16:01 WARN Failed to register uploaded object key=7dpqx889f2psvzai9acbrnsswnbfvghq.narinfo error="server returned 404: 404 page not found\n"12912026/10/27 08:16:01 INFO Received complete push request method=POST path=/api/pushes/1/complete12922026/10/27 08:16:01 WARN Failed to register uploaded object key=w6gkjzxv9vkn9kz44pk1zw0nyq5dp25h.narinfo error="server returned 404: 404 page not found\n"12932026/10/27 08:16:01 INFO Completed push id=1 objects=8 duration=4.081109ms12942026/10/27 08:16:01 INFO Upload complete. (69ms)1295=== NAME TestClientPushesUseOnePush1296 client_pushes_test.go:97: Retrieved narinfo from S3:1297 StorePath: /build/TestClientPushesUseOnePush1294721315/001/store/7dpqx889f2psvzai9acbrnsswnbfvghq-shared-dep1298 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1299 Compression: zstd1300 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821301 NarSize: 1361302 References: 1303 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1304 client_pushes_test.go:97: Retrieved narinfo from S3:1305 StorePath: /build/TestClientPushesUseOnePush1294721315/001/store/w6gkjzxv9vkn9kz44pk1zw0nyq5dp25h-a1306 URL: nar/1x0hp8hrm27r062y0092nph065q9fdby864lklq6zadybiyd7fzc.nar.zst1307 Compression: zstd1308 NarHash: sha256:1x0hp8hrm27r062y0092nph065q9fdby864lklq6zadybiyd7fzc1309 NarSize: 2161310 References: /build/TestClientPushesUseOnePush1294721315/001/store/7dpqx889f2psvzai9acbrnsswnbfvghq-shared-dep1311 CA: text:sha256:0dppqpfmhhgjx0qxqz3v4rv3534i827liqkrn4j6ga19q7y98kvk1312 client_pushes_test.go:97: Retrieved narinfo from S3:1313 StorePath: /build/TestClientPushesUseOnePush1294721315/001/store/7dp24y2lximkhrpmiwdn53l0zhqdwa1p-b1314 URL: nar/1x0hp8hrm27r062y0092nph065q9fdby864lklq6zadybiyd7fzc.nar.zst1315 Compression: zstd1316 NarHash: sha256:1x0hp8hrm27r062y0092nph065q9fdby864lklq6zadybiyd7fzc1317 NarSize: 2161318 References: /build/TestClientPushesUseOnePush1294721315/001/store/7dpqx889f2psvzai9acbrnsswnbfvghq-shared-dep1319 CA: text:sha256:0dppqpfmhhgjx0qxqz3v4rv3534i827liqkrn4j6ga19q7y98kvk1320=== NAME TestClientIntegration1321 client_integration_test.go:291: Created store path: /build/TestClientIntegration2931962471/002/store/2mbkj0j9rdh95k31icz5wws23n1rcqmk-test-file.txt1322=== NAME TestClientWithDependencies1323 client_integration_test.go:660: Built derivation: /build/TestClientWithDependencies810048275/001/store/v3xnqkfk886bn13nadfvvvclphps0ajh-test-script13242026/10/27 08:16:01 INFO Received uploads request method=POST path=/api/pending_closures13252026/10/27 08:16:01 INFO Received uploads request method=POST path=/api/pending_closures1326--- PASS: TestClientPushesUseOnePush (0.73s)1327=== CONT TestReadProxyConditionalGet13282026/10/27 08:16:01 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13292026/10/27 08:16:01 INFO Uploading lq2cz0a72pzz2lkmh1gid832ai9mjmhz-shared-dep (136B)13302026/10/27 08:16:01 INFO Uploading 1lgv1znqk01a89qi639v9ys80r9kxjlw-b (216B)1331=== NAME TestClientMultipleUploads1332 client_integration_test.go:405: Created store path 1: /build/TestClientMultipleUploads3252805345/001/store/hgfwarmbknnp70f7r19g6kzs0s545r0y-test-file-1.txt13332026/10/27 08:16:01 WARN Failed to register uploaded object key=00ksf26s2dfsrl5i9g1gfhz63v04a9hb.ls error="server returned 404: 404 page not found\n"13342026/10/27 08:16:01 WARN Failed to register uploaded object key=lq2cz0a72pzz2lkmh1gid832ai9mjmhz.ls error="server returned 404: 404 page not found\n"13352026/10/27 08:16:01 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13362026/10/27 08:16:01 WARN Failed to register uploaded object key=nar/165gzkzi3kq79gpfvglc9fywvx7k856lkcwxrr5ifxg9rmx8p7bk.nar.zst error="server returned 404: 404 page not found\n"13372026/10/27 08:16:01 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13382026/10/27 08:16:01 WARN Failed to register uploaded object key=1lgv1znqk01a89qi639v9ys80r9kxjlw.ls error="server returned 404: 404 page not found\n"13392026/10/27 08:16:01 INFO Signed narinfos id=1 count=213402026/10/27 08:16:01 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13412026/10/27 08:16:01 INFO Signed narinfos id=2 count=213422026/10/27 08:16:01 INFO Uploading 4 narinfos13432026/10/27 08:16:01 WARN Failed to register uploaded object key=00ksf26s2dfsrl5i9g1gfhz63v04a9hb.narinfo error="server returned 404: 404 page not found\n"13442026/10/27 08:16:01 WARN Failed to register uploaded object key=1lgv1znqk01a89qi639v9ys80r9kxjlw.narinfo error="server returned 404: 404 page not found\n"13452026/10/27 08:16:01 WARN Failed to register uploaded object key=lq2cz0a72pzz2lkmh1gid832ai9mjmhz.narinfo error="server returned 404: 404 page not found\n"13462026/10/27 08:16:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13472026/10/27 08:16:01 WARN Failed to register uploaded object key=lq2cz0a72pzz2lkmh1gid832ai9mjmhz.narinfo error="server returned 404: 404 page not found\n"1348=== NAME TestClientWithDependencies1349 client_integration_test.go:662: Found 1 dependencies (including self)13502026/10/27 08:16:01 INFO Completed upload id=1 objects=6 duration=8.732427ms13512026/10/27 08:16:01 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13522026/10/27 08:16:01 INFO Received push request method=POST path=/api/pushes13532026/10/27 08:16:01 INFO Completed upload id=2 objects=6 duration=2.618939ms13542026/10/27 08:16:01 INFO Upload complete. (72ms)1355=== NAME TestClientFallsBackToClosures1356 client_pushes_test.go:112: Retrieved narinfo from S3:1357 StorePath: /build/TestClientFallsBackToClosures1492140179/001/store/lq2cz0a72pzz2lkmh1gid832ai9mjmhz-shared-dep1358 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1359 Compression: zstd1360 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821361 NarSize: 1361362 References: 1363 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n13642026/10/27 08:16:01 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)13652026/10/27 08:16:01 INFO Uploading isb4my22wk7izd2mx2830i4xvv3lnz1x-top (224B)13662026/10/27 08:16:01 INFO Uploading d34n2vp8a7jkij8jp3bycq8hlm5qk3b1-shared-dep (136B)1367 client_pushes_test.go:112: Retrieved narinfo from S3:1368 StorePath: /build/TestClientFallsBackToClosures1492140179/001/store/00ksf26s2dfsrl5i9g1gfhz63v04a9hb-a1369 URL: nar/165gzkzi3kq79gpfvglc9fywvx7k856lkcwxrr5ifxg9rmx8p7bk.nar.zst1370 Compression: zstd1371 NarHash: sha256:165gzkzi3kq79gpfvglc9fywvx7k856lkcwxrr5ifxg9rmx8p7bk1372 NarSize: 2161373 References: /build/TestClientFallsBackToClosures1492140179/001/store/lq2cz0a72pzz2lkmh1gid832ai9mjmhz-shared-dep1374 CA: text:sha256:02nmdjchbl292fxlz1khnn0kzsfl29aharafwb6msa924060f8iz1375--- PASS: TestPresentReportsOnlyClosureRoots (0.52s)1376=== CONT TestReadProxyOutlastsServerWriteTimeout1377=== NAME TestClientFallsBackToClosures1378 client_pushes_test.go:112: Retrieved narinfo from S3:1379 StorePath: /build/TestClientFallsBackToClosures1492140179/001/store/1lgv1znqk01a89qi639v9ys80r9kxjlw-b1380 URL: nar/165gzkzi3kq79gpfvglc9fywvx7k856lkcwxrr5ifxg9rmx8p7bk.nar.zst1381 Compression: zstd1382 NarHash: sha256:165gzkzi3kq79gpfvglc9fywvx7k856lkcwxrr5ifxg9rmx8p7bk1383 NarSize: 2161384 References: /build/TestClientFallsBackToClosures1492140179/001/store/lq2cz0a72pzz2lkmh1gid832ai9mjmhz-shared-dep1385 CA: text:sha256:02nmdjchbl292fxlz1khnn0kzsfl29aharafwb6msa924060f8iz13862026/10/27 08:16:01 WARN Failed to register uploaded object key=isb4my22wk7izd2mx2830i4xvv3lnz1x.ls error="server returned 404: 404 page not found\n"13872026/10/27 08:16:01 WARN Failed to register uploaded object key=d34n2vp8a7jkij8jp3bycq8hlm5qk3b1.ls error="server returned 404: 404 page not found\n"13882026/10/27 08:16:01 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13892026/10/27 08:16:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13902026/10/27 08:16:01 WARN Failed to register uploaded object key=nar/1m7nbyb97vs84z2507a5s16a4a4nwglc7x60irzifvm1dizkac2c.nar.zst error="server returned 404: 404 page not found\n"13912026/10/27 08:16:01 INFO Signed narinfos id=1 count=21392=== NAME TestClientMultipleUploads13932026/10/27 08:16:01 INFO Uploading 2 narinfos1394 client_integration_test.go:405: Created store path 2: /build/TestClientMultipleUploads3252805345/001/store/wc80anf41xfw8h31fx51wpw9hr44wlyh-test-file-2.txt1395--- PASS: TestObjectStatsUpdatedOncePerCommit (0.60s)1396=== CONT TestReadProxy4041397--- PASS: TestClientFallsBackToClosures (0.78s)1398=== CONT TestReadProxyHead13992026/10/27 08:16:01 INFO Received complete push request method=POST path=/api/pushes/1/complete14002026/10/27 08:16:01 WARN Failed to register uploaded object key=d34n2vp8a7jkij8jp3bycq8hlm5qk3b1.narinfo error="server returned 404: 404 page not found\n"14012026/10/27 08:16:01 WARN Failed to register uploaded object key=isb4my22wk7izd2mx2830i4xvv3lnz1x.narinfo error="server returned 404: 404 page not found\n"14022026/10/27 08:16:01 INFO Completed push id=1 objects=6 duration=9.560927ms14032026/10/27 08:16:01 INFO Upload complete. (68ms)1404=== NAME TestClientSharedPathCommittedMidPush1405 client_integration_test.go:727: Retrieved narinfo from S3:1406 StorePath: /build/TestClientSharedPathCommittedMidPush2059682760/001/store/d34n2vp8a7jkij8jp3bycq8hlm5qk3b1-shared-dep1407 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1408 Compression: zstd1409 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821410 NarSize: 1361411 References: 1412 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1413--- PASS: TestPresentRefreshesOnlyStaleClosures (0.55s)1414=== CONT TestReadProxyNarStreaming1415=== NAME TestClientSharedPathCommittedMidPush1416 client_integration_test.go:727: Retrieved narinfo from S3:1417 StorePath: /build/TestClientSharedPathCommittedMidPush2059682760/001/store/isb4my22wk7izd2mx2830i4xvv3lnz1x-top1418 URL: nar/1m7nbyb97vs84z2507a5s16a4a4nwglc7x60irzifvm1dizkac2c.nar.zst1419 Compression: zstd1420 NarHash: sha256:1m7nbyb97vs84z2507a5s16a4a4nwglc7x60irzifvm1dizkac2c1421 NarSize: 2241422 References: /build/TestClientSharedPathCommittedMidPush2059682760/001/store/d34n2vp8a7jkij8jp3bycq8hlm5qk3b1-shared-dep1423 CA: text:sha256:1ac2xay4cyf5d4msmi7ns8066fwpacnvl8yv909c1p2r4ib32llm1424--- PASS: TestClientSharedPathCommittedMidPush (0.72s)1425=== CONT TestRegisterCompletedObjectNeedsPendingRow14262026/10/27 08:16:01 INFO Received push request method=POST path=/api/pushes1427=== NAME TestClientCADerivations1428 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations4016775737/001/store/id651xf9w1ar920kkiqsk8lzd91mkhp1-ca-test14292026/10/27 08:16:01 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14302026/10/27 08:16:01 INFO Uploading 2mbkj0j9rdh95k31icz5wws23n1rcqmk-test-file.txt (152B)14312026/10/27 08:16:01 WARN Failed to register uploaded object key=2mbkj0j9rdh95k31icz5wws23n1rcqmk.ls error="server returned 404: 404 page not found\n"14322026/10/27 08:16:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14332026/10/27 08:16:01 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"14342026/10/27 08:16:01 INFO Signed narinfos id=1 count=114352026/10/27 08:16:01 INFO Uploading 1 narinfos14362026/10/27 08:16:01 INFO Received complete push request method=POST path=/api/pushes/1/complete14372026/10/27 08:16:01 WARN Failed to register uploaded object key=2mbkj0j9rdh95k31icz5wws23n1rcqmk.narinfo error="server returned 404: 404 page not found\n"14382026/10/27 08:16:01 INFO Completed push id=1 objects=3 duration=5.542628ms14392026/10/27 08:16:01 INFO Upload complete. (63ms)14402026/10/27 08:16:01 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14412026/10/27 08:16:01 WARN Refused reserved pin name=worker-x86_64-linux14422026/10/27 08:16:01 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14432026/10/27 08:16:01 INFO Received create pin request method=POST path=/api/pins/my-app14442026/10/27 08:16:01 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14452026/10/27 08:16:01 INFO Received push request method=POST path=/api/pushes1446--- PASS: TestCreatePin_ReservedPins (0.55s)1447=== CONT TestReadProxyContentNegotiation1448=== NAME TestClientCADerivations1449 client_ca_test.go:139: Found 1 dependencies (including self)14502026/10/27 08:16:01 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14512026/10/27 08:16:01 INFO Uploading v3xnqkfk886bn13nadfvvvclphps0ajh-test-script (136B)14522026/10/27 08:16:01 INFO Received push request method=POST path=/api/pushes14532026/10/27 08:16:01 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"14542026/10/27 08:16:01 WARN Failed to register uploaded object key=log/zkiyf4djahxmpc4gwnyhbrsvpswnwmfj-test-script.drv error="server returned 404: 404 page not found\n"14552026/10/27 08:16:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14562026/10/27 08:16:01 WARN Failed to register uploaded object key=v3xnqkfk886bn13nadfvvvclphps0ajh.ls error="server returned 404: 404 page not found\n"14572026/10/27 08:16:01 INFO Signed narinfos id=1 count=114582026/10/27 08:16:01 INFO Uploading 1 narinfos14592026/10/27 08:16:01 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)14602026/10/27 08:16:01 INFO Uploading mizi92f47s36061rr75vvb8839kkgqk9-test-file-0.txt (160B)14612026/10/27 08:16:01 INFO Uploading hgfwarmbknnp70f7r19g6kzs0s545r0y-test-file-1.txt (160B)14622026/10/27 08:16:01 INFO Uploading wc80anf41xfw8h31fx51wpw9hr44wlyh-test-file-2.txt (160B)14632026/10/27 08:16:01 INFO Received complete push request method=POST path=/api/pushes/1/complete14642026/10/27 08:16:01 WARN Failed to register uploaded object key=v3xnqkfk886bn13nadfvvvclphps0ajh.narinfo error="server returned 404: 404 page not found\n"14652026/10/27 08:16:01 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"14662026/10/27 08:16:01 WARN Failed to register uploaded object key=hgfwarmbknnp70f7r19g6kzs0s545r0y.ls error="server returned 404: 404 page not found\n"14672026/10/27 08:16:01 INFO All 1 paths already cached14682026/10/27 08:16:01 WARN Failed to register uploaded object key=wc80anf41xfw8h31fx51wpw9hr44wlyh.ls error="server returned 404: 404 page not found\n"14692026/10/27 08:16:01 WARN Failed to register uploaded object key=mizi92f47s36061rr75vvb8839kkgqk9.ls error="server returned 404: 404 page not found\n"14702026/10/27 08:16:01 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"1471=== NAME TestClientIntegration1472 client_integration_test.go:317: Retrieved narinfo from S3:1473 StorePath: /build/TestClientIntegration2931962471/002/store/2mbkj0j9rdh95k31icz5wws23n1rcqmk-test-file.txt1474 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1475 Compression: zstd1476 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11477 NarSize: 1521478 References: 1479 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk114802026/10/27 08:16:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14812026/10/27 08:16:01 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"14822026/10/27 08:16:01 INFO Signed narinfos id=1 count=314832026/10/27 08:16:01 INFO Uploading 3 narinfos1484 client_integration_test.go:318: Retrieved .ls file from S3 (compressed size: 77 bytes)1485 client_integration_test.go:318: Decompressed .ls content (64 bytes):1486 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1487--- PASS: TestReadProxyInvalidPath (0.50s)1488=== CONT TestGCTaskStore_StartNew1489--- PASS: TestGCTaskStore_StartNew (0.00s)1490=== CONT TestReadProxyNarinfoAlreadyDecompressed14912026/10/27 08:16:01 WARN Failed to register uploaded object key=hgfwarmbknnp70f7r19g6kzs0s545r0y.narinfo error="server returned 404: 404 page not found\n"14922026/10/27 08:16:01 INFO Completed push id=1 objects=4 duration=6.374958ms14932026/10/27 08:16:01 WARN Failed to register uploaded object key=mizi92f47s36061rr75vvb8839kkgqk9.narinfo error="server returned 404: 404 page not found\n"14942026/10/27 08:16:01 INFO Upload complete. (75ms)14952026/10/27 08:16:01 INFO Received complete push request method=POST path=/api/pushes/1/complete14962026/10/27 08:16:01 WARN Failed to register uploaded object key=wc80anf41xfw8h31fx51wpw9hr44wlyh.narinfo error="server returned 404: 404 page not found\n"1497=== NAME TestClientWithDependencies1498 client_integration_test.go:664: Skipping nix copy test - isolated store (/build/TestClientWithDependencies810048275/001/store) requires matching store prefix1499--- PASS: TestClientWithDependencies (0.77s)1500=== CONT TestGCEndsOnShutdown1501=== RUN TestGCEndsOnShutdown/before_the_run1502=== PAUSE TestGCEndsOnShutdown/before_the_run1503=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1504=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1505=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1506=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1507=== CONT TestCommitRacingPendingCleanupKeepsObjects15082026/10/27 08:16:01 INFO Completed push id=1 objects=9 duration=9.353307ms15092026/10/27 08:16:01 INFO Upload complete. (69ms)1510=== NAME TestClientMultipleUploads1511 client_integration_test.go:416: Uploaded 3 paths in 101.199661ms15122026/10/27 08:16:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1513--- PASS: TestClientMultipleUploads (0.76s)1514=== CONT TestReadProxyNarinfo1515--- PASS: TestReadRedirectNar (0.33s)1516=== CONT TestPushWaitsForSweepHoldingRow15172026/10/27 08:16:01 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YjMxMDdhNDMtODViNy00N2I1LWE5YmMtYzNkZDM3MzNiODA1LjdlMDUxMzg4LTdkZGItNDg0NC1hZjgwLTRlNzBjNmYwYmFhY3gxNzkzMDg4OTYwNzE5NDA5NTIx error="Get \"http://127.0.0.1:1/bucket21/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"15182026/10/27 08:16:01 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YjMxMDdhNDMtODViNy00N2I1LWE5YmMtYzNkZDM3MzNiODA1LjUxMzA4NTRlLTdjMjYtNGEzNC1hMTkwLTg3NTZlZTk5NWJlYXgxNzkzMDg4OTYwNzExMzQ4ODA0 parts=1215192026/10/27 08:16:01 INFO Received cleanup request method=DELETE path=/api/pending_closures15202026/10/27 08:16:01 INFO Aborted multipart uploads count=1 kept=01521--- PASS: TestReadProxyDisabled (0.33s)1522=== CONT TestIsValidCachePath1523=== RUN TestIsValidCachePath/narinfo1524=== PAUSE TestIsValidCachePath/narinfo1525=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1526=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1527=== RUN TestIsValidCachePath/nar_zst1528=== PAUSE TestIsValidCachePath/nar_zst1529=== RUN TestIsValidCachePath/nar_xz1530=== PAUSE TestIsValidCachePath/nar_xz1531=== RUN TestIsValidCachePath/nar_bz21532=== PAUSE TestIsValidCachePath/nar_bz21533=== RUN TestIsValidCachePath/nar_uncompressed1534=== PAUSE TestIsValidCachePath/nar_uncompressed1535=== RUN TestIsValidCachePath/ls1536=== PAUSE TestIsValidCachePath/ls1537=== RUN TestIsValidCachePath/log1538=== PAUSE TestIsValidCachePath/log1539=== RUN TestIsValidCachePath/realisation1540=== PAUSE TestIsValidCachePath/realisation1541=== RUN TestIsValidCachePath/nix-cache-info1542=== PAUSE TestIsValidCachePath/nix-cache-info1543=== RUN TestIsValidCachePath/index.html1544=== PAUSE TestIsValidCachePath/index.html1545=== RUN TestIsValidCachePath/traversal_parent1546=== PAUSE TestIsValidCachePath/traversal_parent1547=== RUN TestIsValidCachePath/traversal_in_middle1548=== PAUSE TestIsValidCachePath/traversal_in_middle1549=== RUN TestIsValidCachePath/invalid_char_e1550=== PAUSE TestIsValidCachePath/invalid_char_e1551=== RUN TestIsValidCachePath/invalid_char_u1552=== PAUSE TestIsValidCachePath/invalid_char_u1553=== RUN TestIsValidCachePath/random_path1554=== PAUSE TestIsValidCachePath/random_path1555=== RUN TestIsValidCachePath/empty1556=== PAUSE TestIsValidCachePath/empty1557=== RUN TestIsValidCachePath/leading_slash1558=== PAUSE TestIsValidCachePath/leading_slash1559=== RUN TestIsValidCachePath/wrong_extension1560=== PAUSE TestIsValidCachePath/wrong_extension1561=== RUN TestIsValidCachePath/short_hash1562=== PAUSE TestIsValidCachePath/short_hash1563=== CONT TestSweepRechecksPendingAfterLocking1564--- PASS: TestRedundantMultipartUpload (1.97s)1565=== CONT TestGetExistingObjectsLocksRows1566--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.29s)1567=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15682026/10/27 08:16:01 INFO Received push request method=POST path=/api/pushes15692026/10/27 08:16:01 INFO Object in database but missing from S3 key=2mbkj0j9rdh95k31icz5wws23n1rcqmk.ls15702026/10/27 08:16:01 WARN Found objects in DB but missing from S3, will re-upload count=115712026/10/27 08:16:01 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)15722026/10/27 08:16:01 INFO Received complete push request method=POST path=/api/pushes/2/complete15732026/10/27 08:16:01 WARN Failed to register uploaded object key=2mbkj0j9rdh95k31icz5wws23n1rcqmk.ls error="server returned 404: 404 page not found\n"15742026/10/27 08:16:01 INFO Received push request method=POST path=/api/pushes15752026/10/27 08:16:01 INFO Completed push id=2 objects=3 duration=3.893839ms15762026/10/27 08:16:01 INFO Upload complete. (50ms)1577=== NAME TestClientIntegration1578 client_integration_test.go:335: Retrieved .ls file from S3 (compressed size: 62 bytes)1579 client_integration_test.go:335: Decompressed .ls content (49 bytes):1580 {"version":1,"root":{"type":"regular","size":39}}1581--- PASS: TestReadProxyConditionalGet (0.23s)1582=== CONT TestService_AuthMiddleware_OIDC15832026/10/27 08:16:01 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15842026/10/27 08:16:01 INFO Uploading id651xf9w1ar920kkiqsk8lzd91mkhp1-ca-test (144B)15852026/10/27 08:16:01 WARN Failed to register uploaded object key=id651xf9w1ar920kkiqsk8lzd91mkhp1.ls error="server returned 404: 404 page not found\n"15862026/10/27 08:16:01 WARN Failed to register uploaded object key=log/25jlh85s9hdy94i23madd9q8acrz3i87-ca-test.drv error="server returned 404: 404 page not found\n"15872026/10/27 08:16:01 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"15882026/10/27 08:16:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15892026/10/27 08:16:01 INFO Signed narinfos id=1 count=115902026/10/27 08:16:01 INFO Uploading 1 narinfos15912026/10/27 08:16:01 INFO Received complete push request method=POST path=/api/pushes/1/complete15922026/10/27 08:16:01 WARN Failed to register uploaded object key=id651xf9w1ar920kkiqsk8lzd91mkhp1.narinfo error="server returned 404: 404 page not found\n"15932026/10/27 08:16:01 INFO Completed push id=1 objects=4 duration=17.771393ms15942026/10/27 08:16:01 INFO Upload complete. (120ms)1595=== NAME TestClientCADerivations1596 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations4016775737/001/store/id651xf9w1ar920kkiqsk8lzd91mkhp1-ca-test1597 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1598 Compression: zstd1599 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1600 NarSize: 1441601 References: 1602 Deriver: /build/TestClientCADerivations4016775737/001/store/25jlh85s9hdy94i23madd9q8acrz3i87-ca-test.drv1603 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1604 client_ca_test.go:185: Checking for realisation files in S3...1605 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1606 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1607--- PASS: TestReadProxyHead (0.24s)1608=== CONT TestService_ReadAuthMiddleware1609--- PASS: TestReadProxy404 (0.26s)1610=== CONT TestService_AuthMiddleware_MTLSProxyHeader16112026/10/27 08:16:01 INFO Received push request method=POST path=/api/pushes16122026/10/27 08:16:01 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1613--- PASS: TestReadProxyNarStreaming (0.28s)1614=== CONT TestCacheConfigHandler1615=== RUN TestCacheConfigHandler/full_config,_no_issuer1616=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1617=== RUN TestCacheConfigHandler/no_cache_url_configured1618=== PAUSE TestCacheConfigHandler/no_cache_url_configured1619=== RUN TestCacheConfigHandler/no_signing_keys1620=== PAUSE TestCacheConfigHandler/no_signing_keys1621=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1622=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1623=== CONT TestMultipartCleanup16242026/10/27 08:16:01 INFO Received complete push request method=POST path=/api/pushes/3/complete16252026/10/27 08:16:01 WARN Failed to register uploaded object key=2mbkj0j9rdh95k31icz5wws23n1rcqmk.ls error="server returned 404: 404 page not found\n"16262026/10/27 08:16:01 INFO Completed push id=3 objects=3 duration=3.019328ms16272026/10/27 08:16:01 INFO Upload complete. (47ms)1628=== NAME TestClientIntegration1629 client_integration_test.go:352: Retrieved .ls file from S3 (compressed size: 62 bytes)1630 client_integration_test.go:352: Decompressed .ls content (49 bytes):1631 {"version":1,"root":{"type":"regular","size":39}}1632 client_integration_test.go:363: Testing garbage collection...1633--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.30s)1634=== CONT TestService_ReadScope_PublicByDefault16352026/10/27 08:16:01 INFO Starting cleanup of old closures method=DELETE path=/api/closures16362026/10/27 08:16:01 INFO Garbage collection started16372026/10/27 08:16:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45069/oidc16382026/10/27 08:16:01 INFO Aborted multipart uploads count=0 kept=016392026/10/27 08:16:01 WARN Force mode enabled - objects will be deleted immediately without grace period1640=== NAME TestClientCADerivations1641 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1642 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1643 error: binary cache 's3://bucket49?endpoint=http://localhost:39855®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations4016775737/001/store'1644 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11645--- PASS: TestClientCADerivations (0.99s)1646=== CONT TestObjectStatsTrigger1647--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.29s)1648=== CONT TestPendingCleanupUsesOneCutoff16492026/10/27 08:16:01 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=01650--- PASS: TestReadProxyContentNegotiation (0.34s)1651=== CONT TestService_RequireScope_OIDC16522026/10/27 08:16:01 INFO Vacuumed table table=pending_closures16532026/10/27 08:16:01 INFO Vacuumed table table=pending_objects16542026/10/27 08:16:01 INFO Vacuumed table table=multipart_uploads16552026/10/27 08:16:01 INFO Vacuumed table table=closures16562026/10/27 08:16:01 INFO Vacuumed table table=objects16572026/10/27 08:16:01 INFO Aborted multipart uploads count=0 kept=016582026/10/27 08:16:01 WARN Force mode enabled - objects will be deleted immediately without grace period16592026/10/27 08:16: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=016602026/10/27 08:16:01 INFO Vacuumed table table=pending_closures16612026/10/27 08:16:01 INFO Vacuumed table table=pending_objects16622026/10/27 08:16:01 INFO Vacuumed table table=multipart_uploads16632026/10/27 08:16:01 INFO Vacuumed table table=closures16642026/10/27 08:16:01 INFO Vacuumed table table=objects16652026/10/27 08:16:01 INFO Received uploads request method=POST path=/api/pending_closures1666--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.38s)1667=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1668=== NAME TestOrphanedObjectsGC1669 orphaned_objects_gc_test.go:287: GC Test Summary:1670 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1671 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1672 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1673 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1674 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1675--- PASS: TestOrphanedObjectsGC (0.91s)1676=== CONT TestService_NativeMTLS16772026/10/27 08:16:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45523/oidc16782026/10/27 08:16:01 INFO Aborted multipart uploads count=0 kept=016792026/10/27 08:16:01 WARN Force mode enabled - objects will be deleted immediately without grace period16802026/10/27 08:16:01 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1681--- PASS: TestReadProxyNarinfo (0.41s)1682=== CONT TestServerTLSConfig1683=== RUN TestServerTLSConfig/no_client_CA1684=== PAUSE TestServerTLSConfig/no_client_CA1685=== RUN TestServerTLSConfig/missing_CA_file1686=== PAUSE TestServerTLSConfig/missing_CA_file1687=== RUN TestServerTLSConfig/not_a_PEM_file1688=== PAUSE TestServerTLSConfig/not_a_PEM_file1689=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection16902026/10/27 08:16: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=01691--- PASS: TestGetExistingObjectsLocksRows (0.42s)1692=== CONT TestSweepSkipsRowsLockedByPush16932026/10/27 08:16:01 INFO Vacuumed table table=pending_closures16942026/10/27 08:16:01 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16952026/10/27 08:16:01 WARN mTLS auth: bound subjects configured but subject DN unavailable16962026/10/27 08:16:01 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1697--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.39s)1698=== CONT TestTombstonedObjectOfferedWithoutWaiting16992026/10/27 08:16:01 INFO Vacuumed table table=pending_objects17002026/10/27 08:16:01 INFO Vacuumed table table=multipart_uploads17012026/10/27 08:16:01 INFO Vacuumed table table=closures17022026/10/27 08:16:01 INFO Vacuumed table table=objects1703--- PASS: TestSweepRechecksPendingAfterLocking (0.43s)1704=== CONT TestFailedS3DeleteKeepsTombstone1705--- PASS: TestService_ReadAuthMiddleware (0.34s)1706=== CONT TestGCSweepDeliversEachKeyOnce1707--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.34s)1708=== CONT TestForceGCDuringPushOffersSweptObject1709=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1710=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1711=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1712=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1713=== CONT TestGCSweepSkipsPendingObjects17142026/10/27 08:16:01 INFO Received uploads request method=POST path=/api/pending_closures1715--- PASS: TestService_ReadScope_PublicByDefault (0.33s)1716=== CONT TestMetricsCommit17172026/10/27 08:16:01 INFO lead: released remote=192.0.2.1:12341718--- PASS: TestLeadEndsOnShutdown (1.72s)1719=== CONT TestProxyWriteTimeout/narinfo1720=== CONT TestProxyWriteTimeout/unknown_size1721=== CONT TestProxyWriteTimeout/10_GiB_nar1722=== CONT TestProxyWriteTimeout/1_GiB_nar1723--- PASS: TestProxyWriteTimeout (0.00s)1724 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1725 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1726 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1727 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1728=== CONT TestPendingClosureWriteTimeout/empty1729=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1730=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1731=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1732=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1733=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1734=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1735=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1736=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1737=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1738=== CONT TestPendingClosureWriteTimeout/670k_objects1739=== CONT TestPendingClosureWriteTimeout/400_objects1740=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17412026/10/27 08:16:01 INFO Received uploads request method=POST path=/1742=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17432026/10/27 08:16:01 INFO Received request for more parts method=POST path=/1744=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17452026/10/27 08:16:01 INFO Received complete multipart upload request method=POST path=/1746=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17472026/10/27 08:16:01 INFO Received uploads request method=POST path=/1748--- PASS: TestUploadHandlersRejectInvalidKeys (0.12s)1749 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1750 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1751 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1752 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1753=== CONT TestIsValidUploadKey/narinfo1754=== CONT TestIsValidUploadKey/realisation_plus_in_output1755=== CONT TestIsValidUploadKey/unknown_type1756=== CONT TestIsValidUploadKey/empty_key1757=== CONT TestIsValidUploadKey/absolute1758=== CONT TestIsValidUploadKey/traversal_nar1759=== CONT TestIsValidUploadKey/traversal1760=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1761=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1762=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1763=== CONT TestIsValidUploadKey/index.html1764=== CONT TestIsValidUploadKey/nix-cache-info1765=== CONT TestIsValidUploadKey/build_log_home-manager_file1766=== CONT TestIsValidUploadKey/realisation1767=== CONT TestIsValidUploadKey/build_log_equals1768=== CONT TestIsValidUploadKey/build_log_question_mark1769=== CONT TestIsValidUploadKey/build_log_plus_in_name1770=== CONT TestIsValidUploadKey/nar_plain1771=== CONT TestIsValidUploadKey/build_log1772=== CONT TestIsValidUploadKey/listing1773=== CONT TestIsValidUploadKey/nar_xz1774=== CONT TestIsValidUploadKey/nar_zst1775--- PASS: TestIsValidUploadKey (0.12s)1776 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1777 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1778 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1779 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1780 --- PASS: TestIsValidUploadKey/absolute (0.00s)1781 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1782 --- PASS: TestIsValidUploadKey/traversal (0.00s)1783 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1784 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1785 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1786 --- PASS: TestIsValidUploadKey/index.html (0.00s)1787 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1788 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1789 --- PASS: TestIsValidUploadKey/realisation (0.00s)1790 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1791 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1792 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1793 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1794 --- PASS: TestIsValidUploadKey/build_log (0.00s)1795 --- PASS: TestIsValidUploadKey/listing (0.00s)1796 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1797 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1798=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17992026/10/27 08:16:01 INFO Received request for more parts method=POST path=/1800=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18012026/10/27 08:16:01 INFO Received complete multipart upload request method=POST path=/1802--- PASS: TestObjectStatsTrigger (0.35s)1803=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18042026/10/27 08:16:01 INFO Received uploads request method=POST path=/18052026/10/27 08:16:01 INFO Received uploads request method=POST path=/api/pending_closures1806=== CONT TestPush_RejectsBadRequests/no_roots18072026/10/27 08:16:01 INFO Received push request method=POST path=/api/pushes1808=== CONT TestPush_RejectsBadRequests/bad_root18092026/10/27 08:16:01 INFO Received uploads request method=POST path=/api/pending_closures18102026/10/27 08:16:01 INFO Received push request method=POST path=/api/pushes1811=== CONT TestPush_RejectsBadRequests/root_not_in_objects18122026/10/27 08:16:01 INFO Received push request method=POST path=/api/pushes1813=== CONT TestPush_RejectsBadRequests/no_objects18142026/10/27 08:16:01 INFO Received push request method=POST path=/api/pushes1815=== CONT TestResolveDBConnectionString/flag_wins1816=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1817=== CONT TestResolveDBConnectionString/nothing_configured1818--- PASS: TestPush_RejectsBadRequests (0.94s)1819 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1820 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1821 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1822 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1823=== CONT TestResolveDBConnectionString/missing_file_is_an_error1824=== CONT TestResolveDBConnectionString/file_when_flag_empty1825=== CONT TestClientErrorHandling/InvalidStorePath1826--- PASS: TestResolveDBConnectionString (0.00s)1827 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1828 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1829 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1830 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1831 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)18322026/10/27 08:16:01 INFO Received cleanup request method=DELETE path=/api/pending_closures18332026/10/27 08:16:01 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket76/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""18342026/10/27 08:16:01 INFO Aborted multipart uploads count=0 kept=118352026/10/27 08:16:01 INFO Received uploads request method=POST path=/api/pending_closures18362026/10/27 08:16:01 INFO Received cleanup request method=DELETE path=/api/pending_closures18372026/10/27 08:16:01 INFO Received cleanup request method=DELETE path=/api/pending_closures18382026/10/27 08:16:01 INFO Aborted multipart uploads count=1 kept=01839--- PASS: TestMultipartCleanup (0.46s)1840=== CONT TestClientErrorHandling/ServerNotAvailable1841--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.28s)1842=== CONT TestClientErrorHandling/InvalidAuthToken18432026/10/27 08:16:01 WARN mTLS auth: subject not in bound subjects subject="CN=reader"18442026/10/27 08:16:01 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1845--- PASS: TestService_NativeMTLS (0.28s)1846=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1847--- PASS: TestDeleteClosuresRacingPins (1.63s)1848=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1849=== RUN TestService_RequireScope_OIDC/builder_may_write1850=== PAUSE TestService_RequireScope_OIDC/builder_may_write1851=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1852=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1853=== RUN TestService_RequireScope_OIDC/ops_may_admin1854=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1855=== RUN TestService_RequireScope_OIDC/ops_may_not_write1856=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1857=== RUN TestService_RequireScope_OIDC/reader_may_not_write1858=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1859=== RUN TestService_RequireScope_OIDC/static_token_may_admin1860=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1861=== RUN TestService_RequireScope_OIDC/static_token_may_write1862=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1863=== RUN TestService_RequireScope_OIDC/reader_may_read1864=== PAUSE TestService_RequireScope_OIDC/reader_may_read1865=== RUN TestService_RequireScope_OIDC/writer_implies_read1866=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1867=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1868=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1869=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1870=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1871=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1872=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1873=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1874=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1875=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1876=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1877=== CONT TestParseSingleRange/none1878=== CONT TestParseSingleRange/open-ended1879=== CONT TestParseSingleRange/start_far_past_EOF1880=== CONT TestParseSingleRange/start_past_EOF1881=== CONT TestParseSingleRange/single_byte1882=== CONT TestParseSingleRange/suffix_exceeds_size1883=== CONT TestParseSingleRange/suffix1884=== CONT TestParseSingleRange/end_clamped_to_size1885=== CONT TestParseSingleRange/malformed_both_empty1886=== CONT TestParseSingleRange/closed1887=== CONT TestParseSingleRange/malformed_end_before_start1888=== CONT TestParseSingleRange/multi-range_ignored1889=== CONT TestParseSingleRange/malformed_no_dash1890=== CONT TestParseSingleRange/unknown_unit1891--- PASS: TestParseSingleRange (0.00s)1892 --- PASS: TestParseSingleRange/none (0.00s)1893 --- PASS: TestParseSingleRange/open-ended (0.00s)1894 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1895 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1896 --- PASS: TestParseSingleRange/single_byte (0.00s)1897 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1898 --- PASS: TestParseSingleRange/suffix (0.00s)1899 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1900 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1901 --- PASS: TestParseSingleRange/closed (0.00s)1902 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1903 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1904 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1905 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1906=== CONT TestGCEndsOnShutdown/before_the_run19072026/10/27 08:16:01 INFO Received uploads request method=POST path=/api/pending_closures19082026/10/27 08:16:01 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/present19092026/10/27 08:16:01 INFO Received uploads request method=POST path=/api/pending_closures19102026/10/27 08:16:01 INFO Aborted multipart uploads count=0 kept=019112026/10/27 08:16:01 INFO lead: released remote=192.0.2.1:123419122026/10/27 08:16:01 WARN Force mode enabled - objects will be deleted immediately without grace period19132026/10/27 08:16: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=019142026/10/27 08:16:01 INFO Vacuumed table table=pending_closures19152026/10/27 08:16:01 INFO Vacuumed table table=pending_objects19162026/10/27 08:16:01 INFO Vacuumed table table=multipart_uploads19172026/10/27 08:16:01 INFO Vacuumed table table=closures19182026/10/27 08:16:01 INFO Received uploads request method=POST path=/api/pending_closures19192026/10/27 08:16:01 INFO Vacuumed table table=objects19202026/10/27 08:16:01 INFO Aborted multipart uploads count=0 kept=01921--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.35s)1922=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark19232026/10/27 08:16:01 WARN Force mode enabled - objects will be deleted immediately without grace period19242026/10/27 08:16:01 INFO Aborted multipart uploads count=0 kept=019252026/10/27 08:16: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=019262026/10/27 08:16:02 INFO Vacuumed table table=pending_closures19272026/10/27 08:16:02 INFO Vacuumed table table=pending_objects19282026/10/27 08:16:02 INFO Vacuumed table table=multipart_uploads19292026/10/27 08:16:02 INFO Vacuumed table table=closures19302026/10/27 08:16:02 WARN Force mode enabled - objects will be deleted immediately without grace period19312026/10/27 08:16:02 INFO Vacuumed table table=objects19322026/10/27 08:16:02 WARN Request failed, retrying attempt=2 backoff=189.964212ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1933--- PASS: TestSweepSkipsRowsLockedByPush (0.38s)1934=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete19352026/10/27 08:16:02 INFO lead: acquired remote=192.0.2.1:123419362026/10/27 08:16:02 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."19372026/10/27 08:16:02 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1938--- PASS: TestFailedS3DeleteKeepsTombstone (0.50s)1939=== CONT TestIsValidCachePath/narinfo1940=== CONT TestIsValidCachePath/index.html1941=== CONT TestIsValidCachePath/short_hash1942=== CONT TestIsValidCachePath/wrong_extension1943=== CONT TestIsValidCachePath/leading_slash1944--- PASS: TestPushWaitsForSweepHoldingRow (0.95s)1945=== CONT TestIsValidCachePath/random_path1946=== CONT TestIsValidCachePath/empty1947=== CONT TestIsValidCachePath/invalid_char_e1948=== CONT TestIsValidCachePath/invalid_char_u1949=== CONT TestIsValidCachePath/nar_uncompressed1950=== CONT TestIsValidCachePath/nix-cache-info1951=== CONT TestIsValidCachePath/realisation1952=== CONT TestIsValidCachePath/nar_xz1953=== CONT TestIsValidCachePath/log1954=== CONT TestIsValidCachePath/nar_bz21955=== CONT TestIsValidCachePath/ls1956=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1957=== CONT TestIsValidCachePath/nar_zst1958=== CONT TestCacheConfigHandler/full_config,_no_issuer1959--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.54s)1960=== CONT TestIsValidCachePath/traversal_parent1961=== CONT TestIsValidCachePath/traversal_in_middle1962=== CONT TestCacheConfigHandler/no_signing_keys1963=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1964=== CONT TestServerTLSConfig/not_a_PEM_file1965--- PASS: TestIsValidCachePath (0.00s)1966 --- PASS: TestIsValidCachePath/narinfo (0.00s)1967 --- PASS: TestIsValidCachePath/index.html (0.00s)1968 --- PASS: TestIsValidCachePath/short_hash (0.00s)1969 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1970 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1971 --- PASS: TestIsValidCachePath/random_path (0.00s)1972 --- PASS: TestIsValidCachePath/empty (0.00s)1973 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1974 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1975 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1976 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1977 --- PASS: TestIsValidCachePath/realisation (0.00s)1978 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1979 --- PASS: TestIsValidCachePath/log (0.00s)1980 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1981 --- PASS: TestIsValidCachePath/ls (0.00s)1982 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1983 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1984 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1985 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1986=== CONT TestCacheConfigHandler/no_cache_url_configured1987--- PASS: TestCacheConfigHandler (0.00s)1988 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1989 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1990 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1991 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1992=== CONT TestServerTLSConfig/no_client_CA1993=== CONT TestServerTLSConfig/missing_CA_file1994=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1995=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1996--- PASS: TestServerTLSConfig (0.00s)1997 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1998 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1999 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2000=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token20012026/10/27 08:16:02 INFO Received uploads request method=POST path=/api/pending_closures20022026/10/27 08:16:02 INFO Aborted multipart uploads count=0 kept=02003=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20042026/10/27 08:16:02 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]2005=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2006=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20072026/10/27 08:16:02 WARN Authentication failed token_preview=eyJhbGciOi...7VgQI3J5Jg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2008=== CONT TestService_RequireScope_OIDC/builder_may_write2009--- PASS: TestService_AuthMiddleware_OIDC (0.48s)2010 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2011 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2012 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2013 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2014=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2015=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read20162026/10/27 08:16:02 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]2017=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2018=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2019=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2020=== CONT TestService_RequireScope_OIDC/writer_implies_read2021=== CONT TestService_RequireScope_OIDC/reader_may_read2022=== CONT TestService_RequireScope_OIDC/static_token_may_write2023=== CONT TestService_RequireScope_OIDC/static_token_may_admin2024=== CONT TestService_RequireScope_OIDC/reader_may_not_write2025=== CONT TestService_RequireScope_OIDC/ops_may_not_write20262026/10/27 08:16:02 WARN Force mode enabled - objects will be deleted immediately without grace period2027=== CONT TestService_RequireScope_OIDC/ops_may_admin2028=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2029--- PASS: TestService_RequireScope_OIDC (0.41s)2030 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2031 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2032 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2033 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2034 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2035 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2036 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2037 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2038 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2039 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2040 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2041 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2042 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2043 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)20442026/10/27 08:16:02 INFO Aborted multipart uploads count=0 kept=020452026/10/27 08:16:02 WARN Force mode enabled - objects will be deleted immediately without grace period20462026/10/27 08:16:02 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=020472026/10/27 08:16:02 INFO Received push request method=POST path=/api/pushes20482026/10/27 08:16:02 INFO Vacuumed table table=pending_closures20492026/10/27 08:16:02 INFO Vacuumed table table=pending_objects20502026/10/27 08:16:02 INFO Vacuumed table table=multipart_uploads20512026/10/27 08:16:02 INFO Vacuumed table table=closures20522026/10/27 08:16:02 INFO Vacuumed table table=objects2053--- PASS: TestGCSweepSkipsPendingObjects (0.51s)20542026/10/27 08:16:02 INFO Received complete push request method=POST path=/api/pushes/1/complete20552026/10/27 08:16:02 INFO Completed push id=1 objects=4 duration=6.939088ms20562026/10/27 08:16:02 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete20572026/10/27 08:16:02 INFO Completed upload id=2 objects=2 duration=1.43703ms20582026/10/27 08:16:02 INFO Received uploads request method=POST path=/api/pending_closures20592026/10/27 08:16:02 WARN Request failed, retrying attempt=3 backoff=426.684245ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20602026/10/27 08:16:02 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=020612026/10/27 08:16:02 INFO Vacuumed table table=pending_closures20622026/10/27 08:16:02 INFO Vacuumed table table=pending_objects20632026/10/27 08:16:02 INFO Vacuumed table table=multipart_uploads2064--- PASS: TestMetricsCommit (0.48s)20652026/10/27 08:16:02 INFO Vacuumed table table=closures20662026/10/27 08:16:02 INFO Vacuumed table table=objects2067--- PASS: TestGCSweepDeliversEachKeyOnce (0.56s)20682026/10/27 08:16:02 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20692026/10/27 08:16:02 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20702026/10/27 08:16:02 INFO Aborted multipart uploads count=0 kept=020712026/10/27 08:16:02 WARN Force mode enabled - objects will be deleted immediately without grace period20722026/10/27 08:16:02 INFO Aborted multipart uploads count=0 kept=020732026/10/27 08:16:02 WARN Force mode enabled - objects will be deleted immediately without grace period20742026/10/27 08:16:02 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:39855/bucket98/?delete=\": context canceled"2075--- PASS: TestGCEndsOnShutdown (0.00s)2076 --- PASS: TestGCEndsOnShutdown/before_the_run (0.46s)2077 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.41s)2078 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.39s)20792026/10/27 08:16:02 INFO Received uploads request method=POST path=/api/pending_closures20802026/10/27 08:16:02 INFO Aborted multipart uploads count=0 kept=020812026/10/27 08:16:02 WARN Force mode enabled - objects will be deleted immediately without grace period20822026/10/27 08:16:02 INFO Received uploads request method=POST path=/api/pending_closures2083--- PASS: TestUploadHandlersRejectOversizedBody (0.19s)2084 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.03s)2085 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.03s)2086 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.66s)20872026/10/27 08:16:02 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=020882026/10/27 08:16:02 INFO Vacuumed table table=pending_closures20892026/10/27 08:16:02 INFO Vacuumed table table=pending_objects20902026/10/27 08:16:02 INFO Vacuumed table table=multipart_uploads20912026/10/27 08:16:02 INFO Vacuumed table table=closures20922026/10/27 08:16:02 INFO Aborted multipart uploads count=0 kept=020932026/10/27 08:16:02 INFO Vacuumed table table=objects20942026/10/27 08:16:02 WARN Force mode enabled - objects will be deleted immediately without grace period20952026/10/27 08:16:02 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=020962026/10/27 08:16:02 INFO Vacuumed table table=pending_closures20972026/10/27 08:16:02 INFO Vacuumed table table=pending_objects20982026/10/27 08:16:02 INFO Vacuumed table table=multipart_uploads20992026/10/27 08:16:02 INFO Vacuumed table table=closures21002026/10/27 08:16:02 INFO Vacuumed table table=objects2101--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2102 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.33s)2103 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.34s)21042026/10/27 08:16:02 WARN Rate limiter enabled after throttle name=s3-test rate=521052026/10/27 08:16:02 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2106=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2107 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102108 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002109--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (3.37s)21102026/10/27 08:16:02 WARN Request failed, retrying attempt=4 backoff=782.902209ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2111--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2112 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.94s)2113 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.95s)21142026/10/27 08:16:02 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=021152026/10/27 08:16:02 INFO Received create pin request method=POST path=/api/pins/myapp21162026/10/27 08:16:02 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3596638313/001/store/n6drdad2nbh4zin60krsfx4l58q73gl1-pinned-file.txt narinfo_key=n6drdad2nbh4zin60krsfx4l58q73gl1.narinfo21172026/10/27 08:16:02 INFO Starting cleanup of old closures method=DELETE path=/api/closures21182026/10/27 08:16:02 INFO Garbage collection started21192026/10/27 08:16:02 INFO Aborted multipart uploads count=0 kept=021202026/10/27 08:16:02 WARN Force mode enabled - objects will be deleted immediately without grace period21212026/10/27 08:16:02 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=021222026/10/27 08:16:02 INFO Vacuumed table table=pending_closures21232026/10/27 08:16:02 INFO Vacuumed table table=pending_objects21242026/10/27 08:16:02 INFO Vacuumed table table=multipart_uploads21252026/10/27 08:16:02 INFO Vacuumed table table=closures21262026/10/27 08:16:02 INFO Vacuumed table table=objects2127--- PASS: TestPendingClosureWriteTimeout (0.11s)2128 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2129 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2130 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2131 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.27s)2132=== NAME TestOrphanedObjectsGCStressTest2133 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2134 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion21352026/10/27 08:16:03 INFO lead: released remote=192.0.2.1:12342136--- PASS: TestLeadElectsOneAndHandsOver (2.95s)21372026/10/27 08:16:03 WARN Request failed, retrying attempt=5 backoff=1.524902581s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21382026/10/27 08:16:03 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02139=== NAME TestClientIntegration2140 client_integration_test.go:370: Objects in database after GC:2141 client_integration_test.go:370: Successfully deleted all objects with GC --force2142--- PASS: TestClientIntegration (2.99s)2143=== NAME TestOrphanedObjectsGCStressTest2144 orphaned_objects_gc_test.go:503: Stress test completed successfully:2145 orphaned_objects_gc_test.go:504: - Active objects preserved: 202146 orphaned_objects_gc_test.go:505: - Objects deleted: 2102147 orphaned_objects_gc_test.go:506: - Total GC'd: 2102148--- PASS: TestOrphanedObjectsGCStressTest (3.62s)2149=== NAME TestPinProtectsFromGC2150 client_integration_test.go:887: Pin successfully protected closure from garbage collection2151--- PASS: TestPinProtectsFromGC (5.01s)21522026/10/27 08:16:04 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21532026/10/27 08:16:05 WARN Request failed, retrying attempt=2 backoff=219.51598ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21542026/10/27 08:16:05 WARN Request failed, retrying attempt=3 backoff=393.386901ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2155--- PASS: TestConnectWaitsForAPeerMigration (5.15s)2156--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.48s)21572026/10/27 08:16:05 WARN Request failed, retrying attempt=4 backoff=764.759475ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21582026/10/27 08:16:06 WARN Request failed, retrying attempt=5 backoff=1.474047304s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21592026/10/27 08:16:07 INFO Aborted multipart uploads count=1 kept=021602026/10/27 08:16:07 INFO Received cleanup request method=DELETE path=/api/pending_closures21612026/10/27 08:16:07 INFO Aborted multipart uploads count=1 kept=02162--- PASS: TestPendingCleanupUsesOneCutoff (6.40s)21632026/10/27 08:16:07 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"21642026/10/27 08:16: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-config21652026/10/27 08:16:08 WARN Request failed, retrying attempt=2 backoff=189.901803ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21662026/10/27 08:16:08 WARN Request failed, retrying attempt=3 backoff=434.501261ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21672026/10/27 08:16:08 WARN Request failed, retrying attempt=4 backoff=855.032873ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21682026/10/27 08:16:09 WARN Request failed, retrying attempt=5 backoff=1.651437321s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21692026/10/27 08:16:11 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_closures21702026/10/27 08:16:11 WARN Request failed, retrying attempt=2 backoff=216.597414ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21712026/10/27 08:16:11 WARN Request failed, retrying attempt=3 backoff=397.450275ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21722026/10/27 08:16:11 WARN Request failed, retrying attempt=4 backoff=742.7023ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21732026/10/27 08:16:12 WARN Request failed, retrying attempt=5 backoff=1.665126556s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2174--- PASS: TestClientErrorHandling (0.00s)2175 --- PASS: TestClientErrorHandling/InvalidStorePath (0.45s)2176 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.53s)2177 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.47s)2178PASS2179{"timestamp":"2026-10-27T08:16:14.302766708Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:58730","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(391)"}21802026-10-27 08:16:14.590 UTC [128] LOG: received smart shutdown request21812026-10-27 08:16:14.595 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 121822026-10-27 08:16:14.606 UTC [133] LOG: shutting down21832026-10-27 08:16:14.607 UTC [133] LOG: checkpoint starting: shutdown immediate21842026-10-27 08:16:16.494 UTC [133] LOG: checkpoint complete: wrote 11121 buffers (67.9%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 30 recycled; write=0.240 s, sync=1.588 s, total=1.888 s; sync files=34046, longest=0.015 s, average=0.001 s; distance=494050 kB, estimate=494050 kB; lsn=0/1F9DE538, redo lsn=0/1F9DE53821852026-10-27 08:16:16.575 UTC [128] LOG: database system is shut down2186Running OIDC tests...2187=== RUN TestAudienceForIssuer2188=== PAUSE TestAudienceForIssuer2189=== RUN TestGlobMatch2190=== PAUSE TestGlobMatch2191=== RUN TestValidateToken_ValidToken2192=== PAUSE TestValidateToken_ValidToken2193=== RUN TestValidateToken_WrongAudience2194=== PAUSE TestValidateToken_WrongAudience2195=== RUN TestValidateToken_Expired2196=== PAUSE TestValidateToken_Expired2197=== RUN TestValidateToken_BoundClaimsMismatch2198=== PAUSE TestValidateToken_BoundClaimsMismatch2199=== RUN TestValidateToken_BoundSubjectMismatch2200=== PAUSE TestValidateToken_BoundSubjectMismatch2201=== RUN TestValidateToken_MultipleProviders2202=== PAUSE TestValidateToken_MultipleProviders2203=== RUN TestValidateToken_NoMatchingProvider2204=== PAUSE TestValidateToken_NoMatchingProvider2205=== RUN TestValidateToken_KubernetesServiceAccount2206=== PAUSE TestValidateToken_KubernetesServiceAccount2207=== RUN TestNewValidator_KubernetesRequiresCA2208=== PAUSE TestNewValidator_KubernetesRequiresCA2209=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2210=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2211=== RUN TestPins_ReservedForMatchingRule2212=== PAUSE TestPins_ReservedForMatchingRule2213=== RUN TestPins_TopLevelShorthand2214=== PAUSE TestPins_TopLevelShorthand2215=== RUN TestPins_ConfigValidation2216=== PAUSE TestPins_ConfigValidation2217=== RUN TestScopes_LegacyProviderDefaultsToWrite2218=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2219=== RUN TestScopes_Rules2220=== PAUSE TestScopes_Rules2221=== RUN TestScopes_ConfigValidation2222=== PAUSE TestScopes_ConfigValidation2223=== CONT TestAudienceForIssuer2224=== CONT TestValidateToken_BoundClaimsMismatch2225=== CONT TestValidateToken_WrongAudience2226--- PASS: TestAudienceForIssuer (0.00s)2227=== CONT TestValidateToken_ValidToken2228=== CONT TestGlobMatch2229=== RUN TestGlobMatch/foo_foo2230=== PAUSE TestGlobMatch/foo_foo2231=== RUN TestGlobMatch/foo_bar2232=== PAUSE TestGlobMatch/foo_bar2233=== RUN TestGlobMatch/*_2234=== PAUSE TestGlobMatch/*_2235=== RUN TestGlobMatch/*_anything2236=== PAUSE TestGlobMatch/*_anything2237=== RUN TestGlobMatch/foo*_foo2238=== PAUSE TestGlobMatch/foo*_foo2239=== CONT TestValidateToken_MultipleProviders2240=== CONT TestValidateToken_NoMatchingProvider2241=== CONT TestValidateToken_BoundSubjectMismatch2242=== CONT TestValidateToken_Expired2243=== CONT TestPins_ConfigValidation2244=== CONT TestScopes_ConfigValidation2245=== CONT TestScopes_Rules2246=== CONT TestValidateToken_KubernetesServiceAccount2247=== CONT TestScopes_LegacyProviderDefaultsToWrite2248=== CONT TestPins_TopLevelShorthand2249=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2250=== CONT TestPins_ReservedForMatchingRule2251=== CONT TestNewValidator_KubernetesRequiresCA2252=== RUN TestGlobMatch/foo*_foobar2253=== PAUSE TestGlobMatch/foo*_foobar2254=== RUN TestGlobMatch/foo*_bar2255=== PAUSE TestGlobMatch/foo*_bar2256=== RUN TestGlobMatch/*bar_bar2257=== PAUSE TestGlobMatch/*bar_bar2258=== RUN TestGlobMatch/*bar_foobar2259=== PAUSE TestGlobMatch/*bar_foobar2260=== RUN TestGlobMatch/*bar_foo2261=== PAUSE TestGlobMatch/*bar_foo2262=== RUN TestGlobMatch/foo*bar_foobar2263=== PAUSE TestGlobMatch/foo*bar_foobar2264=== RUN TestGlobMatch/foo*bar_foo123bar2265=== PAUSE TestGlobMatch/foo*bar_foo123bar2266=== RUN TestGlobMatch/foo*bar_foobarbaz2267=== PAUSE TestGlobMatch/foo*bar_foobarbaz2268=== RUN TestGlobMatch/*/*_foo/bar2269=== PAUSE TestGlobMatch/*/*_foo/bar2270=== RUN TestGlobMatch/*/*_foo2271=== PAUSE TestGlobMatch/*/*_foo2272--- PASS: TestScopes_ConfigValidation (0.00s)2273=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2274=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2275=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02276=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02277=== RUN TestGlobMatch/refs/*/main_refs/heads/main2278=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2279=== RUN TestGlobMatch/fo?_foo2280=== PAUSE TestGlobMatch/fo?_foo2281=== RUN TestGlobMatch/fo?_fo2282=== PAUSE TestGlobMatch/fo?_fo2283=== RUN TestGlobMatch/fo?_fooo2284=== PAUSE TestGlobMatch/fo?_fooo2285=== RUN TestGlobMatch/?oo_foo2286=== PAUSE TestGlobMatch/?oo_foo2287=== RUN TestGlobMatch/?oo_boo2288=== PAUSE TestGlobMatch/?oo_boo2289=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2290=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2291=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2292=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2293=== CONT TestGlobMatch/foo_foo2294=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2295=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2296=== CONT TestGlobMatch/?oo_boo2297=== CONT TestGlobMatch/?oo_foo2298=== CONT TestGlobMatch/fo?_fooo2299=== CONT TestGlobMatch/fo?_fo2300=== CONT TestGlobMatch/fo?_foo2301=== CONT TestGlobMatch/refs/*/main_refs/heads/main2302=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02303=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2304=== CONT TestGlobMatch/*/*_foo2305=== CONT TestGlobMatch/*/*_foo/bar2306=== CONT TestGlobMatch/foo*bar_foobarbaz2307=== CONT TestGlobMatch/foo*bar_foo123bar2308=== CONT TestGlobMatch/foo*bar_foobar2309=== CONT TestGlobMatch/*bar_foo2310=== CONT TestGlobMatch/*bar_foobar2311=== CONT TestGlobMatch/*bar_bar2312=== CONT TestGlobMatch/foo*_bar2313=== CONT TestGlobMatch/foo*_foobar2314=== CONT TestGlobMatch/foo*_foo2315=== CONT TestGlobMatch/*_anything2316=== CONT TestGlobMatch/*_2317=== CONT TestGlobMatch/foo_bar2318--- PASS: TestGlobMatch (0.01s)2319 --- PASS: TestGlobMatch/foo_foo (0.00s)2320 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2321 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2322 --- PASS: TestGlobMatch/?oo_boo (0.00s)2323 --- PASS: TestGlobMatch/?oo_foo (0.00s)2324 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2325 --- PASS: TestGlobMatch/fo?_fo (0.00s)2326 --- PASS: TestGlobMatch/fo?_foo (0.00s)2327 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2328 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2329 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2330 --- PASS: TestGlobMatch/*/*_foo (0.00s)2331 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2332 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2333 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2334 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2335 --- PASS: TestGlobMatch/*bar_foo (0.00s)2336 --- PASS: TestGlobMatch/*bar_bar (0.00s)2337 --- PASS: TestGlobMatch/foo*_bar (0.00s)2338 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2339 --- PASS: TestGlobMatch/foo*_foo (0.00s)2340 --- PASS: TestGlobMatch/*_anything (0.00s)2341 --- PASS: TestGlobMatch/*_ (0.00s)2342 --- PASS: TestGlobMatch/foo_bar (0.00s)2343 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2344--- PASS: TestPins_ConfigValidation (0.00s)23452026/10/27 08:16:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45179/oidc2346--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.03s)23472026/10/27 08:16:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45321/oidc2348--- PASS: TestValidateToken_BoundSubjectMismatch (0.03s)23492026/10/27 08:16:18 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:3356523502026/10/27 08:16:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46715/oidc2351--- PASS: TestValidateToken_BoundClaimsMismatch (0.05s)2352--- PASS: TestValidateToken_KubernetesServiceAccount (0.04s)23532026/10/27 08:16:18 http: TLS handshake error from 127.0.0.1:52590: remote error: tls: bad certificate2354--- PASS: TestNewValidator_KubernetesRequiresCA (0.06s)23552026/10/27 08:16:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36361/oidc23562026/10/27 08:16:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42679/oidc2357--- PASS: TestValidateToken_ValidToken (0.07s)23582026/10/27 08:16:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39607/oidc2359--- PASS: TestValidateToken_WrongAudience (0.08s)23602026/10/27 08:16:18 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232361--- PASS: TestValidateToken_Expired (0.07s)2362--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.08s)23632026/10/27 08:16:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39807/oidc2364--- PASS: TestPins_TopLevelShorthand (0.08s)23652026/10/27 08:16:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46445/oidc2366--- PASS: TestScopes_Rules (0.09s)23672026/10/27 08:16:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39677/oidc2368--- PASS: TestPins_ReservedForMatchingRule (0.13s)23692026/10/27 08:16:18 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:38923/oidc23702026/10/27 08:16:18 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:39719/oidc2371--- PASS: TestValidateToken_MultipleProviders (0.14s)23722026/10/27 08:16:18 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:32785/oidc2373--- PASS: TestValidateToken_NoMatchingProvider (0.25s)2374PASS2375Running hook tests...2376=== RUN TestSendPathsEmpty2377=== PAUSE TestSendPathsEmpty2378=== RUN TestQueueEnqueueAndFetch2379=== PAUSE TestQueueEnqueueAndFetch2380=== RUN TestQueueDeduplication2381=== PAUSE TestQueueDeduplication2382=== RUN TestQueueRemove2383=== PAUSE TestQueueRemove2384=== RUN TestQueueFetchBatchLimit2385=== PAUSE TestQueueFetchBatchLimit2386=== RUN TestQueueRetryMovesToBack2387=== PAUSE TestQueueRetryMovesToBack2388=== RUN TestQueueFetchRemoveLifecycle2389=== PAUSE TestQueueFetchRemoveLifecycle2390=== RUN TestQueueConcurrentWriters2391=== PAUSE TestQueueConcurrentWriters2392=== RUN TestQueueRemoveLargeClosure2393=== PAUSE TestQueueRemoveLargeClosure2394=== RUN TestServerClientIntegration2395--- PASS: TestServerClientIntegration (0.00s)2396=== RUN TestServerQueueError23972026/10/27 08:16:18 ERROR Failed to queue paths error="permission denied" count=12398--- PASS: TestServerQueueError (0.00s)2399=== RUN TestGetListenerSocketActivation2400 server_test.go:218: === RUN TestGetListenerSocketActivation2401 --- PASS: TestGetListenerSocketActivation (0.00s)2402 PASS2403 2404--- PASS: TestGetListenerSocketActivation (0.01s)2405=== RUN TestServerStalledClientDoesNotBlockShutdown2406=== PAUSE TestServerStalledClientDoesNotBlockShutdown2407=== RUN TestServerBacksOffOnAcceptErrors2408=== PAUSE TestServerBacksOffOnAcceptErrors2409=== RUN TestDrainIsolatesPoisonPath2410=== PAUSE TestDrainIsolatesPoisonPath2411=== RUN TestRunNotBlockedByPoisonHead2412=== PAUSE TestRunNotBlockedByPoisonHead2413=== RUN TestDrainGivesUpWhenServerDown2414=== PAUSE TestDrainGivesUpWhenServerDown2415=== RUN TestFailedPathPrunedByLaterClosure2416=== PAUSE TestFailedPathPrunedByLaterClosure2417=== RUN TestWorkerUploadsAndRemoves2418=== PAUSE TestWorkerUploadsAndRemoves2419=== RUN TestWorkerSkipsGCdPaths2420=== PAUSE TestWorkerSkipsGCdPaths2421=== RUN TestWorkerPrunesClosureDeps2422=== PAUSE TestWorkerPrunesClosureDeps2423=== RUN TestDrainTimeout2424=== PAUSE TestDrainTimeout2425=== RUN TestWorkerRemoveFailureIsNotProgress2426=== PAUSE TestWorkerRemoveFailureIsNotProgress2427=== RUN TestWorkerKeepsPathItCannotStat2428=== PAUSE TestWorkerKeepsPathItCannotStat2429=== CONT TestSendPathsEmpty2430=== CONT TestWorkerRemoveFailureIsNotProgress2431--- PASS: TestSendPathsEmpty (0.00s)2432=== CONT TestWorkerKeepsPathItCannotStat2433=== CONT TestDrainIsolatesPoisonPath2434=== CONT TestQueueRetryMovesToBack2435=== CONT TestQueueFetchBatchLimit2436=== CONT TestQueueRemove2437=== CONT TestQueueDeduplication2438=== CONT TestQueueFetchRemoveLifecycle2439=== CONT TestQueueEnqueueAndFetch2440=== CONT TestServerBacksOffOnAcceptErrors24412026/10/27 08:16:18 ERROR Accept failed error="too many open files"2442=== CONT TestQueueConcurrentWriters2443=== CONT TestWorkerUploadsAndRemoves2444=== CONT TestQueueRemoveLargeClosure2445=== CONT TestDrainTimeout2446=== CONT TestServerStalledClientDoesNotBlockShutdown2447=== CONT TestWorkerPrunesClosureDeps2448=== CONT TestWorkerSkipsGCdPaths2449=== CONT TestDrainGivesUpWhenServerDown2450=== CONT TestRunNotBlockedByPoisonHead2451=== CONT TestFailedPathPrunedByLaterClosure24522026/10/27 08:16:18 ERROR Accept failed error="too many open files"24532026/10/27 08:16:18 INFO Uploading batch count=224542026/10/27 08:16:18 ERROR Upload failed error="upload failed" count=224552026/10/27 08:16:18 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2263373885/002/a24562026/10/27 08:16:18 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3858277439/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat3858277439/002/locked/aaa: permission denied"24572026/10/27 08:16:18 ERROR Accept failed error="too many open files"24582026/10/27 08:16:18 INFO Uploading batch count=424592026/10/27 08:16:18 ERROR Upload failed error="upload failed" count=424602026/10/27 08:16:18 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2263373885/002/b24612026/10/27 08:16:18 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3858277439/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat3858277439/002/locked/aaa: permission denied"24622026/10/27 08:16:18 INFO Uploading batch count=224632026/10/27 08:16:18 INFO Uploading batch count=124642026/10/27 08:16:18 ERROR Upload failed error="upload failed" count=12465--- PASS: TestQueueRemove (0.02s)2466--- PASS: TestQueueDeduplication (0.02s)24672026/10/27 08:16:18 INFO Upload queue status pending=224682026/10/27 08:16:18 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath4124861730/002/bbb24692026/10/27 08:16:18 INFO Upload queue status pending=224702026/10/27 08:16:18 INFO Upload queue status pending=32471--- PASS: TestQueueEnqueueAndFetch (0.02s)24722026/10/27 08:16:18 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths621066889/002/nonexistent24732026/10/27 08:16:18 INFO Uploading batch count=124742026/10/27 08:16:18 ERROR Upload failed error="upload failed" count=124752026/10/27 08:16:18 INFO Uploading batch count=224762026/10/27 08:16:18 INFO Uploading batch count=22477--- PASS: TestQueueFetchBatchLimit (0.02s)24782026/10/27 08:16:18 ERROR Upload failed error="upload failed" count=224792026/10/27 08:16:18 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2263373885/002/c24802026/10/27 08:16:18 INFO Upload queue status pending=224812026/10/27 08:16:18 INFO Uploading batch count=12482--- PASS: TestQueueRetryMovesToBack (0.02s)24832026/10/27 08:16:18 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3858277439/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat3858277439/002/locked/aaa: permission denied"2484--- PASS: TestQueueFetchRemoveLifecycle (0.02s)24852026/10/27 08:16:18 INFO Uploading batch count=124862026/10/27 08:16:18 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress2675837150/002/nonexistent24872026/10/27 08:16:18 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2263373885/002/d24882026/10/27 08:16:18 INFO Uploading batch count=124892026/10/27 08:16:18 INFO Uploading batch count=124902026/10/27 08:16:18 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=124912026/10/27 08:16:18 ERROR Drain finished with paths left in queue remaining=124922026/10/27 08:16:18 INFO Uploading batch count=124932026/10/27 08:16:18 ERROR Upload failed error="upload failed" count=124942026/10/27 08:16:18 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress2675837150/002/nonexistent24952026/10/27 08:16:18 INFO Uploading batch count=224962026/10/27 08:16:18 ERROR Upload failed error="upload failed" count=224972026/10/27 08:16:18 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2263373885/002/e24982026/10/27 08:16:18 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=124992026/10/27 08:16:18 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress2675837150/002/nonexistent25002026/10/27 08:16:18 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125012026/10/27 08:16:18 ERROR Drain finished with paths left in queue remaining=125022026/10/27 08:16:18 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2263373885/002/f25032026/10/27 08:16:18 INFO Uploading batch count=125042026/10/27 08:16:18 ERROR Upload failed error="upload failed" count=125052026/10/27 08:16:18 ERROR Drain finished with paths left in queue remaining=102506--- PASS: TestWorkerKeepsPathItCannotStat (0.02s)2507--- PASS: TestWorkerRemoveFailureIsNotProgress (0.02s)25082026/10/27 08:16:18 INFO Uploading batch count=125092026/10/27 08:16:18 ERROR Upload failed error="upload failed" count=12510--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)25112026/10/27 08:16:18 ERROR Drain finished with paths left in queue remaining=12512--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2513--- PASS: TestDrainIsolatesPoisonPath (0.03s)25142026/10/27 08:16:18 ERROR Accept failed error="too many open files"2515--- PASS: TestWorkerSkipsGCdPaths (0.04s)2516--- PASS: TestWorkerUploadsAndRemoves (0.04s)2517--- PASS: TestWorkerPrunesClosureDeps (0.04s)2518--- PASS: TestQueueRemoveLargeClosure (0.06s)25192026/10/27 08:16:19 ERROR Accept failed error="too many open files"25202026/10/27 08:16:19 ERROR Accept failed error="too many open files"25212026/10/27 08:16:19 ERROR Failed to decode request error="read unix /build/hook3185969132/test.sock->@: i/o timeout"25222026/10/27 08:16:19 ERROR Failed to write response error="write unix /build/hook3185969132/test.sock->@: i/o timeout"2523--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)25242026/10/27 08:16:19 ERROR Upload failed error="context deadline exceeded" count=225252026/10/27 08:16:19 ERROR Drain finished with paths left in queue remaining=42526--- PASS: TestDrainTimeout (0.22s)2527--- PASS: TestQueueConcurrentWriters (0.28s)25282026/10/27 08:16:19 ERROR Accept failed error="too many open files"25292026/10/27 08:16:19 ERROR Accept failed error="too many open files"2530--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)25312026/10/27 08:16:19 INFO Uploading batch count=125322026/10/27 08:16:19 INFO Uploading batch count=125332026/10/27 08:16:19 INFO Uploading batch count=125342026/10/27 08:16:19 ERROR Upload failed error="upload failed" count=125352026/10/27 08:16:19 INFO Uploading batch count=125362026/10/27 08:16:19 ERROR Upload failed error="upload failed" count=125372026/10/27 08:16:19 INFO Uploading batch count=125382026/10/27 08:16:19 ERROR Upload failed error="upload failed" count=125392026/10/27 08:16:19 INFO Uploading batch count=125402026/10/27 08:16:19 ERROR Upload failed error="upload failed" count=125412026/10/27 08:16:19 ERROR Drain finished with paths left in queue remaining=12542--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2543PASS2544Running signing tests...2545=== RUN TestExternalSigner2546=== PAUSE TestExternalSigner2547=== RUN TestExternalSignerWrongPublicKey2548=== PAUSE TestExternalSignerWrongPublicKey2549=== RUN TestExternalSignerErrors2550=== PAUSE TestExternalSignerErrors2551=== RUN TestExternalSignerRestartsAfterCrash2552=== PAUSE TestExternalSignerRestartsAfterCrash2553=== RUN TestExternalSignerProgramErrorKeepsProcess2554=== PAUSE TestExternalSignerProgramErrorKeepsProcess2555=== RUN TestExternalSignerClose2556=== PAUSE TestExternalSignerClose2557=== RUN TestExternalSignerRejectsInvalidPublicKey2558=== PAUSE TestExternalSignerRejectsInvalidPublicKey2559=== RUN TestExternalSignerCancellation2560=== PAUSE TestExternalSignerCancellation2561=== RUN TestGenerateFingerprint2562=== PAUSE TestGenerateFingerprint2563=== RUN TestParseSigningKey2564=== PAUSE TestParseSigningKey2565=== RUN TestSign2566=== PAUSE TestSign2567=== RUN TestSignBatch2568=== PAUSE TestSignBatch2569=== RUN TestNilKeyPublicKey2570=== PAUSE TestNilKeyPublicKey2571=== RUN TestSignErrors2572=== PAUSE TestSignErrors2573=== CONT TestExternalSigner2574=== CONT TestExternalSignerCancellation2575=== CONT TestSignErrors2576=== CONT TestExternalSignerProgramErrorKeepsProcess2577=== CONT TestExternalSignerClose2578=== CONT TestSign2579=== CONT TestExternalSignerRejectsInvalidPublicKey2580=== CONT TestNilKeyPublicKey2581=== RUN TestExternalSignerRejectsInvalidPublicKey/#002582--- PASS: TestNilKeyPublicKey (0.00s)2583=== CONT TestExternalSignerRestartsAfterCrash2584--- PASS: TestSign (0.00s)2585=== CONT TestSignBatch2586=== CONT TestParseSigningKey2587=== RUN TestParseSigningKey/valid_32-byte_key2588=== PAUSE TestParseSigningKey/valid_32-byte_key2589=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2590=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2591=== CONT TestExternalSignerWrongPublicKey2592=== CONT TestGenerateFingerprint2593=== CONT TestExternalSignerErrors2594=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002595=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2596=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2597=== RUN TestSignErrors/nil_key2598=== RUN TestGenerateFingerprint/basic_with_references2599=== PAUSE TestSignErrors/nil_key2600=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2601=== RUN TestSignErrors/nil_narinfo2602=== PAUSE TestSignErrors/nil_narinfo2603=== RUN TestSignErrors/invalid_narinfo2604=== PAUSE TestSignErrors/invalid_narinfo2605=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2606=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2607=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2608=== RUN TestParseSigningKey/no_colon2609=== PAUSE TestParseSigningKey/no_colon2610=== PAUSE TestGenerateFingerprint/basic_with_references2611--- PASS: TestSignBatch (0.00s)2612=== RUN TestGenerateFingerprint/no_references2613=== PAUSE TestGenerateFingerprint/no_references2614=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2615=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2616=== RUN TestExternalSignerErrors/exit_at_startup2617=== PAUSE TestExternalSignerErrors/exit_at_startup2618=== RUN TestSignErrors/canceled2619=== PAUSE TestSignErrors/canceled2620=== CONT TestSignErrors/nil_key2621=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2622=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2623=== CONT TestExternalSignerRejectsInvalidPublicKey/#002624=== RUN TestParseSigningKey/empty_name2625=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2626=== RUN TestExternalSignerErrors/wrong_id2627=== PAUSE TestExternalSignerErrors/wrong_id2628=== CONT TestSignErrors/invalid_narinfo2629=== CONT TestSignErrors/canceled2630=== CONT TestSignErrors/nil_narinfo2631--- PASS: TestSignErrors (0.00s)2632 --- PASS: TestSignErrors/nil_key (0.00s)2633 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2634 --- PASS: TestSignErrors/canceled (0.00s)2635 --- PASS: TestSignErrors/nil_narinfo (0.00s)2636=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2637=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2638=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2639=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2640--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2641 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2642 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2643 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2644 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2645 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2646=== PAUSE TestParseSigningKey/empty_name2647=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2648=== RUN TestExternalSignerErrors/null_signatures2649=== RUN TestGenerateFingerprint/invalid_nar_hash_length2650=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2651=== RUN TestGenerateFingerprint/invalid_store_path_prefix2652=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2653=== RUN TestGenerateFingerprint/invalid_reference_prefix2654=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2655=== CONT TestGenerateFingerprint/basic_with_references2656--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2657--- PASS: TestExternalSignerClose (0.00s)2658=== CONT TestGenerateFingerprint/invalid_nar_hash_length2659=== RUN TestParseSigningKey/invalid_base642660=== PAUSE TestParseSigningKey/invalid_base642661=== RUN TestParseSigningKey/wrong_length2662=== PAUSE TestParseSigningKey/wrong_length2663=== CONT TestParseSigningKey/valid_32-byte_key2664=== CONT TestParseSigningKey/invalid_base642665=== PAUSE TestExternalSignerErrors/null_signatures2666=== CONT TestParseSigningKey/empty_name2667=== CONT TestGenerateFingerprint/invalid_reference_prefix2668=== CONT TestGenerateFingerprint/invalid_store_path_prefix2669=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2670=== CONT TestGenerateFingerprint/no_references2671=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2672--- PASS: TestGenerateFingerprint (0.00s)2673 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2674 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2675 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2676 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2677 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2678 --- PASS: TestGenerateFingerprint/no_references (0.00s)2679 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2680--- PASS: TestExternalSignerWrongPublicKey (0.00s)2681=== CONT TestParseSigningKey/no_colon2682=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2683=== CONT TestParseSigningKey/wrong_length2684--- PASS: TestParseSigningKey (0.00s)2685 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2686 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2687 --- PASS: TestParseSigningKey/empty_name (0.00s)2688 --- PASS: TestParseSigningKey/no_colon (0.00s)2689 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2690 --- PASS: TestParseSigningKey/wrong_length (0.00s)2691=== RUN TestExternalSignerErrors/wrong_signatures_shape2692=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2693=== RUN TestExternalSignerErrors/unrequested_key2694=== PAUSE TestExternalSignerErrors/unrequested_key2695=== RUN TestExternalSignerErrors/invalid_signature_base642696=== PAUSE TestExternalSignerErrors/invalid_signature_base642697=== RUN TestExternalSignerErrors/null2698=== PAUSE TestExternalSignerErrors/null2699=== RUN TestExternalSignerErrors/missing_signature_name2700=== PAUSE TestExternalSignerErrors/missing_signature_name2701=== RUN TestExternalSignerErrors/exit_on_request2702=== PAUSE TestExternalSignerErrors/exit_on_request2703=== RUN TestExternalSignerErrors/invalid_JSON2704=== PAUSE TestExternalSignerErrors/invalid_JSON2705=== RUN TestExternalSignerErrors/missing_signatures2706=== PAUSE TestExternalSignerErrors/missing_signatures2707=== RUN TestExternalSignerErrors/wrong_signature_name2708=== PAUSE TestExternalSignerErrors/wrong_signature_name2709=== RUN TestExternalSignerErrors/wrong_signature_length2710=== PAUSE TestExternalSignerErrors/wrong_signature_length2711=== RUN TestExternalSignerErrors/program_error2712=== PAUSE TestExternalSignerErrors/program_error2713=== RUN TestExternalSignerErrors/wrong_shape2714=== PAUSE TestExternalSignerErrors/wrong_shape2715=== RUN TestExternalSignerErrors/too_few_signatures2716=== PAUSE TestExternalSignerErrors/too_few_signatures2717=== CONT TestExternalSignerErrors/exit_at_startup2718=== CONT TestExternalSignerErrors/too_few_signatures2719=== CONT TestExternalSignerErrors/exit_on_request2720=== CONT TestExternalSignerErrors/wrong_shape2721=== CONT TestExternalSignerErrors/program_error2722=== CONT TestExternalSignerErrors/unrequested_key2723=== CONT TestExternalSignerErrors/wrong_signature_length2724=== CONT TestExternalSignerErrors/missing_signature_name2725=== CONT TestExternalSignerErrors/wrong_signature_name2726=== CONT TestExternalSignerErrors/null2727=== CONT TestExternalSignerErrors/invalid_JSON2728=== CONT TestExternalSignerErrors/invalid_signature_base642729=== CONT TestExternalSignerErrors/null_signatures2730=== CONT TestExternalSignerErrors/missing_signatures2731=== CONT TestExternalSignerErrors/wrong_signatures_shape2732=== CONT TestExternalSignerErrors/wrong_id2733--- PASS: TestExternalSigner (0.01s)2734--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2735--- PASS: TestExternalSignerErrors (0.00s)2736 --- PASS: TestExternalSignerErrors/too_few_signatures (0.00s)2737 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2738 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2739 --- PASS: TestExternalSignerErrors/program_error (0.00s)2740 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.00s)2741 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2742 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2743 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2744 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2745 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2746 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2747 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2748 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2749 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2750 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2751 --- PASS: TestExternalSignerErrors/null (0.01s)2752--- PASS: TestExternalSignerCancellation (0.02s)2753PASS2754Running OpenBao signer tests...2755=== RUN TestSign2756=== PAUSE TestSign2757=== RUN TestSignErrors2758=== PAUSE TestSignErrors2759=== RUN TestServe2760=== PAUSE TestServe2761=== RUN TestServeRejectsGarbage2762=== PAUSE TestServeRejectsGarbage2763=== CONT TestSign2764=== CONT TestServe2765=== CONT TestServeRejectsGarbage2766=== CONT TestSignErrors2767--- PASS: TestServeRejectsGarbage (0.00s)2768=== RUN TestSignErrors/http_error2769=== PAUSE TestSignErrors/http_error2770=== RUN TestSignErrors/invalid_json2771=== PAUSE TestSignErrors/invalid_json2772=== RUN TestSignErrors/no_prefix2773=== PAUSE TestSignErrors/no_prefix2774=== RUN TestSignErrors/invalid_base642775=== PAUSE TestSignErrors/invalid_base642776=== CONT TestSignErrors/http_error2777=== CONT TestSignErrors/no_prefix2778--- PASS: TestServe (0.00s)2779=== CONT TestSignErrors/invalid_base642780=== CONT TestSignErrors/invalid_json2781--- PASS: TestSign (0.00s)2782--- PASS: TestSignErrors (0.00s)2783 --- PASS: TestSignErrors/invalid_json (0.00s)2784 --- PASS: TestSignErrors/no_prefix (0.00s)2785 --- PASS: TestSignErrors/http_error (0.00s)2786 --- PASS: TestSignErrors/invalid_base64 (0.00s)2787PASS