niks3-go-unit-tests log

succeeded `niks3-go-unit-tests` `checks.aarch64-linux.go-unit-tests` · build #441 · raw

1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestUploadMultipart_PartsInParallel18=== PAUSE TestUploadMultipart_PartsInParallel19=== RUN TestUploadMultipart_FailedPartBufferNotReused20=== PAUSE TestUploadMultipart_FailedPartBufferNotReused21=== RUN TestPartSizeForNAR22=== PAUSE TestPartSizeForNAR23=== RUN TestUploadMultipart_SupersededByPeer24=== PAUSE TestUploadMultipart_SupersededByPeer25=== RUN TestDumpPathCaseHackMatchesNix26--- PASS: TestDumpPathCaseHackMatchesNix (0.13s)27=== RUN TestDumpPathCaseHackCollision28--- PASS: TestDumpPathCaseHackCollision (0.00s)29=== RUN TestSupersededNARStillUploadsListing30=== PAUSE TestSupersededNARStillUploadsListing31=== RUN TestDumpPathMatchesNix32=== PAUSE TestDumpPathMatchesNix33=== RUN TestDumpPathSingleFile34=== PAUSE TestDumpPathSingleFile35=== RUN TestDumpPathWriterError36=== PAUSE TestDumpPathWriterError37=== RUN TestEncodeNixBase3238=== PAUSE TestEncodeNixBase3239=== RUN TestEncodeNixBase32WithRealHash40=== PAUSE TestEncodeNixBase32WithRealHash41=== RUN TestConvertHashToNix3242=== PAUSE TestConvertHashToNix3243=== RUN TestGetStorePathHash44=== PAUSE TestGetStorePathHash45=== RUN TestPathInfoHashCompatibility46=== PAUSE TestPathInfoHashCompatibility47=== RUN TestParsePathInfoJSON48=== PAUSE TestParsePathInfoJSON49=== RUN TestParsePathInfoJSONMultiplePaths50=== PAUSE TestParsePathInfoJSONMultiplePaths51=== RUN TestPathInfoCACompatibility52=== PAUSE TestPathInfoCACompatibility53=== RUN TestRateLimiterFeedback54=== PAUSE TestRateLimiterFeedback55=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess56=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess57=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer58=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer59=== RUN TestResolveStorePath60=== PAUSE TestResolveStorePath61=== RUN TestDoWithRetry_BodyReplayedViaGetBody62=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody63=== RUN TestRetryTimeoutOutlastsMaxRetries64=== PAUSE TestRetryTimeoutOutlastsMaxRetries65=== RUN TestDoWithRetry_FinalResponseBodyReadable66=== PAUSE TestDoWithRetry_FinalResponseBodyReadable67=== RUN TestShellSplit68=== PAUSE TestShellSplit69=== RUN TestShellSplitErrors70=== PAUSE TestShellSplitErrors71=== RUN TestStreamPushReportsEveryPath72=== PAUSE TestStreamPushReportsEveryPath73=== RUN TestStreamPushBatchesUnderLoad74=== PAUSE TestStreamPushBatchesUnderLoad75=== RUN TestStreamPushIsolatesFailures76=== PAUSE TestStreamPushIsolatesFailures77=== RUN TestStreamPushGivesUpOnDeadServer78=== PAUSE TestStreamPushGivesUpOnDeadServer79=== RUN TestStreamPushRequestLine80=== PAUSE TestStreamPushRequestLine81=== RUN TestStreamPushReportsSignatures82=== PAUSE TestStreamPushReportsSignatures83=== RUN TestStreamPushReportsSkippedPaths84=== PAUSE TestStreamPushReportsSkippedPaths85=== RUN TestClientSignaturesByStorePath86=== PAUSE TestClientSignaturesByStorePath87=== RUN TestStreamPushStopsWhenCanceled88=== PAUSE TestStreamPushStopsWhenCanceled89=== RUN TestSetClientTLS90=== PAUSE TestSetClientTLS91=== RUN TestSetClientTLSDoesNotMutateDefaultTransport92=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport93=== RUN TestSetClientTLSErrors94=== PAUSE TestSetClientTLSErrors95=== RUN TestStaticToken96=== PAUSE TestStaticToken97=== RUN TestFileTokenReadsAndCaches98=== PAUSE TestFileTokenReadsAndCaches99=== RUN TestFileTokenMissing100=== PAUSE TestFileTokenMissing101=== RUN TestFileTokenEmpty102=== PAUSE TestFileTokenEmpty103=== RUN TestScriptTokenNoExpiryRerunsEveryCall104=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall105=== RUN TestScriptTokenCachesUntilRefresh106=== PAUSE TestScriptTokenCachesUntilRefresh107=== RUN TestScriptTokenEmptyToken108=== PAUSE TestScriptTokenEmptyToken109=== RUN TestScriptTokenBadJSON110=== PAUSE TestScriptTokenBadJSON111=== RUN TestScriptTokenScriptFails112=== PAUSE TestScriptTokenScriptFails113=== RUN TestScriptTokenEmptyCommand114=== PAUSE TestScriptTokenEmptyCommand115=== CONT TestDoServerRequestAttachesToken116=== CONT TestScriptTokenEmptyCommand117--- PASS: TestScriptTokenEmptyCommand (0.00s)118=== CONT TestRetryTimeoutOutlastsMaxRetries119=== CONT TestScriptTokenEmptyToken120=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer121=== CONT TestScriptTokenCachesUntilRefresh122=== CONT TestScriptTokenNoExpiryRerunsEveryCall123=== CONT TestFileTokenEmpty124=== CONT TestFileTokenMissing125=== CONT TestFileTokenReadsAndCaches126=== CONT TestScriptTokenScriptFails127=== CONT TestStaticToken128=== CONT TestSetClientTLSErrors129=== CONT TestStreamPushIsolatesFailures130=== CONT TestStreamPushBatchesUnderLoad131=== CONT TestSetClientTLSDoesNotMutateDefaultTransport132=== CONT TestStreamPushRequestLine133=== CONT TestStreamPushReportsEveryPath134=== CONT TestSetClientTLS135=== CONT TestShellSplitErrors136=== CONT TestStreamPushStopsWhenCanceled137=== CONT TestShellSplit138=== CONT TestClientSignaturesByStorePath139=== CONT TestStreamPushReportsSkippedPaths140=== CONT TestDoWithRetry_FinalResponseBodyReadable141=== CONT TestStreamPushReportsSignatures142--- PASS: TestFileTokenMissing (0.03s)143=== CONT TestResolveStorePath1442026/10/27 08:43:19 ERROR Upload failed error="bad path" count=3145=== CONT TestDumpPathSingleFile146=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess147=== CONT TestDumpPathMatchesNix148=== CONT TestUploadMultipart_PartsInParallel149--- PASS: TestFileTokenEmpty (0.00s)150--- PASS: TestFileTokenReadsAndCaches (0.00s)151--- PASS: TestStaticToken (0.00s)152--- PASS: TestShellSplit (0.00s)153--- PASS: TestShellSplitErrors (0.00s)154--- PASS: TestStreamPushStopsWhenCanceled (0.00s)155--- PASS: TestStreamPushIsolatesFailures (0.00s)156--- PASS: TestStreamPushReportsEveryPath (0.00s)157=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false158=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false159=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true160=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true161--- PASS: TestScriptTokenScriptFails (0.01s)162=== CONT TestDoWithRetry_BodyReplayedViaGetBody163=== CONT TestRateLimiterFeedback164=== RUN TestRateLimiterFeedback/429_enables_limiter165=== CONT TestSupersededNARStillUploadsListing1662026/10/27 08:43:19 WARN Rate limiter enabled after throttle name=server-test rate=5167=== RUN TestSupersededNARStillUploadsListing/small_NAR168=== PAUSE TestSupersededNARStillUploadsListing/small_NAR1692026/10/27 08:43:19 ERROR Upload failed error=boom count=1170--- PASS: TestClientSignaturesByStorePath (0.00s)171=== CONT TestPathInfoCACompatibility172--- PASS: TestStreamPushReportsSignatures (0.01s)173=== CONT TestParsePathInfoJSONMultiplePaths174=== RUN TestPathInfoCACompatibility/null_ca_field175=== PAUSE TestRateLimiterFeedback/429_enables_limiter176=== RUN TestSupersededNARStillUploadsListing/dump_cut_short177=== RUN TestRateLimiterFeedback/503_enables_limiter178--- PASS: TestResolveStorePath (0.01s)179=== CONT TestPartSizeForNAR180=== RUN TestPartSizeForNAR/zero_stays_at_minimum181=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum182=== RUN TestPartSizeForNAR/small_stays_at_minimum183=== PAUSE TestPartSizeForNAR/small_stays_at_minimum184=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum185=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum186=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts187=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts188=== RUN TestPartSizeForNAR/1_TiB189=== PAUSE TestPartSizeForNAR/1_TiB190=== RUN TestPartSizeForNAR/5_TiB_S3_max_object191=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object192=== RUN TestPartSizeForNAR/capped_at_5_GiB193=== PAUSE TestPartSizeForNAR/capped_at_5_GiB194=== CONT TestParsePathInfoJSON195=== RUN TestParsePathInfoJSON/Nix_format196=== PAUSE TestParsePathInfoJSON/Nix_format197=== RUN TestParsePathInfoJSON/Lix_format198=== PAUSE TestParsePathInfoJSON/Lix_format199=== RUN TestParsePathInfoJSON/empty_input200=== PAUSE TestParsePathInfoJSON/empty_input201=== RUN TestParsePathInfoJSON/whitespace_only202=== PAUSE TestParsePathInfoJSON/whitespace_only203=== RUN TestParsePathInfoJSON/invalid_JSON204=== PAUSE TestParsePathInfoJSON/invalid_JSON205=== CONT TestUploadMultipart_FailedPartBufferNotReused206=== RUN TestSetClientTLSErrors/missing_cert_file207=== CONT TestUploadMultipart_SupersededByPeer208=== RUN TestUploadMultipart_SupersededByPeer/exists209=== PAUSE TestUploadMultipart_SupersededByPeer/exists210=== RUN TestUploadMultipart_SupersededByPeer/missing211=== PAUSE TestUploadMultipart_SupersededByPeer/missing212=== CONT TestPathInfoHashCompatibility213=== CONT TestStreamPushGivesUpOnDeadServer214=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)215=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)216=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon217=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths218=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths219=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths220=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon2212026/10/27 08:43:19 ERROR Upload failed error="connection refused" count=20222=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2232026/10/27 08:43:19 ERROR Server seems unavailable, giving up on batch untried=17224=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI2252026/10/27 08:43:19 ERROR Upload failed error=boom count=1226--- PASS: TestStreamPushReportsSkippedPaths (0.00s)227=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI228=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun229=== CONT TestGetStorePathHash230=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512231--- PASS: TestScriptTokenEmptyToken (0.21s)232=== CONT TestConvertHashToNix32233=== RUN TestConvertHashToNix32/SRI_format_to_Nix32234=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32235=== RUN TestConvertHashToNix32/already_Nix32_format236=== PAUSE TestConvertHashToNix32/already_Nix32_format237=== RUN TestConvertHashToNix32/invalid_format238=== PAUSE TestConvertHashToNix32/invalid_format239=== CONT TestFilterOversizedClosures240=== RUN TestFilterOversizedClosures/no_limit_keeps_everything241=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything242=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped243--- PASS: TestScriptTokenCachesUntilRefresh (0.21s)244=== CONT TestEncodeNixBase32WithRealHash245=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped246--- PASS: TestEncodeNixBase32WithRealHash (0.00s)247=== CONT TestCaseHackSuffix248=== RUN TestFilterOversizedClosures/all_closures_skipped249--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.03s)250=== PAUSE TestFilterOversizedClosures/all_closures_skipped251=== CONT TestEncodeNixBase32252=== RUN TestEncodeNixBase32/test_string_hash253=== CONT TestDumpPathWriterError254=== PAUSE TestEncodeNixBase32/test_string_hash255=== RUN TestEncodeNixBase32/empty_input256=== PAUSE TestEncodeNixBase32/empty_input257=== CONT TestRegisterUploadedObjectReusesConnections258=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short259=== PAUSE TestRateLimiterFeedback/503_enables_limiter2602026/10/27 08:43:19 WARN Rate limiter enabled after throttle name=server-test rate=5261=== PAUSE TestPathInfoCACompatibility/null_ca_field262--- PASS: TestStreamPushGivesUpOnDeadServer (0.04s)263=== RUN TestPathInfoCACompatibility/old_string_format_-_text264=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text265=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive2662026/10/27 08:43:19 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:46871267=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive2682026/10/27 08:43:19 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:46773269=== RUN TestPathInfoCACompatibility/new_structured_format_-_text270=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text271=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method272=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method273--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.25s)274=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter2752026/10/27 08:43:19 WARN Rate limiter enabled after throttle name=server-test rate=52762026/10/27 08:43:19 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:41711277=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter278=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter279=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter280=== PAUSE TestSetClientTLSErrors/missing_cert_file281=== RUN TestSetClientTLSErrors/missing_key_file282=== PAUSE TestSetClientTLSErrors/missing_key_file2832026/10/27 08:43:19 WARN Rate limiter backed off name=server-test rate=5284=== RUN TestSetClientTLSErrors/missing_ca_file2852026/10/27 08:43:19 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:417112862026/10/27 08:43:19 WARN Rate limiter backed off name=server-test rate=5287--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.06s)288=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true289--- PASS: TestDoServerRequestAttachesToken (0.25s)290--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.06s)291=== CONT TestPartSizeForNAR/capped_at_5_GiB292=== CONT TestPartSizeForNAR/5_TiB_S3_max_object293=== CONT TestPartSizeForNAR/1_TiB294=== CONT TestPartSizeForNAR/zero_stays_at_minimum295=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts296=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum297=== CONT TestPartSizeForNAR/small_stays_at_minimum298=== CONT TestParsePathInfoJSON/Nix_format299=== PAUSE TestSetClientTLSErrors/missing_ca_file300=== RUN TestSetClientTLSErrors/invalid_ca_file301=== PAUSE TestSetClientTLSErrors/invalid_ca_file302=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512303=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica304=== CONT TestParsePathInfoJSON/whitespace_only305=== CONT TestParsePathInfoJSON/empty_input306=== CONT TestParsePathInfoJSON/Lix_format307=== CONT TestParsePathInfoJSON/invalid_JSON308=== CONT TestUploadMultipart_SupersededByPeer/exists309=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry310=== RUN TestSetClientTLS/rejects_connection_without_client_cert311=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert312=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA313=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA314=== RUN TestSetClientTLS/preserves_debug_logging_transport315=== PAUSE TestSetClientTLS/preserves_debug_logging_transport316=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths3172026/10/27 08:43:19 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:46871318=== CONT TestUploadMultipart_SupersededByPeer/missing3192026/10/27 08:43:19 INFO Garbage collection started320=== CONT TestScriptTokenBadJSON321=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false322=== RUN TestGetStorePathHash/valid_store_path323=== PAUSE TestGetStorePathHash/valid_store_path324=== RUN TestGetStorePathHash/basename_without_hyphen_should_error325=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error326=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error327=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error328=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error3292026/10/27 08:43:19 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:46871330=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails331=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails332=== CONT TestConvertHashToNix32/invalid_format333=== CONT TestFilterOversizedClosures/no_limit_keeps_everything334=== CONT TestFilterOversizedClosures/all_closures_skipped3352026/10/27 08:43:19 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=50336=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3372026/10/27 08:43:19 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=2000338--- PASS: TestStreamPushBatchesUnderLoad (0.01s)339 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)340 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)341=== CONT TestConvertHashToNix32/already_Nix32_format342=== CONT TestEncodeNixBase32/empty_input343=== CONT TestPathInfoCACompatibility/null_ca_field3442026/10/27 08:43:19 INFO Garbage collection started345=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive346=== CONT TestRateLimiterFeedback/429_enables_limiter347=== CONT TestConvertHashToNix32/SRI_format_to_Nix323482026/10/27 08:43:19 WARN Rate limiter enabled after throttle name=s3-test rate=5349=== CONT TestSetClientTLSErrors/missing_cert_file3502026/10/27 08:43:19 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:42141351=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)352=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI353=== CONT TestEncodeNixBase32/test_string_hash354=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon355=== CONT TestSetClientTLSErrors/invalid_ca_file3562026/10/27 08:43:19 WARN Rate limiter enabled after throttle name=server-test rate=53572026/10/27 08:43:19 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:411233582026/10/27 08:43:19 WARN Rate limiter backed off name=server-test rate=5359=== CONT TestSetClientTLSErrors/missing_ca_file360=== CONT TestSetClientTLSErrors/missing_key_file361=== CONT TestSetClientTLS/preserves_debug_logging_transport362=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA363=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths3642026/10/27 08:43:19 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=0365=== CONT TestRateLimiterFeedback/503_enables_limiter366--- PASS: TestParsePathInfoJSON (0.00s)367 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)368 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)369 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)370 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)371 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)372=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512373=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter374=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error375=== CONT TestPathInfoCACompatibility/old_string_format_-_text376=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method377=== CONT TestSetClientTLS/rejects_connection_without_client_cert378=== CONT TestSupersededNARStillUploadsListing/small_NAR3792026/10/27 08:43:19 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:46871380=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails381=== CONT TestGetStorePathHash/valid_store_path382=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter383--- PASS: TestPartSizeForNAR (0.00s)384 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)385 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)386 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)387 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)388 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)389 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)390 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)391--- PASS: TestConvertHashToNix32 (0.00s)392 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)393 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)394 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)3952026/10/27 08:43:19 INFO Uploading abc-hello (1.0GB)396--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.00s)397--- PASS: TestScriptTokenBadJSON (0.00s)398--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)399=== CONT TestSupersededNARStillUploadsListing/dump_cut_short4002026/10/27 08:43:19 INFO Uploading abc-hello (1.0GB)401=== CONT TestGetStorePathHash/basename_without_hyphen_should_error402=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error403=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error404=== CONT TestPathInfoCACompatibility/new_structured_format_-_text4052026/10/27 08:43:19 WARN Rate limiter enabled after throttle name=server-test rate=54062026/10/27 08:43:19 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:407714072026/10/27 08:43:19 WARN Rate limiter backed off name=server-test rate=5408--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)409 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)410 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)4112026/10/27 08:43:19 WARN Garbage collection finished on another replica. Its statistics are not available here412--- PASS: TestFilterOversizedClosures (0.00s)413 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)414 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)415 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)4162026/10/27 08:43:19 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:468714172026/10/27 08:43:19 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:46871418--- PASS: TestEncodeNixBase32 (0.00s)419 --- PASS: TestEncodeNixBase32/empty_input (0.00s)420 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)421--- PASS: TestPathInfoHashCompatibility (0.04s)422 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)423 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)424 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)425 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)426--- PASS: TestGetStorePathHash (0.00s)427 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)428 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)429 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)430 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)431--- PASS: TestSetClientTLSErrors (0.06s)432 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)433 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)434 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)435 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)436--- PASS: TestParsePathInfoJSONMultiplePaths (0.02s)437 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)438 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)439--- PASS: TestPathInfoCACompatibility (0.06s)440 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)441 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)442 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)443 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)444 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)445--- PASS: TestRateLimiterFeedback (0.06s)446 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)447 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)448 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)449 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)4502026/10/27 08:43:19 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:46871451--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.29s)4522026/10/27 08:43:19 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:468714532026/10/27 08:43:19 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:468714542026/10/27 08:43:19 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:46871455--- PASS: TestDumpPathSingleFile (0.36s)456--- PASS: TestCaseHackSuffix (0.33s)4572026/10/27 08:43:19 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:468714582026/10/27 08:43:19 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:468714592026/10/27 08:43:19 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:468714602026/10/27 08:43:19 http: TLS handshake error from 127.0.0.1:35946: remote error: tls: bad certificate4612026/10/27 08:43:19 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:46871462--- PASS: TestSetClientTLS (0.06s)463 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.29s)464 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.29s)465 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.30s)4662026/10/27 08:43:19 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:468714672026/10/27 08:43:19 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:46871468--- PASS: TestRegisterUploadedObjectReusesConnections (0.34s)4692026/10/27 08:43:19 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:46871470--- PASS: TestStreamPushRequestLine (0.37s)4712026/10/27 08:43:19 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:468714722026/10/27 08:43:19 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:46871473--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.56s)474--- PASS: TestDumpPathWriterError (0.35s)4752026/10/27 08:43:19 WARN Rate limiter enabled after throttle name=s3-test rate=54762026/10/27 08:43:19 INFO Uploading abc-hello (1.0GB)4772026/10/27 08:43:19 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:35175/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:35175/part/2478--- PASS: TestDumpPathMatchesNix (0.44s)4792026/10/27 08:43:19 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:35175/part/3\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:35175/part/34802026/10/27 08:43:19 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:35175/part/4\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:35175/part/44812026/10/27 08:43:19 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:35175/part/5\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:35175/part/54822026/10/27 08:43:19 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:35175/part/6\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:35175/part/64832026/10/27 08:43:19 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"4842026/10/27 08:43:20 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:46685/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:46685/api/uploads/complete4852026/10/27 08:43:20 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4862026/10/27 08:43:20 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:46685/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:46685/api/uploads/complete4872026/10/27 08:43:20 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"488--- PASS: TestSupersededNARStillUploadsListing (0.06s)489 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.29s)490 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.29s)491 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.86s)492--- PASS: TestUploadMultipart_FailedPartBufferNotReused (0.93s)4932026/10/27 08:43:20 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:46685/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:46685/api/uploads/complete4942026/10/27 08:43:20 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"495--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.14s)496--- PASS: TestUploadMultipart_PartsInParallel (0.96s)497--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.01s)498PASS499Running server tests...500The files belonging to this database system will be owned by user "nixbld".501This user must also own the server process.502503The database cluster will be initialized with locale "C".504The default database encoding has accordingly been set to "SQL_ASCII".505The default text search configuration will be set to "english".506507Data page checksums are enabled.508509creating directory /build/postgres3538523543/data ... ok510creating subdirectories ... ok511selecting dynamic shared memory implementation ... posix512selecting default "max_connections" ... 100513selecting default "shared_buffers" ... 128MB514selecting default time zone ... UTC515creating configuration files ... ok516running bootstrap script ... ok517performing post-bootstrap initialization ... ok518syncing data to disk ... ok519520initdb: warning: enabling "trust" authentication for local connections521initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.522523Success. You can now start the database server using:524525 pg_ctl -D /build/postgres3538523543/data -l logfile start526527/build/postgres3538523543:5432 - no response5282026-10-27 08:43:21.584 UTC [128] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit5292026-10-27 08:43:21.584 UTC [128] LOG: listening on Unix socket "/build/postgres3538523543/.s.PGSQL.5432"5302026-10-27 08:43:21.589 UTC [135] LOG: database system was shut down at 2026-10-27 08:43:21 UTC5312026-10-27 08:43:21.593 UTC [128] LOG: database system is ready to accept connections532/build/postgres3538523543:5432 - accepting connections533{"timestamp":"2026-10-27T08:43:23.407617729Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"30f990a0-21c7-4004-b8c1-537086c2f3f3","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":4,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(194)"}534=== RUN TestService_AuthMiddleware535=== PAUSE TestService_AuthMiddleware536=== RUN TestService_AuthMiddleware_MTLSProxyHeader537=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader538=== RUN TestService_AuthMiddleware_MTLSBoundSubjects539=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects540=== RUN TestService_ReadAuthMiddleware541=== PAUSE TestService_ReadAuthMiddleware542=== RUN TestService_AuthMiddleware_OIDC543=== PAUSE TestService_AuthMiddleware_OIDC544=== RUN TestService_RequireScope_OIDC545=== PAUSE TestService_RequireScope_OIDC546=== RUN TestService_ReadScope_PublicByDefault547=== PAUSE TestService_ReadScope_PublicByDefault548=== RUN TestCacheConfigHandler549=== PAUSE TestCacheConfigHandler550=== RUN TestCacheStatsHandler551=== PAUSE TestCacheStatsHandler552=== RUN TestClientCADerivations553=== PAUSE TestClientCADerivations554=== RUN TestClientErrorHandling555=== PAUSE TestClientErrorHandling556=== RUN TestClientIntegration557=== PAUSE TestClientIntegration558=== RUN TestClientMultipleUploads559=== PAUSE TestClientMultipleUploads560=== RUN TestClientWithDependencies561=== PAUSE TestClientWithDependencies562=== RUN TestClientSharedPathCommittedMidPush563=== PAUSE TestClientSharedPathCommittedMidPush564=== RUN TestPinProtectsFromGC565=== PAUSE TestPinProtectsFromGC566=== RUN TestClientPushesUseOnePush567=== PAUSE TestClientPushesUseOnePush568=== RUN TestClientFallsBackToClosures569=== PAUSE TestClientFallsBackToClosures570=== RUN TestDeleteClosuresRacingPins571=== PAUSE TestDeleteClosuresRacingPins572=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock573=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock574=== RUN TestResolveDBConnectionString575=== PAUSE TestResolveDBConnectionString576=== RUN TestConnectWaitsForAPeerMigration577=== PAUSE TestConnectWaitsForAPeerMigration578=== RUN TestLeadElectsOneAndHandsOver579=== PAUSE TestLeadElectsOneAndHandsOver580=== RUN TestLeadIncumbentWinsAfterRestart5812026/10/27 08:43:23 INFO lead: acquired remote=192.0.2.1:12345822026/10/27 08:43:24 INFO lead: released remote=192.0.2.1:12345832026/10/27 08:43:24 INFO lead: acquired remote=192.0.2.1:12345842026/10/27 08:43:25 INFO lead: released remote=192.0.2.1:1234585--- PASS: TestLeadIncumbentWinsAfterRestart (2.19s)586=== RUN TestLeadIncumbentAnnouncesAtOnce587=== PAUSE TestLeadIncumbentAnnouncesAtOnce588=== RUN TestLeadEndsOnShutdown589=== PAUSE TestLeadEndsOnShutdown590=== RUN TestLeadEndsWhenItsConnectionHangs5912026/10/27 08:43:26 INFO lead: acquired remote=192.0.2.1:12345922026-10-27 08:43:27.539 UTC [384] FATAL: terminating connection due to administrator command5932026/10/27 08:43:27 INFO lead: acquired remote=192.0.2.1:12345942026/10/27 08:43:28 WARN lead: lock connection lost error="timeout: context deadline exceeded"5952026/10/27 08:43:28 INFO lead: released remote=192.0.2.1:12345962026/10/27 08:43:28 INFO lead: released remote=192.0.2.1:1234597--- PASS: TestLeadEndsWhenItsConnectionHangs (3.23s)598=== RUN TestGCAdvisoryLockBlocksConcurrentRun599=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun600=== RUN TestGCBugBareHashReferences601=== PAUSE TestGCBugBareHashReferences602=== RUN TestGCMetrics603=== PAUSE TestGCMetrics604=== RUN TestPushDedupSurvivesConcurrentGC605=== PAUSE TestPushDedupSurvivesConcurrentGC606=== RUN TestDeduplicatedObjectsRecordedAsPending607=== PAUSE TestDeduplicatedObjectsRecordedAsPending608=== RUN TestGCSweepSkipsPendingObjects609=== PAUSE TestGCSweepSkipsPendingObjects610=== RUN TestTombstonedObjectOfferedWithoutWaiting611=== PAUSE TestTombstonedObjectOfferedWithoutWaiting612=== RUN TestGCSweepDeliversEachKeyOnce613=== PAUSE TestGCSweepDeliversEachKeyOnce614=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection615=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection616=== RUN TestForceGCDuringPushOffersSweptObject617=== PAUSE TestForceGCDuringPushOffersSweptObject618=== RUN TestFailedS3DeleteKeepsTombstone619=== PAUSE TestFailedS3DeleteKeepsTombstone620=== RUN TestSweepSkipsRowsLockedByPush621=== PAUSE TestSweepSkipsRowsLockedByPush622=== RUN TestRegisterCompletedObjectNeedsPendingRow623=== PAUSE TestRegisterCompletedObjectNeedsPendingRow624=== RUN TestGetExistingObjectsLocksRows625=== PAUSE TestGetExistingObjectsLocksRows626=== RUN TestSweepRechecksPendingAfterLocking627=== PAUSE TestSweepRechecksPendingAfterLocking628=== RUN TestPushWaitsForSweepHoldingRow629=== PAUSE TestPushWaitsForSweepHoldingRow630=== RUN TestCommitRacingPendingCleanupKeepsObjects631=== PAUSE TestCommitRacingPendingCleanupKeepsObjects632=== RUN TestGCEndsOnShutdown633=== PAUSE TestGCEndsOnShutdown634=== RUN TestGCTaskStore_StartNew635=== PAUSE TestGCTaskStore_StartNew636=== RUN TestGCTaskStore_DeduplicateSameParams637=== PAUSE TestGCTaskStore_DeduplicateSameParams638=== RUN TestGCTaskStore_ConflictDifferentParams639=== PAUSE TestGCTaskStore_ConflictDifferentParams640=== RUN TestGCTaskStore_GetEmpty641=== PAUSE TestGCTaskStore_GetEmpty642=== RUN TestGCTaskStore_GetReturnsLatest643=== PAUSE TestGCTaskStore_GetReturnsLatest644=== RUN TestGCTaskStore_CompletedAllowsNewTask645=== PAUSE TestGCTaskStore_CompletedAllowsNewTask646=== RUN TestGCTaskStore_PhaseUpdates647=== PAUSE TestGCTaskStore_PhaseUpdates648=== RUN TestGCTaskStore_Fail649=== PAUSE TestGCTaskStore_Fail650=== RUN TestGracefulShutdownDrainsInflight651=== PAUSE TestGracefulShutdownDrainsInflight652=== RUN TestService_healthCheckHandler653=== PAUSE TestService_healthCheckHandler654=== RUN TestService_readinessHandler655=== PAUSE TestService_readinessHandler656=== RUN TestGenerateLandingPage657=== PAUSE TestGenerateLandingPage658=== RUN TestCacheConfigHandlerMaxNarSize659=== PAUSE TestCacheConfigHandlerMaxNarSize660=== RUN TestCreatePendingClosureRejectsOversizedNAR661=== PAUSE TestCreatePendingClosureRejectsOversizedNAR662=== RUN TestNARDeduplicationMetadataUploadBug663=== PAUSE TestNARDeduplicationMetadataUploadBug664=== RUN TestMetricsInventory665=== PAUSE TestMetricsInventory666=== RUN TestMetricsCommit667=== PAUSE TestMetricsCommit668=== RUN TestService_NativeMTLS669=== PAUSE TestService_NativeMTLS670=== RUN TestServerTLSConfig671=== PAUSE TestServerTLSConfig672=== RUN TestMultipartCleanup673=== PAUSE TestMultipartCleanup674=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded675=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded676=== RUN TestPendingCleanupUsesOneCutoff677=== PAUSE TestPendingCleanupUsesOneCutoff678=== RUN TestObjectStatsTrigger679=== PAUSE TestObjectStatsTrigger680=== RUN TestObjectStatsUpdatedOncePerCommit681=== PAUSE TestObjectStatsUpdatedOncePerCommit682=== RUN TestOrphanedObjectsGC683=== PAUSE TestOrphanedObjectsGC684=== RUN TestOrphanedObjectsGCStressTest685=== PAUSE TestOrphanedObjectsGCStressTest686=== RUN TestCreatePin_ReservedPins687=== PAUSE TestCreatePin_ReservedPins688=== RUN TestPresentReportsOnlyClosureRoots689=== PAUSE TestPresentReportsOnlyClosureRoots690=== RUN TestPresentRefreshesOnlyStaleClosures691=== PAUSE TestPresentRefreshesOnlyStaleClosures692=== RUN TestPresentNotReportedWhileGCDeletesClosure693=== PAUSE TestPresentNotReportedWhileGCDeletesClosure694=== RUN TestParseSingleRange695=== PAUSE TestParseSingleRange696=== RUN TestProxyHeadersOnlyTrustedOnSocket6972026/10/27 08:43:29 INFO Starting HTTP server address=127.0.0.1:424836982026/10/27 08:43:29 INFO Starting HTTP server address=proxy.sock6992026/10/27 08:43:29 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7002026/10/27 08:43:29 INFO Shutdown signal received, draining in-flight requests timeout=10s701--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.12s)702=== RUN TestIsValidCachePath703=== PAUSE TestIsValidCachePath704=== RUN TestReadProxyNarinfo705=== PAUSE TestReadProxyNarinfo706=== RUN TestReadProxyNarinfoAlreadyDecompressed707=== PAUSE TestReadProxyNarinfoAlreadyDecompressed708=== RUN TestReadProxyContentNegotiation709=== PAUSE TestReadProxyContentNegotiation710=== RUN TestReadProxyNarStreaming711=== PAUSE TestReadProxyNarStreaming712=== RUN TestReadProxy404713=== PAUSE TestReadProxy404714=== RUN TestReadProxyInvalidPath715=== PAUSE TestReadProxyInvalidPath716=== RUN TestReadProxyHead717=== PAUSE TestReadProxyHead718=== RUN TestReadProxyOutlastsServerWriteTimeout719=== PAUSE TestReadProxyOutlastsServerWriteTimeout720=== RUN TestReadProxyConditionalGet721=== PAUSE TestReadProxyConditionalGet722=== RUN TestReadProxyRootRedirectsToIndexHTML723=== PAUSE TestReadProxyRootRedirectsToIndexHTML724=== RUN TestReadProxyDisabled725=== PAUSE TestReadProxyDisabled726=== RUN TestReadRedirectNar727=== PAUSE TestReadRedirectNar728=== RUN TestReadRedirectKeepsNarinfoProxied729=== PAUSE TestReadRedirectKeepsNarinfoProxied730=== RUN TestReadProxyRangeRequest731=== PAUSE TestReadProxyRangeRequest732=== RUN TestReadRedirectUsesPublicS3URL733=== PAUSE TestReadRedirectUsesPublicS3URL734=== RUN TestPush_OverlappingRootsStoreOneRowPerKey735=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey736=== RUN TestPush_CompleteCommitsEveryRoot737=== PAUSE TestPush_CompleteCommitsEveryRoot738=== RUN TestPush_RepeatedRootCommitsOnce739=== PAUSE TestPush_RepeatedRootCommitsOnce740=== RUN TestPush_CompleteWaitsForCleanupOfThePush741=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush742=== RUN TestPush_RootsAreLockedInByteOrder743=== PAUSE TestPush_RootsAreLockedInByteOrder744=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit745=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit746=== RUN TestPush_RejectsBadRequests747=== PAUSE TestPush_RejectsBadRequests748=== RUN TestPush_SignsNarinfosOfItsPendingObjects749=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects750=== RUN TestRedundantMultipartUpload751=== PAUSE TestRedundantMultipartUpload752=== RUN TestCompleteMultipartUpload_ErrorButObjectExists753=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists754=== RUN TestCompletedNarNotReofferedAcrossClosures755=== PAUSE TestCompletedNarNotReofferedAcrossClosures756=== RUN TestPresignedUploadRegisteredBeforeCommit757=== PAUSE TestPresignedUploadRegisteredBeforeCommit758=== RUN TestService_Rustfstest759=== PAUSE TestService_Rustfstest760=== RUN TestParseSize761=== PAUSE TestParseSize762=== RUN TestSkippedUploadsHandler763=== PAUSE TestSkippedUploadsHandler764=== RUN TestSystemdListenerNotActivated765--- PASS: TestSystemdListenerNotActivated (0.00s)766=== RUN TestWatchdogBeatsWhenHealthy767--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)768=== RUN TestWatchdogSkipsWhenUnhealthy7692026/10/27 08:43:29 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7702026/10/27 08:43:29 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7712026/10/27 08:43:29 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7722026/10/27 08:43:29 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7732026/10/27 08:43:29 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7742026/10/27 08:43:29 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7752026/10/27 08:43:29 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7762026/10/27 08:43:29 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7772026/10/27 08:43:29 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7782026/10/27 08:43:29 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"779--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)780=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle781=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle782=== RUN TestProxyWriteTimeout783=== PAUSE TestProxyWriteTimeout784=== RUN TestPendingClosureWriteTimeout785=== PAUSE TestPendingClosureWriteTimeout786=== RUN TestIsValidUploadKey787=== PAUSE TestIsValidUploadKey788=== RUN TestUploadHandlersRejectInvalidKeys789=== PAUSE TestUploadHandlersRejectInvalidKeys790=== RUN TestUploadHandlersRejectOversizedBody791=== PAUSE TestUploadHandlersRejectOversizedBody792=== RUN TestService_cleanupPendingClosuresHandler793=== PAUSE TestService_cleanupPendingClosuresHandler794=== RUN TestService_createPendingClosureHandler795=== PAUSE TestService_createPendingClosureHandler796=== RUN TestService_verifyS3Integrity797=== PAUSE TestService_verifyS3Integrity798=== RUN TestCompleteMultipartUnregistered799=== PAUSE TestCompleteMultipartUnregistered800=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT801=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT802=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle803=== CONT TestParseSize804=== CONT TestService_cleanupPendingClosuresHandler805=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock806=== CONT TestService_healthCheckHandler807=== CONT TestSkippedUploadsHandler808=== CONT TestService_Rustfstest809--- PASS: TestParseSize (0.00s)810=== CONT TestGracefulShutdownDrainsInflight811=== CONT TestPresignedUploadRegisteredBeforeCommit8122026/10/27 08:43:29 INFO Client skipped oversized paths paths=3 nar_bytes=50000000008132026/10/27 08:43:29 INFO Starting HTTP server address=127.0.0.1:39267814=== CONT TestGCAdvisoryLockBlocksConcurrentRun815=== CONT TestCompletedNarNotReofferedAcrossClosures816=== CONT TestLeadEndsOnShutdown817=== CONT TestCompleteMultipartUpload_ErrorButObjectExists8182026/10/27 08:43:29 INFO Shutdown signal received, draining in-flight requests timeout=10s819=== CONT TestLeadIncumbentAnnouncesAtOnce820=== CONT TestRedundantMultipartUpload821=== CONT TestLeadElectsOneAndHandsOver822--- PASS: TestSkippedUploadsHandler (0.02s)823=== CONT TestGCTaskStore_PhaseUpdates824--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)825=== CONT TestPush_CompleteWaitsForCleanupOfThePush826=== CONT TestPush_SignsNarinfosOfItsPendingObjects827=== CONT TestConnectWaitsForAPeerMigration828=== CONT TestPush_RejectsBadRequests829=== CONT TestGCBugBareHashReferences830=== CONT TestResolveDBConnectionString831=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit832=== CONT TestGCTaskStore_Fail833=== CONT TestPush_RepeatedRootCommitsOnce834=== CONT TestPush_RootsAreLockedInByteOrder835=== CONT TestService_AuthMiddleware836--- PASS: TestGracefulShutdownDrainsInflight (0.10s)837--- PASS: TestGCTaskStore_Fail (0.00s)838=== CONT TestGCTaskStore_CompletedAllowsNewTask839--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)840=== CONT TestGCTaskStore_GetReturnsLatest841--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)842=== CONT TestPush_CompleteCommitsEveryRoot843=== RUN TestResolveDBConnectionString/flag_wins844=== PAUSE TestResolveDBConnectionString/flag_wins845=== RUN TestResolveDBConnectionString/file_when_flag_empty846=== PAUSE TestResolveDBConnectionString/file_when_flag_empty847=== RUN TestResolveDBConnectionString/missing_file_is_an_error848=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error849=== RUN TestResolveDBConnectionString/PGHOST_allows_empty850=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty851=== RUN TestResolveDBConnectionString/nothing_configured852=== PAUSE TestResolveDBConnectionString/nothing_configured853=== CONT TestPush_OverlappingRootsStoreOneRowPerKey854--- PASS: TestService_healthCheckHandler (0.30s)855=== CONT TestGCTaskStore_GetEmpty856--- PASS: TestGCTaskStore_GetEmpty (0.00s)857=== CONT TestGCTaskStore_ConflictDifferentParams858--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)859=== CONT TestPresentReportsOnlyClosureRoots8602026/10/27 08:43:29 INFO Received uploads request method=POST path=/api/pending_closures8612026/10/27 08:43:29 INFO Received cleanup request method=DELETE path=/api/pending_closures8622026/10/27 08:43:29 INFO Aborted multipart uploads count=0 kept=08632026/10/27 08:43:29 INFO Received uploads request method=POST path=/api/pending_closures8642026/10/27 08:43:29 INFO Received cleanup request method=DELETE path=/api/pending_closures8652026/10/27 08:43:29 INFO Aborted multipart uploads count=1 kept=08662026/10/27 08:43:29 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8672026-10-27 08:43:29.683 UTC [455] ERROR: Closure does not exist: id=18682026-10-27 08:43:29.683 UTC [455] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE8692026-10-27 08:43:29.683 UTC [455] STATEMENT: -- name: CommitPendingClosure :one870 SELECT commit_pending_closure($1::bigint)::bigint871 872--- PASS: TestService_cleanupPendingClosuresHandler (0.40s)873=== CONT TestGCTaskStore_DeduplicateSameParams874--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)875=== CONT TestCreatePin_ReservedPins8762026/10/27 08:43:29 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"877--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.41s)878=== CONT TestGCTaskStore_StartNew879--- PASS: TestGCTaskStore_StartNew (0.00s)880=== CONT TestOrphanedObjectsGCStressTest881--- PASS: TestService_Rustfstest (0.42s)882=== CONT TestGCEndsOnShutdown883=== RUN TestGCEndsOnShutdown/before_the_run884=== PAUSE TestGCEndsOnShutdown/before_the_run885=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete886=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete887=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark888=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark889=== CONT TestOrphanedObjectsGC8902026/10/27 08:43:29 INFO Received uploads request method=POST path=/api/pending_closures8912026/10/27 08:43:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8922026/10/27 08:43:29 INFO Received uploads request method=POST path=/api/pending_closures8932026/10/27 08:43:29 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst8942026/10/27 08:43:29 INFO Received uploads request method=POST path=/api/pending_closures895--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.47s)896=== CONT TestCommitRacingPendingCleanupKeepsObjects8972026/10/27 08:43:29 INFO Received push request method=POST path=/api/pushes8982026/10/27 08:43:29 INFO Received uploads request method=POST path=/api/pending_closures8992026/10/27 08:43:29 INFO Received uploads request method=POST path=/api/pending_closures9002026/10/27 08:43:29 INFO Received uploads request method=POST path=/api/pending_closures9012026/10/27 08:43:29 INFO lead: acquired remote=192.0.2.1:12349022026/10/27 08:43:29 INFO lead: released remote=192.0.2.1:1234903--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.56s)904=== CONT TestObjectStatsUpdatedOncePerCommit9052026/10/27 08:43:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9062026/10/27 08:43:29 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZDNiYjc5ZDktZDY4Yi00MTQwLTg1ZDItOTA1YTEyZjI5MDYxLjgyMTdmZTFjLWNjMzAtNGEwYS04OTZhLWFiNjZhMDhiYWYzNngxNzkzMDkwNjA5ODQzMzAyMzkx9072026/10/27 08:43:29 INFO lead: acquired remote=192.0.2.1:12349082026/10/27 08:43:29 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZDNiYjc5ZDktZDY4Yi00MTQwLTg1ZDItOTA1YTEyZjI5MDYxLjgyMTdmZTFjLWNjMzAtNGEwYS04OTZhLWFiNjZhMDhiYWYzNngxNzkzMDkwNjA5ODQzMzAyMzkx parts=1909--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.60s)910=== CONT TestPushWaitsForSweepHoldingRow9112026/10/27 08:43:29 INFO lead: acquired remote=192.0.2.1:12349122026/10/27 08:43:29 INFO Received push request method=POST path=/api/pushes9132026/10/27 08:43:29 INFO Received complete push request method=POST path=/api/pushes/1/complete9142026/10/27 08:43:29 INFO Received push request method=POST path=/api/pushes9152026/10/27 08:43:29 INFO Received complete push request method=POST path=/api/pushes/1/complete9162026/10/27 08:43:29 INFO Completed push id=1 objects=6 duration=34.045499ms9172026/10/27 08:43:29 INFO Completed push id=1 objects=4 duration=11.118177ms9182026/10/27 08:43:29 INFO Received push request method=POST path=/api/pushes9192026/10/27 08:43:30 INFO Received push request method=POST path=/api/pushes920--- PASS: TestPush_CompleteCommitsEveryRoot (0.61s)921=== CONT TestPresentRefreshesOnlyStaleClosures922--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.59s)923=== CONT TestObjectStatsTrigger9242026/10/27 08:43:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34681/oidc9252026/10/27 08:43:30 INFO Received push request method=POST path=/api/pushes9262026/10/27 08:43:30 INFO Aborted multipart uploads count=0 kept=09272026/10/27 08:43:30 WARN Force mode enabled - objects will be deleted immediately without grace period9282026/10/27 08:43:30 INFO Received push request method=POST path=/api/pushes9292026-10-27 08:43:30.089 UTC [495] ERROR: Push does not exist: id=19302026-10-27 08:43:30.089 UTC [495] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE9312026-10-27 08:43:30.089 UTC [495] STATEMENT: SELECT commit_push($1)932--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.78s)933=== CONT TestSweepRechecksPendingAfterLocking9342026/10/27 08:43:30 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=09352026/10/27 08:43:30 INFO Vacuumed table table=pending_closures9362026-10-27 08:43:30.096 UTC [521] ERROR: could not obtain lock on row in relation "closures"9372026-10-27 08:43:30.096 UTC [521] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9382026-10-27 08:43:30.096 UTC [521] ERROR: could not obtain lock on row in relation "closures"9392026-10-27 08:43:30.096 UTC [521] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9402026-10-27 08:43:30.097 UTC [521] ERROR: could not obtain lock on row in relation "closures"9412026-10-27 08:43:30.097 UTC [521] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9422026-10-27 08:43:30.097 UTC [521] ERROR: could not obtain lock on row in relation "closures"9432026-10-27 08:43:30.097 UTC [521] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9442026/10/27 08:43:30 INFO Vacuumed table table=pending_objects9452026-10-27 08:43:30.097 UTC [521] ERROR: could not obtain lock on row in relation "closures"9462026-10-27 08:43:30.097 UTC [521] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9472026/10/27 08:43:30 INFO Vacuumed table table=multipart_uploads9482026/10/27 08:43:30 INFO Received complete push request method=POST path=/api/pushes/1/complete9492026/10/27 08:43:30 INFO Vacuumed table table=closures950--- PASS: TestPush_RootsAreLockedInByteOrder (0.72s)951=== CONT TestGetExistingObjectsLocksRows9522026/10/27 08:43:30 INFO Vacuumed table table=objects953--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.83s)954=== CONT TestPendingCleanupUsesOneCutoff9552026/10/27 08:43:30 INFO Received complete push request method=POST path=/api/pushes/2/complete9562026/10/27 08:43:30 INFO Received push request method=POST path=/api/pushes9572026/10/27 08:43:30 INFO Completed push id=1 objects=4 duration=13.767321ms958--- PASS: TestPush_RepeatedRootCommitsOnce (0.74s)959=== CONT TestReadRedirectUsesPublicS3URL9602026/10/27 08:43:30 INFO Completed push id=2 objects=4 duration=5.75743ms961--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.74s)962=== CONT TestRegisterCompletedObjectNeedsPendingRow9632026/10/27 08:43:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9642026/10/27 08:43:30 INFO Signed narinfos id=1 count=19652026/10/27 08:43:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9662026/10/27 08:43:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9672026/10/27 08:43:30 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"9682026/10/27 08:43:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9692026/10/27 08:43:30 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"9702026/10/27 08:43:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9712026/10/27 08:43:30 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=19722026/10/27 08:43:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9732026/10/27 08:43:30 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo974--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.76s)975=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded976=== RUN TestPush_RejectsBadRequests/no_roots977=== PAUSE TestPush_RejectsBadRequests/no_roots978=== RUN TestPush_RejectsBadRequests/no_objects979=== PAUSE TestPush_RejectsBadRequests/no_objects980=== RUN TestPush_RejectsBadRequests/bad_root981=== PAUSE TestPush_RejectsBadRequests/bad_root982=== RUN TestPush_RejectsBadRequests/root_not_in_objects983=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects984=== CONT TestReadProxyRangeRequest9852026/10/27 08:43:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9862026/10/27 08:43:30 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"987--- PASS: TestService_AuthMiddleware (0.79s)988=== CONT TestSweepSkipsRowsLockedByPush9892026/10/27 08:43:30 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZDNiYjc5ZDktZDY4Yi00MTQwLTg1ZDItOTA1YTEyZjI5MDYxLmI2ZTg4NDU0LTc5ZTEtNDhhYi04ODVjLTMwNzFkYzY1ZGFjY3gxNzkzMDkwNjA5NzU5MTc1NTcy parts=129902026/10/27 08:43:30 INFO Received uploads request method=POST path=/api/pending_closures991--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.92s)992=== CONT TestMultipartCleanup993--- PASS: TestPresentReportsOnlyClosureRoots (0.63s)994=== CONT TestReadRedirectKeepsNarinfoProxied9952026/10/27 08:43:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9962026/10/27 08:43:30 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZDNiYjc5ZDktZDY4Yi00MTQwLTg1ZDItOTA1YTEyZjI5MDYxLjRmOWYwNWE0LWI5MTUtNDBmMi1iMzUwLWJlYTdjYjUyMDJkOXgxNzkzMDkwNjA5ODAxNTI0MTY0 parts=129972026/10/27 08:43:30 INFO Received uploads request method=POST path=/api/pending_closures9982026/10/27 08:43:30 INFO Received uploads request method=POST path=/api/pending_closures9992026/10/27 08:43:30 INFO Received uploads request method=POST path=/api/pending_closures1000--- PASS: TestGCBugBareHashReferences (0.96s)1001=== CONT TestFailedS3DeleteKeepsTombstone1002--- PASS: TestObjectStatsUpdatedOncePerCommit (0.49s)1003=== CONT TestReadRedirectNar10042026/10/27 08:43:30 INFO Aborted multipart uploads count=0 kept=01005--- PASS: TestPresentRefreshesOnlyStaleClosures (0.41s)1006=== CONT TestServerTLSConfig1007=== RUN TestServerTLSConfig/no_client_CA1008=== PAUSE TestServerTLSConfig/no_client_CA1009=== RUN TestServerTLSConfig/missing_CA_file1010=== PAUSE TestServerTLSConfig/missing_CA_file1011=== RUN TestServerTLSConfig/not_a_PEM_file1012=== PAUSE TestServerTLSConfig/not_a_PEM_file1013=== CONT TestReadProxyDisabled10142026/10/27 08:43:30 WARN Force mode enabled - objects will be deleted immediately without grace period10152026/10/27 08:43:30 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=01016--- PASS: TestObjectStatsTrigger (0.41s)1017=== CONT TestForceGCDuringPushOffersSweptObject1018=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1019=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1020=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1021=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1022=== CONT TestService_NativeMTLS10232026/10/27 08:43:30 INFO Vacuumed table table=pending_closures10242026/10/27 08:43:30 INFO Vacuumed table table=pending_objects10252026/10/27 08:43:30 INFO Vacuumed table table=multipart_uploads10262026/10/27 08:43:30 INFO Vacuumed table table=closures10272026/10/27 08:43:30 INFO Vacuumed table table=objects10282026/10/27 08:43:30 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10292026/10/27 08:43:30 WARN Refused reserved pin name=worker-x86_64-linux10302026/10/27 08:43:30 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10312026/10/27 08:43:30 INFO Received create pin request method=POST path=/api/pins/my-app10322026/10/27 08:43:30 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1033--- PASS: TestCreatePin_ReservedPins (0.77s)1034=== CONT TestReadProxyContentNegotiation10352026/10/27 08:43:30 INFO Received uploads request method=POST path=/api/pending_closures10362026/10/27 08:43:30 INFO Received uploads request method=POST path=/api/pending_closures10372026/10/27 08:43:30 INFO Received cleanup request method=DELETE path=/api/pending_closures1038--- PASS: TestReadRedirectUsesPublicS3URL (0.40s)1039=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1040--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.78s)1041=== CONT TestMetricsCommit10422026/10/27 08:43:30 INFO Aborted multipart uploads count=0 kept=010432026/10/27 08:43:30 WARN Force mode enabled - objects will be deleted immediately without grace period1044--- PASS: TestReadProxyRangeRequest (0.42s)1045=== CONT TestGCSweepDeliversEachKeyOnce10462026/10/27 08:43:30 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=010472026/10/27 08:43:30 INFO Vacuumed table table=pending_closures10482026/10/27 08:43:30 INFO Vacuumed table table=pending_objects10492026/10/27 08:43:30 INFO Vacuumed table table=multipart_uploads10502026/10/27 08:43:30 INFO Vacuumed table table=closures10512026/10/27 08:43:30 INFO Vacuumed table table=objects1052--- PASS: TestSweepRechecksPendingAfterLocking (0.51s)1053=== CONT TestReadProxyNarinfoAlreadyDecompressed10542026/10/27 08:43:30 INFO Aborted multipart uploads count=0 kept=010552026/10/27 08:43:30 INFO Received uploads request method=POST path=/api/pending_closures10562026/10/27 08:43:30 WARN Force mode enabled - objects will be deleted immediately without grace period10572026/10/27 08:43:30 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010582026/10/27 08:43:30 INFO Vacuumed table table=pending_closures10592026/10/27 08:43:30 INFO Vacuumed table table=pending_objects10602026/10/27 08:43:30 INFO Vacuumed table table=multipart_uploads10612026/10/27 08:43:30 INFO Vacuumed table table=closures10622026/10/27 08:43:30 INFO Vacuumed table table=objects1063--- PASS: TestReadRedirectKeepsNarinfoProxied (0.45s)1064=== CONT TestMetricsInventory1065--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.55s)1066=== CONT TestTombstonedObjectOfferedWithoutWaiting10672026/10/27 08:43:30 INFO Aborted multipart uploads count=0 kept=010682026/10/27 08:43:30 INFO Received uploads request method=POST path=/api/pending_closures10692026/10/27 08:43:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10702026/10/27 08:43:30 WARN Force mode enabled - objects will be deleted immediately without grace period10712026/10/27 08:43:30 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZDNiYjc5ZDktZDY4Yi00MTQwLTg1ZDItOTA1YTEyZjI5MDYxLjVhMWMzOTc2LWU2NmUtNGUzZS1iYmQ5LTkxZjYwZjE4ZmZlZngxNzkzMDkwNjEwMjcyMjcyNzU5 error="Get \"http://127.0.0.1:1/bucket13/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"10722026/10/27 08:43:30 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZDNiYjc5ZDktZDY4Yi00MTQwLTg1ZDItOTA1YTEyZjI5MDYxLjZjMjA1OTQxLTk4Y2YtNGY0Zi1hOGVhLWVlNjZkMThlOWM1MXgxNzkzMDkwNjEwMjYxMzkzNDA0 parts=121073--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.57s)1074=== CONT TestReadProxyNarinfo10752026/10/27 08:43:30 INFO Received cleanup request method=DELETE path=/api/pending_closures10762026/10/27 08:43:30 INFO Aborted multipart uploads count=1 kept=01077--- PASS: TestRedundantMultipartUpload (1.42s)1078=== CONT TestNARDeduplicationMetadataUploadBug10792026/10/27 08:43:30 INFO Received cleanup request method=DELETE path=/api/pending_closures10802026/10/27 08:43:30 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket41/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""10812026/10/27 08:43:30 INFO Aborted multipart uploads count=0 kept=110822026/10/27 08:43:30 INFO Received cleanup request method=DELETE path=/api/pending_closures10832026/10/27 08:43:30 INFO Aborted multipart uploads count=1 kept=01084--- PASS: TestGetExistingObjectsLocksRows (0.64s)1085=== CONT TestGCSweepSkipsPendingObjects10862026/10/27 08:43:30 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=010872026/10/27 08:43:30 INFO Vacuumed table table=pending_closures1088--- PASS: TestMultipartCleanup (0.54s)1089=== CONT TestIsValidCachePath1090=== RUN TestIsValidCachePath/narinfo1091=== PAUSE TestIsValidCachePath/narinfo1092=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1093=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1094=== RUN TestIsValidCachePath/nar_zst1095=== PAUSE TestIsValidCachePath/nar_zst1096=== RUN TestIsValidCachePath/nar_xz1097=== PAUSE TestIsValidCachePath/nar_xz1098=== RUN TestIsValidCachePath/nar_bz210992026/10/27 08:43:30 INFO Vacuumed table table=pending_objects1100=== PAUSE TestIsValidCachePath/nar_bz21101=== RUN TestIsValidCachePath/nar_uncompressed11022026/10/27 08:43:30 INFO Vacuumed table table=multipart_uploads1103=== PAUSE TestIsValidCachePath/nar_uncompressed1104=== RUN TestIsValidCachePath/ls1105=== PAUSE TestIsValidCachePath/ls1106=== RUN TestIsValidCachePath/log1107=== PAUSE TestIsValidCachePath/log1108=== RUN TestIsValidCachePath/realisation1109=== PAUSE TestIsValidCachePath/realisation1110=== RUN TestIsValidCachePath/nix-cache-info1111=== PAUSE TestIsValidCachePath/nix-cache-info1112=== RUN TestIsValidCachePath/index.html1113=== PAUSE TestIsValidCachePath/index.html1114=== RUN TestIsValidCachePath/traversal_parent11152026/10/27 08:43:30 INFO Vacuumed table table=closures1116=== PAUSE TestIsValidCachePath/traversal_parent1117=== RUN TestIsValidCachePath/traversal_in_middle1118=== PAUSE TestIsValidCachePath/traversal_in_middle1119=== RUN TestIsValidCachePath/invalid_char_e1120=== PAUSE TestIsValidCachePath/invalid_char_e1121=== RUN TestIsValidCachePath/invalid_char_u1122=== PAUSE TestIsValidCachePath/invalid_char_u1123=== RUN TestIsValidCachePath/random_path1124=== PAUSE TestIsValidCachePath/random_path1125=== RUN TestIsValidCachePath/empty1126=== PAUSE TestIsValidCachePath/empty1127=== RUN TestIsValidCachePath/leading_slash1128=== PAUSE TestIsValidCachePath/leading_slash1129=== RUN TestIsValidCachePath/wrong_extension1130=== PAUSE TestIsValidCachePath/wrong_extension1131=== RUN TestIsValidCachePath/short_hash1132=== PAUSE TestIsValidCachePath/short_hash1133=== CONT TestCreatePendingClosureRejectsOversizedNAR11342026/10/27 08:43:30 INFO Received uploads request method=POST path=/api/pending_closures1135--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1136=== CONT TestDeduplicatedObjectsRecordedAsPending11372026/10/27 08:43:30 INFO Vacuumed table table=objects1138--- PASS: TestSweepSkipsRowsLockedByPush (0.58s)1139=== CONT TestCacheConfigHandlerMaxNarSize1140--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1141=== CONT TestReadProxyNarStreaming1142--- PASS: TestReadRedirectNar (0.42s)1143=== CONT TestGenerateLandingPage1144--- PASS: TestGenerateLandingPage (0.00s)1145=== CONT TestReadProxyRootRedirectsToIndexHTML1146--- PASS: TestPushWaitsForSweepHoldingRow (0.89s)1147=== CONT TestService_readinessHandler11482026/10/27 08:43:30 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11492026/10/27 08:43:30 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1150--- PASS: TestService_NativeMTLS (0.36s)1151=== CONT TestReadProxyConditionalGet1152=== NAME TestOrphanedObjectsGC1153 orphaned_objects_gc_test.go:287: GC Test Summary:1154 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1155 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1156 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1157 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1158 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1159--- PASS: TestOrphanedObjectsGC (1.10s)1160=== CONT TestParseSingleRange1161=== RUN TestParseSingleRange/none1162=== PAUSE TestParseSingleRange/none1163=== RUN TestParseSingleRange/unknown_unit1164=== PAUSE TestParseSingleRange/unknown_unit1165=== RUN TestParseSingleRange/multi-range_ignored1166=== PAUSE TestParseSingleRange/multi-range_ignored1167=== RUN TestParseSingleRange/malformed_no_dash1168=== PAUSE TestParseSingleRange/malformed_no_dash1169=== RUN TestParseSingleRange/malformed_both_empty1170=== PAUSE TestParseSingleRange/malformed_both_empty1171=== RUN TestParseSingleRange/malformed_end_before_start1172=== PAUSE TestParseSingleRange/malformed_end_before_start1173=== RUN TestParseSingleRange/closed1174=== PAUSE TestParseSingleRange/closed1175=== RUN TestParseSingleRange/open-ended1176=== PAUSE TestParseSingleRange/open-ended1177=== RUN TestParseSingleRange/end_clamped_to_size1178=== PAUSE TestParseSingleRange/end_clamped_to_size1179=== RUN TestParseSingleRange/suffix1180=== PAUSE TestParseSingleRange/suffix1181=== RUN TestParseSingleRange/suffix_exceeds_size1182=== PAUSE TestParseSingleRange/suffix_exceeds_size1183=== RUN TestParseSingleRange/single_byte1184=== PAUSE TestParseSingleRange/single_byte1185=== RUN TestParseSingleRange/start_past_EOF1186=== PAUSE TestParseSingleRange/start_past_EOF1187=== RUN TestParseSingleRange/start_far_past_EOF1188=== PAUSE TestParseSingleRange/start_far_past_EOF1189=== CONT TestReadProxyOutlastsServerWriteTimeout11902026/10/27 08:43:30 INFO Received uploads request method=POST path=/api/pending_closures1191--- PASS: TestReadProxyDisabled (0.47s)1192=== CONT TestCompleteMultipartUnregistered11932026/10/27 08:43:30 INFO Received uploads request method=POST path=/api/pending_closures11942026/10/27 08:43:30 INFO Aborted multipart uploads count=0 kept=01195--- PASS: TestReadProxyContentNegotiation (0.47s)1196=== CONT TestReadProxyHead11972026/10/27 08:43:30 INFO Received push request method=POST path=/api/pushes11982026/10/27 08:43:30 INFO Received complete push request method=POST path=/api/pushes/1/complete1199--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.36s)1200=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT12012026/10/27 08:43:30 INFO lead: released remote=192.0.2.1:12341202--- PASS: TestLeadEndsOnShutdown (1.68s)1203=== CONT TestPresentNotReportedWhileGCDeletesClosure1204=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1205=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1206=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1207=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1208=== CONT TestReadProxyInvalidPath12092026/10/27 08:43:30 WARN Force mode enabled - objects will be deleted immediately without grace period12102026/10/27 08:43:30 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12112026/10/27 08:43:30 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1212--- PASS: TestFailedS3DeleteKeepsTombstone (0.65s)1213=== CONT TestClientErrorHandling1214=== RUN TestClientErrorHandling/InvalidStorePath1215=== PAUSE TestClientErrorHandling/InvalidStorePath1216=== RUN TestClientErrorHandling/InvalidAuthToken1217=== PAUSE TestClientErrorHandling/InvalidAuthToken1218=== RUN TestClientErrorHandling/ServerNotAvailable1219=== PAUSE TestClientErrorHandling/ServerNotAvailable1220=== CONT TestReadProxy4041221--- PASS: TestReadProxyConditionalGet (0.29s)1222=== CONT TestPinProtectsFromGC12232026/10/27 08:43:31 INFO lead: released remote=192.0.2.1:12341224--- PASS: TestReadProxyNarStreaming (0.35s)1225=== CONT TestClientSharedPathCommittedMidPush1226--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.61s)1227=== CONT TestPushDedupSurvivesConcurrentGC12282026/10/27 08:43:31 INFO Received uploads request method=POST path=/api/pending_closures12292026/10/27 08:43:31 INFO lead: acquired remote=192.0.2.1:123412302026/10/27 08:43:31 INFO Completed push id=1 objects=4 duration=185.696731ms12312026/10/27 08:43:31 INFO Aborted multipart uploads count=0 kept=012322026/10/27 08:43:31 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12332026/10/27 08:43:31 INFO Completed upload id=2 objects=2 duration=4.233517ms1234--- PASS: TestMetricsCommit (0.63s)1235=== CONT TestClientWithDependencies12362026/10/27 08:43:31 WARN readiness check failed error="closed pool"1237--- PASS: TestService_readinessHandler (0.41s)1238=== CONT TestClientFallsBackToClosures1239--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.45s)1240=== CONT TestGCMetrics12412026/10/27 08:43:31 INFO Received uploads request method=POST path=/api/pending_closures1242--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.53s)1243=== CONT TestClientMultipleUploads12442026/10/27 08:43:31 INFO Received uploads request method=POST path=/api/pending_closures1245--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.61s)1246=== CONT TestDeleteClosuresRacingPins12472026/10/27 08:43:31 WARN Force mode enabled - objects will be deleted immediately without grace period12482026/10/27 08:43:31 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=012492026/10/27 08:43:31 INFO Vacuumed table table=pending_closures12502026/10/27 08:43:31 INFO Vacuumed table table=pending_objects12512026/10/27 08:43:31 INFO Vacuumed table table=multipart_uploads12522026/10/27 08:43:31 INFO Vacuumed table table=closures12532026/10/27 08:43:31 INFO Vacuumed table table=objects1254--- PASS: TestMetricsInventory (0.68s)1255=== CONT TestClientIntegration1256--- PASS: TestGCSweepSkipsPendingObjects (0.61s)1257=== CONT TestService_RequireScope_OIDC12582026/10/27 08:43:31 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1259--- PASS: TestReadProxyNarinfo (0.68s)1260=== CONT TestIsValidUploadKey1261=== RUN TestIsValidUploadKey/narinfo1262=== PAUSE TestIsValidUploadKey/narinfo1263=== RUN TestIsValidUploadKey/nar_zst1264=== PAUSE TestIsValidUploadKey/nar_zst1265=== RUN TestIsValidUploadKey/nar_xz1266=== PAUSE TestIsValidUploadKey/nar_xz1267=== RUN TestIsValidUploadKey/nar_plain1268=== PAUSE TestIsValidUploadKey/nar_plain1269=== RUN TestIsValidUploadKey/listing1270=== PAUSE TestIsValidUploadKey/listing1271=== RUN TestIsValidUploadKey/build_log1272=== PAUSE TestIsValidUploadKey/build_log1273=== RUN TestIsValidUploadKey/build_log_home-manager_file1274=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1275=== RUN TestIsValidUploadKey/build_log_plus_in_name1276=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1277=== RUN TestIsValidUploadKey/build_log_question_mark1278=== PAUSE TestIsValidUploadKey/build_log_question_mark1279=== RUN TestIsValidUploadKey/build_log_equals1280=== PAUSE TestIsValidUploadKey/build_log_equals1281=== RUN TestIsValidUploadKey/realisation1282=== PAUSE TestIsValidUploadKey/realisation1283=== RUN TestIsValidUploadKey/realisation_plus_in_output1284=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1285=== RUN TestIsValidUploadKey/nix-cache-info1286=== PAUSE TestIsValidUploadKey/nix-cache-info1287=== RUN TestIsValidUploadKey/index.html1288=== PAUSE TestIsValidUploadKey/index.html1289=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1290=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1291=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1292=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1293=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1294=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1295=== RUN TestIsValidUploadKey/traversal1296=== PAUSE TestIsValidUploadKey/traversal1297=== RUN TestIsValidUploadKey/traversal_nar1298=== PAUSE TestIsValidUploadKey/traversal_nar1299=== RUN TestIsValidUploadKey/absolute1300=== PAUSE TestIsValidUploadKey/absolute1301=== RUN TestIsValidUploadKey/empty_key1302=== PAUSE TestIsValidUploadKey/empty_key1303=== RUN TestIsValidUploadKey/unknown_type1304=== PAUSE TestIsValidUploadKey/unknown_type1305=== CONT TestCacheStatsHandler13062026/10/27 08:43:31 INFO Aborted multipart uploads count=0 kept=013072026/10/27 08:43:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40317/oidc13082026/10/27 08:43:31 WARN Force mode enabled - objects will be deleted immediately without grace period1309--- PASS: TestReadProxyHead (0.53s)1310=== CONT TestUploadHandlersRejectOversizedBody1311=== NAME TestNARDeduplicationMetadataUploadBug1312 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1985021238/001/store/0dqkjhl9rvymwcjxbcglnfsvbwpf2xp3-file1.txt13132026/10/27 08:43:31 INFO Received uploads request method=POST path=/api/pending_closures13142026/10/27 08:43:31 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=013152026/10/27 08:43:31 INFO Vacuumed table table=pending_closures13162026/10/27 08:43:31 INFO Vacuumed table table=pending_objects13172026/10/27 08:43:31 INFO Vacuumed table table=multipart_uploads13182026/10/27 08:43:31 INFO Vacuumed table table=closures13192026/10/27 08:43:31 INFO Vacuumed table table=objects1320--- PASS: TestGCSweepDeliversEachKeyOnce (0.97s)1321=== CONT TestClientCADerivations1322--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.58s)1323=== CONT TestUploadHandlersRejectInvalidKeys1324=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1325=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1326=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1327=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1328=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1329=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1330=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1331=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1332=== CONT TestClientPushesUseOnePush13332026/10/27 08:43:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13342026/10/27 08:43:31 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1335--- PASS: TestCompleteMultipartUnregistered (0.68s)1336=== CONT TestCacheConfigHandler1337=== RUN TestCacheConfigHandler/full_config,_no_issuer1338=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1339=== RUN TestCacheConfigHandler/no_cache_url_configured1340=== PAUSE TestCacheConfigHandler/no_cache_url_configured1341=== RUN TestCacheConfigHandler/no_signing_keys1342=== PAUSE TestCacheConfigHandler/no_signing_keys1343=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1344=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1345=== CONT TestService_ReadAuthMiddleware1346--- PASS: TestReadProxyInvalidPath (0.66s)1347=== CONT TestService_createPendingClosureHandler1348=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1349=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1350=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1351=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1352=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1353=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1354=== CONT TestService_ReadScope_PublicByDefault1355--- PASS: TestReadProxy404 (0.67s)1356=== CONT TestService_verifyS3Integrity13572026/10/27 08:43:31 INFO Received uploads request method=POST path=/api/pending_closures13582026/10/27 08:43:31 INFO Aborted multipart uploads count=0 kept=013592026/10/27 08:43:31 INFO Aborted multipart uploads count=0 kept=01360--- PASS: TestCacheStatsHandler (0.46s)1361=== CONT TestPendingClosureWriteTimeout1362=== RUN TestPendingClosureWriteTimeout/empty1363=== PAUSE TestPendingClosureWriteTimeout/empty1364=== RUN TestPendingClosureWriteTimeout/400_objects1365=== PAUSE TestPendingClosureWriteTimeout/400_objects1366=== RUN TestPendingClosureWriteTimeout/670k_objects1367=== PAUSE TestPendingClosureWriteTimeout/670k_objects1368=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1369=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1370=== CONT TestProxyWriteTimeout1371=== RUN TestProxyWriteTimeout/narinfo1372=== PAUSE TestProxyWriteTimeout/narinfo1373=== RUN TestProxyWriteTimeout/1_GiB_nar1374=== PAUSE TestProxyWriteTimeout/1_GiB_nar1375=== RUN TestProxyWriteTimeout/10_GiB_nar1376=== PAUSE TestProxyWriteTimeout/10_GiB_nar1377=== RUN TestProxyWriteTimeout/unknown_size1378=== PAUSE TestProxyWriteTimeout/unknown_size1379=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1380=== RUN TestService_RequireScope_OIDC/builder_may_write1381=== PAUSE TestService_RequireScope_OIDC/builder_may_write1382=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1383=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1384=== RUN TestService_RequireScope_OIDC/ops_may_admin1385=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1386=== RUN TestService_RequireScope_OIDC/ops_may_not_write1387=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1388=== RUN TestService_RequireScope_OIDC/reader_may_not_write1389=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1390=== RUN TestService_RequireScope_OIDC/static_token_may_admin1391=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1392=== RUN TestService_RequireScope_OIDC/static_token_may_write1393=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1394=== RUN TestService_RequireScope_OIDC/reader_may_read1395=== PAUSE TestService_RequireScope_OIDC/reader_may_read1396=== RUN TestService_RequireScope_OIDC/writer_implies_read1397=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1398=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1399=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1400=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1401=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1402=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1403=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1404=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1405=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1406=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1407=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1408=== CONT TestService_AuthMiddleware_MTLSProxyHeader14092026/10/27 08:43:31 WARN Force mode enabled - objects will be deleted immediately without grace period14102026/10/27 08:43:31 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=014112026/10/27 08:43:31 INFO Vacuumed table table=pending_closures14122026/10/27 08:43:31 INFO Vacuumed table table=pending_objects14132026/10/27 08:43:31 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=014142026/10/27 08:43:31 INFO Vacuumed table table=multipart_uploads14152026/10/27 08:43:31 INFO Vacuumed table table=closures14162026/10/27 08:43:31 INFO Vacuumed table table=objects1417=== NAME TestClientIntegration1418 client_integration_test.go:291: Created store path: /build/TestClientIntegration1098468183/002/store/x0lq4bm9qyflgjm0f7vz85ijm34fiyyk-test-file.txt1419=== NAME TestClientMultipleUploads1420 client_integration_test.go:405: Created store path 0: /build/TestClientMultipleUploads3385080785/001/store/ywa3p588f85jdy0kjahkfi8d7sdgb5sr-test-file-0.txt14212026/10/27 08:43:31 INFO Vacuumed table table=pending_closures1422--- PASS: TestGCMetrics (0.76s)14232026/10/27 08:43:31 INFO Vacuumed table table=pending_objects1424=== CONT TestService_AuthMiddleware_OIDC14252026/10/27 08:43:31 INFO Vacuumed table table=multipart_uploads14262026/10/27 08:43:31 INFO Vacuumed table table=closures14272026/10/27 08:43:32 INFO Vacuumed table table=objects14282026/10/27 08:43:32 INFO Aborted multipart uploads count=0 kept=014292026/10/27 08:43:32 WARN Force mode enabled - objects will be deleted immediately without grace period14302026/10/27 08:43:32 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=014312026/10/27 08:43:32 INFO Vacuumed table table=pending_closures14322026/10/27 08:43:32 INFO Vacuumed table table=pending_objects14332026/10/27 08:43:32 INFO Vacuumed table table=multipart_uploads14342026/10/27 08:43:32 INFO Vacuumed table table=closures14352026/10/27 08:43:32 INFO Vacuumed table table=objects1436--- PASS: TestPushDedupSurvivesConcurrentGC (0.90s)1437=== CONT TestResolveDBConnectionString/flag_wins1438=== CONT TestResolveDBConnectionString/missing_file_is_an_error1439=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1440=== CONT TestResolveDBConnectionString/nothing_configured1441=== CONT TestResolveDBConnectionString/file_when_flag_empty1442=== CONT TestGCEndsOnShutdown/before_the_run1443--- PASS: TestResolveDBConnectionString (0.06s)1444 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1445 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1446 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1447 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1448 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)14492026/10/27 08:43:32 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44581/oidc1450--- PASS: TestService_ReadScope_PublicByDefault (0.41s)1451=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete14522026/10/27 08:43:32 INFO Received uploads request method=POST path=/api/pending_closures14532026/10/27 08:43:32 INFO Received uploads request method=POST path=/api/pending_closures14542026/10/27 08:43:32 INFO Received uploads request method=POST path=/api/pending_closures1455--- PASS: TestService_ReadAuthMiddleware (0.56s)1456=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark14572026/10/27 08:43:32 INFO Received uploads request method=POST path=/api/pending_closures1458--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.28s)1459=== CONT TestPush_RejectsBadRequests/no_roots14602026/10/27 08:43:32 INFO Received push request method=POST path=/api/pushes1461=== CONT TestPush_RejectsBadRequests/root_not_in_objects14622026/10/27 08:43:32 INFO Received push request method=POST path=/api/pushes1463=== CONT TestPush_RejectsBadRequests/bad_root14642026/10/27 08:43:32 INFO Received push request method=POST path=/api/pushes1465=== CONT TestPush_RejectsBadRequests/no_objects14662026/10/27 08:43:32 INFO Received push request method=POST path=/api/pushes1467=== CONT TestServerTLSConfig/no_client_CA1468=== CONT TestServerTLSConfig/not_a_PEM_file1469--- PASS: TestPush_RejectsBadRequests (0.77s)1470 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1471 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1472 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1473 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1474=== CONT TestServerTLSConfig/missing_CA_file1475--- PASS: TestServerTLSConfig (0.00s)1476 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1477 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1478 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1479=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows14802026/10/27 08:43:32 INFO lead: released remote=192.0.2.1:12341481--- PASS: TestLeadElectsOneAndHandsOver (2.89s)1482=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check14832026/10/27 08:43:32 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"14842026/10/27 08:43:32 WARN mTLS auth: bound subjects configured but subject DN unavailable14852026/10/27 08:43:32 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1486--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.38s)1487=== CONT TestIsValidCachePath/narinfo1488=== CONT TestIsValidCachePath/short_hash1489=== CONT TestIsValidCachePath/wrong_extension1490=== CONT TestIsValidCachePath/leading_slash1491=== CONT TestIsValidCachePath/empty1492=== CONT TestIsValidCachePath/random_path1493=== CONT TestIsValidCachePath/invalid_char_u1494=== CONT TestIsValidCachePath/invalid_char_e1495=== CONT TestIsValidCachePath/traversal_in_middle1496=== CONT TestIsValidCachePath/traversal_parent1497=== CONT TestIsValidCachePath/index.html1498=== CONT TestIsValidCachePath/nix-cache-info1499=== CONT TestIsValidCachePath/realisation1500=== CONT TestIsValidCachePath/log1501=== CONT TestIsValidCachePath/ls1502=== CONT TestIsValidCachePath/nar_uncompressed1503=== CONT TestIsValidCachePath/nar_zst1504=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1505=== CONT TestIsValidCachePath/nar_bz21506=== CONT TestIsValidCachePath/nar_xz1507--- PASS: TestIsValidCachePath (0.00s)1508 --- PASS: TestIsValidCachePath/narinfo (0.00s)1509 --- PASS: TestIsValidCachePath/short_hash (0.00s)1510 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1511 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1512 --- PASS: TestIsValidCachePath/empty (0.00s)1513 --- PASS: TestIsValidCachePath/random_path (0.00s)1514 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1515 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1516 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1517 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1518 --- PASS: TestIsValidCachePath/index.html (0.00s)1519 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1520 --- PASS: TestIsValidCachePath/realisation (0.00s)1521 --- PASS: TestIsValidCachePath/log (0.00s)1522 --- PASS: TestIsValidCachePath/ls (0.00s)1523 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1524 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1525 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1526 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1527 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1528=== CONT TestParseSingleRange/none1529=== CONT TestParseSingleRange/single_byte1530=== CONT TestParseSingleRange/suffix_exceeds_size1531=== CONT TestParseSingleRange/suffix1532=== CONT TestParseSingleRange/end_clamped_to_size1533=== CONT TestParseSingleRange/open-ended1534=== CONT TestParseSingleRange/closed1535=== CONT TestParseSingleRange/malformed_end_before_start1536=== CONT TestParseSingleRange/start_past_EOF1537=== CONT TestParseSingleRange/malformed_both_empty1538=== CONT TestParseSingleRange/unknown_unit1539=== CONT TestParseSingleRange/start_far_past_EOF1540=== CONT TestParseSingleRange/malformed_no_dash1541=== CONT TestParseSingleRange/multi-range_ignored1542--- PASS: TestParseSingleRange (0.00s)1543 --- PASS: TestParseSingleRange/none (0.00s)1544 --- PASS: TestParseSingleRange/single_byte (0.00s)1545 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1546 --- PASS: TestParseSingleRange/suffix (0.00s)1547 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1548 --- PASS: TestParseSingleRange/open-ended (0.00s)1549 --- PASS: TestParseSingleRange/closed (0.00s)1550 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1551 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1552 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1553 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1554 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1555 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1556 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1557=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale15582026/10/27 08:43:32 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15592026/10/27 08:43:32 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZDNiYjc5ZDktZDY4Yi00MTQwLTg1ZDItOTA1YTEyZjI5MDYxLjMwMTQyNDUxLThiNjQtNDE0Yy1hODE4LTRiZjkyZTRlODY3NXgxNzkzMDkwNjEyMTA1NDQ2OTY0 parts=1015602026/10/27 08:43:32 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15612026/10/27 08:43:32 INFO Completed upload id=1 objects=2 duration=2.24474ms15622026/10/27 08:43:32 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000015632026/10/27 08:43:32 INFO Received uploads request method=POST path=/api/pending_closures15642026/10/27 08:43:32 INFO Starting cleanup of old closures method=DELETE path=/api/closures15652026/10/27 08:43:32 INFO Aborted multipart uploads count=0 kept=01566=== NAME TestOrphanedObjectsGCStressTest1567 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains15682026/10/27 08:43:32 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1569 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion15702026/10/27 08:43:32 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZDNiYjc5ZDktZDY4Yi00MTQwLTg1ZDItOTA1YTEyZjI5MDYxLjdjNDZhOWYwLTcyY2ItNGMzMS05ZjQ4LTMxNzI0MTQzYzhkZngxNzkzMDkwNjEyMTU1NTM0MTI0 parts=1015712026/10/27 08:43:32 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15722026/10/27 08:43:32 INFO Completed upload id=1 objects=2 duration=2.391341ms15732026/10/27 08:43:32 INFO Received uploads request method=POST path=/api/pending_closures15742026/10/27 08:43:32 INFO Received uploads request method=POST path=/api/pending_closures15752026/10/27 08:43:32 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo15762026/10/27 08:43:32 WARN Found objects in DB but missing from S3, will re-upload count=11577--- PASS: TestService_verifyS3Integrity (0.89s)1578=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh15792026/10/27 08:43:32 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=015802026/10/27 08:43:32 INFO Vacuumed table table=pending_closures1581=== NAME TestPinProtectsFromGC1582 client_integration_test.go:778: Pinned store path: /build/TestPinProtectsFromGC1676887441/001/store/a963zsay97vwxwh8ybqavz0wn5zwv3mh-pinned-file.txt1583 client_integration_test.go:779: Unpinned store path: /build/TestPinProtectsFromGC1676887441/001/store/swwqv6chgm2ylrc6y2yn3bfk3lr7dxzg-unpinned-file.txt15842026/10/27 08:43:32 INFO Received push request method=POST path=/api/pushes1585=== NAME TestClientMultipleUploads1586 client_integration_test.go:405: Created store path 1: /build/TestClientMultipleUploads3385080785/001/store/np8y20bkil04sp3dz4xgh8n2f4vnfqnw-test-file-1.txt1587=== NAME TestClientWithDependencies1588 client_integration_test.go:660: Built derivation: /build/TestClientWithDependencies3800147774/001/store/mxg47lywjywq8iilwzscmai0vsblg2l8-test-script15892026/10/27 08:43:32 INFO Vacuumed table table=pending_objects15902026/10/27 08:43:32 INFO Vacuumed table table=multipart_uploads15912026/10/27 08:43:32 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15922026/10/27 08:43:32 INFO Uploading 0dqkjhl9rvymwcjxbcglnfsvbwpf2xp3-file1.txt (160B)15932026/10/27 08:43:32 INFO Received push request method=POST path=/api/pushes1594=== NAME TestClientMultipleUploads1595 client_integration_test.go:405: Created store path 2: /build/TestClientMultipleUploads3385080785/001/store/dr853gbg02r37zkf9yqpg5s9byf85xga-test-file-2.txt15962026/10/27 08:43:32 INFO Vacuumed table table=closures15972026/10/27 08:43:32 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15982026/10/27 08:43:32 INFO Vacuumed table table=objects15992026/10/27 08:43:32 INFO Uploading x0lq4bm9qyflgjm0f7vz85ijm34fiyyk-test-file.txt (152B)16002026/10/27 08:43:32 WARN Failed to register uploaded object key=0dqkjhl9rvymwcjxbcglnfsvbwpf2xp3.ls error="server returned 404: 404 page not found\n"16012026/10/27 08:43:32 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16022026/10/27 08:43:32 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"16032026/10/27 08:43:32 INFO Signed narinfos id=1 count=116042026/10/27 08:43:32 INFO Uploading 1 narinfos16052026/10/27 08:43:32 WARN Failed to register uploaded object key=x0lq4bm9qyflgjm0f7vz85ijm34fiyyk.ls error="server returned 404: 404 page not found\n"16062026/10/27 08:43:32 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16072026/10/27 08:43:32 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"16082026/10/27 08:43:32 INFO Signed narinfos id=1 count=116092026/10/27 08:43:32 INFO Uploading 1 narinfos16102026/10/27 08:43:32 WARN Failed to register uploaded object key=0dqkjhl9rvymwcjxbcglnfsvbwpf2xp3.narinfo error="server returned 404: 404 page not found\n"16112026/10/27 08:43:32 INFO Received complete push request method=POST path=/api/pushes/1/complete1612=== NAME TestClientCADerivations1613 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3822590238/001/store/j6wykxn4rbyk3pgjfhwsiwmybk8jy80c-ca-test16142026/10/27 08:43:32 INFO Received complete push request method=POST path=/api/pushes/1/complete16152026/10/27 08:43:32 WARN Failed to register uploaded object key=x0lq4bm9qyflgjm0f7vz85ijm34fiyyk.narinfo error="server returned 404: 404 page not found\n"16162026/10/27 08:43:32 INFO Completed push id=1 objects=3 duration=7.856309ms16172026/10/27 08:43:32 INFO Upload complete. (923ms)16182026/10/27 08:43:32 INFO Completed push id=1 objects=3 duration=5.758591ms16192026/10/27 08:43:32 INFO Upload complete. (336ms)1620=== NAME TestNARDeduplicationMetadataUploadBug1621 metadata_upload_test.go:54: Retrieved narinfo from S3:1622 StorePath: /build/TestNARDeduplicationMetadataUploadBug1985021238/001/store/0dqkjhl9rvymwcjxbcglnfsvbwpf2xp3-file1.txt1623 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1624 Compression: zstd1625 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1626 NarSize: 1601627 References: 1628 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1629 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1630 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1631 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}16322026/10/27 08:43:32 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001633--- PASS: TestService_createPendingClosureHandler (1.31s)1634=== CONT TestClientErrorHandling/InvalidStorePath16352026/10/27 08:43:32 INFO Aborted multipart uploads count=0 kept=016362026/10/27 08:43:32 INFO Aborted multipart uploads count=0 kept=01637=== CONT TestClientErrorHandling/ServerNotAvailable16382026/10/27 08:43:33 INFO Received uploads request method=POST path=/api/pending_closures16392026/10/27 08:43:33 INFO Aborted multipart uploads count=0 kept=01640=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1641=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1642=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1643=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1644=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1645=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1646=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1647=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1648=== CONT TestClientErrorHandling/InvalidAuthToken16492026/10/27 08:43:33 INFO Received uploads request method=POST path=/api/pending_closures16502026/10/27 08:43:33 INFO Aborted multipart uploads count=0 kept=016512026/10/27 08:43:33 WARN Force mode enabled - objects will be deleted immediately without grace period16522026/10/27 08:43:33 WARN Force mode enabled - objects will be deleted immediately without grace period16532026/10/27 08:43:33 WARN Force mode enabled - objects will be deleted immediately without grace period16542026/10/27 08:43:33 WARN Force mode enabled - objects will be deleted immediately without grace period1655=== NAME TestClientWithDependencies1656 client_integration_test.go:662: Found 1 dependencies (including self)16572026/10/27 08:43:33 INFO Received push request method=POST path=/api/pushes16582026/10/27 08:43:33 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=016592026/10/27 08:43:33 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:40943/bucket91/?delete=\": context canceled"1660=== NAME TestClientCADerivations1661 client_ca_test.go:139: Found 1 dependencies (including self)16622026/10/27 08:43:33 INFO All 1 paths already cached1663=== CONT TestIsValidUploadKey/narinfo1664=== CONT TestIsValidUploadKey/empty_key1665=== CONT TestIsValidUploadKey/absolute1666=== CONT TestIsValidUploadKey/traversal_nar1667=== CONT TestIsValidUploadKey/traversal1668=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1669=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1670=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1671=== CONT TestIsValidUploadKey/index.html1672=== CONT TestIsValidUploadKey/nix-cache-info1673=== CONT TestIsValidUploadKey/realisation_plus_in_output1674=== CONT TestIsValidUploadKey/realisation1675=== CONT TestIsValidUploadKey/build_log_equals1676=== CONT TestIsValidUploadKey/build_log_question_mark1677=== CONT TestIsValidUploadKey/build_log_plus_in_name1678=== CONT TestIsValidUploadKey/build_log_home-manager_file1679=== CONT TestIsValidUploadKey/build_log1680=== CONT TestIsValidUploadKey/listing1681=== CONT TestIsValidUploadKey/nar_plain1682=== CONT TestIsValidUploadKey/unknown_type1683=== CONT TestIsValidUploadKey/nar_xz1684=== CONT TestIsValidUploadKey/nar_zst1685--- PASS: TestIsValidUploadKey (0.00s)1686 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1687 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1688 --- PASS: TestIsValidUploadKey/absolute (0.00s)1689 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1690 --- PASS: TestIsValidUploadKey/traversal (0.00s)1691 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1692 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1693 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1694 --- PASS: TestIsValidUploadKey/index.html (0.00s)1695 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1696 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1697 --- PASS: TestIsValidUploadKey/realisation (0.00s)1698 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1699 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1700 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1701 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1702 --- PASS: TestIsValidUploadKey/build_log (0.00s)1703 --- PASS: TestIsValidUploadKey/listing (0.00s)1704 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1705 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1706 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1707 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1708=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17092026/10/27 08:43:33 INFO Received uploads request method=POST path=/1710=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17112026/10/27 08:43:33 INFO Received request for more parts method=POST path=/1712=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1713=== NAME TestNARDeduplicationMetadataUploadBug17142026/10/27 08:43:33 INFO Received complete multipart upload request method=POST path=/1715 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1985021238/001/store/i9hdvs70gbd1ba2p1y0cjwgq2a93mygm-file2.txt1716=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17172026/10/27 08:43:33 INFO Received uploads request method=POST path=/1718--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1719 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1720 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1721 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1722 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1723=== CONT TestCacheConfigHandler/full_config,_no_issuer1724=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1725=== CONT TestCacheConfigHandler/no_signing_keys1726=== NAME TestClientIntegration1727 client_integration_test.go:317: Retrieved narinfo from S3:1728 StorePath: /build/TestClientIntegration1098468183/002/store/x0lq4bm9qyflgjm0f7vz85ijm34fiyyk-test-file.txt1729 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1730 Compression: zstd1731 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11732 NarSize: 1521733 References: 1734 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11735=== CONT TestCacheConfigHandler/no_cache_url_configured17362026/10/27 08:43:33 INFO Vacuumed table table=pending_closures1737=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17382026/10/27 08:43:33 INFO Received uploads request method=POST path=/1739--- PASS: TestCacheConfigHandler (0.00s)1740 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1741 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1742 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1743 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)17442026/10/27 08:43:33 INFO Vacuumed table table=pending_objects1745=== NAME TestClientIntegration1746 client_integration_test.go:318: Retrieved .ls file from S3 (compressed size: 77 bytes)1747 client_integration_test.go:318: Decompressed .ls content (64 bytes):1748 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}17492026/10/27 08:43:33 INFO Vacuumed table table=multipart_uploads17502026/10/27 08:43:33 INFO Vacuumed table table=closures17512026/10/27 08:43:33 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)17522026/10/27 08:43:33 INFO Uploading 28fkv90ivkjw8v6l67447918yflvjmx4-shared-dep (136B)17532026/10/27 08:43:33 INFO Uploading ikic64w89b7vni17nw6asczi30zlnx6n-top (224B)17542026/10/27 08:43:33 INFO Vacuumed table table=objects1755--- PASS: TestGCEndsOnShutdown (0.00s)1756 --- PASS: TestGCEndsOnShutdown/before_the_run (0.95s)1757 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (1.16s)1758 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (1.10s)1759=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17602026/10/27 08:43:33 INFO Received complete multipart upload request method=POST path=/17612026/10/27 08:43:33 WARN Failed to register uploaded object key=ikic64w89b7vni17nw6asczi30zlnx6n.ls error="server returned 404: 404 page not found\n"17622026/10/27 08:43:33 WARN Failed to register uploaded object key=nar/0dl4fw96v8sy474m98yxrk5pmbk6rk9czsq80dcvhn485xivx842.nar.zst error="server returned 404: 404 page not found\n"17632026/10/27 08:43:33 WARN Failed to register uploaded object key=28fkv90ivkjw8v6l67447918yflvjmx4.ls error="server returned 404: 404 page not found\n"17642026/10/27 08:43:33 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17652026/10/27 08:43:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17662026/10/27 08:43:33 INFO Signed narinfos id=1 count=217672026/10/27 08:43:33 INFO Uploading 2 narinfos17682026/10/27 08:43:33 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=017692026/10/27 08:43:33 INFO Received complete push request method=POST path=/api/pushes/1/complete17702026/10/27 08:43:33 WARN Failed to register uploaded object key=28fkv90ivkjw8v6l67447918yflvjmx4.narinfo error="server returned 404: 404 page not found\n"17712026/10/27 08:43:33 WARN Failed to register uploaded object key=ikic64w89b7vni17nw6asczi30zlnx6n.narinfo error="server returned 404: 404 page not found\n"1772=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17732026/10/27 08:43:33 INFO Vacuumed table table=pending_closures17742026/10/27 08:43:33 INFO Received request for more parts method=POST path=/17752026/10/27 08:43:33 INFO Vacuumed table table=pending_objects17762026/10/27 08:43:33 INFO Vacuumed table table=multipart_uploads17772026/10/27 08:43:33 INFO Vacuumed table table=closures17782026/10/27 08:43:33 INFO Vacuumed table table=objects17792026/10/27 08:43:33 INFO Completed push id=1 objects=6 duration=9.757706ms17802026/10/27 08:43:33 INFO Upload complete. (356ms)1781=== NAME TestClientSharedPathCommittedMidPush1782 client_integration_test.go:727: Retrieved narinfo from S3:1783 StorePath: /build/TestClientSharedPathCommittedMidPush4236259079/001/store/28fkv90ivkjw8v6l67447918yflvjmx4-shared-dep1784 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1785 Compression: zstd1786 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821787 NarSize: 1361788 References: 1789 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1790=== NAME TestOrphanedObjectsGCStressTest1791 orphaned_objects_gc_test.go:503: Stress test completed successfully:1792 orphaned_objects_gc_test.go:504: - Active objects preserved: 201793 orphaned_objects_gc_test.go:505: - Objects deleted: 2101794 orphaned_objects_gc_test.go:506: - Total GC'd: 2101795--- PASS: TestOrphanedObjectsGCStressTest (3.55s)1796=== CONT TestPendingClosureWriteTimeout/empty1797=== CONT TestPendingClosureWriteTimeout/670k_objects1798=== CONT TestPendingClosureWriteTimeout/400_objects1799=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1800=== NAME TestClientSharedPathCommittedMidPush1801 client_integration_test.go:727: Retrieved narinfo from S3:1802 StorePath: /build/TestClientSharedPathCommittedMidPush4236259079/001/store/ikic64w89b7vni17nw6asczi30zlnx6n-top1803 URL: nar/0dl4fw96v8sy474m98yxrk5pmbk6rk9czsq80dcvhn485xivx842.nar.zst1804 Compression: zstd1805 NarHash: sha256:0dl4fw96v8sy474m98yxrk5pmbk6rk9czsq80dcvhn485xivx8421806 NarSize: 2241807 References: /build/TestClientSharedPathCommittedMidPush4236259079/001/store/28fkv90ivkjw8v6l67447918yflvjmx4-shared-dep1808 CA: text:sha256:04ma9p5lr4klycvyfvk0bp96kgg63pdbpljqnd0qn5p8k5m5a10q1809--- PASS: TestClientSharedPathCommittedMidPush (2.15s)1810=== CONT TestProxyWriteTimeout/narinfo1811=== CONT TestProxyWriteTimeout/10_GiB_nar1812=== CONT TestProxyWriteTimeout/1_GiB_nar1813=== CONT TestProxyWriteTimeout/unknown_size1814=== CONT TestService_RequireScope_OIDC/builder_may_write1815--- PASS: TestProxyWriteTimeout (0.00s)1816 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1817 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1818 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1819 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1820=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1821=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18222026/10/27 08:43:33 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]1823=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1824=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1825=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1826=== CONT TestService_RequireScope_OIDC/writer_implies_read1827=== CONT TestService_RequireScope_OIDC/reader_may_read1828=== CONT TestService_RequireScope_OIDC/static_token_may_write1829=== CONT TestService_RequireScope_OIDC/static_token_may_admin1830=== CONT TestService_RequireScope_OIDC/reader_may_not_write1831=== CONT TestService_RequireScope_OIDC/ops_may_not_write1832=== CONT TestService_RequireScope_OIDC/ops_may_admin1833=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1834=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1835--- PASS: TestService_RequireScope_OIDC (0.54s)1836 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1837 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1838 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1839 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1840 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1841 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1842 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1843 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1844 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1845 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1846 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1847 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1848 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1849 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1850=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1851=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18522026/10/27 08:43:33 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]1853=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18542026/10/27 08:43:33 WARN Authentication failed token_preview=eyJhbGciOi...4z6bB8T59A token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1855--- PASS: TestService_AuthMiddleware_OIDC (1.04s)1856 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1857 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1858 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1859 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1860--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1861 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (1.03s)1862 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (1.09s)18632026/10/27 08:43:33 INFO Received push request method=POST path=/api/pushes18642026/10/27 08:43:33 INFO Received uploads request method=POST path=/api/pending_closures18652026/10/27 08:43:33 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/present18662026/10/27 08:43:33 INFO Received uploads request method=POST path=/api/pending_closures18672026/10/27 08:43:33 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18682026/10/27 08:43:33 INFO Uploading a963zsay97vwxwh8ybqavz0wn5zwv3mh-pinned-file.txt (128B)18692026/10/27 08:43:33 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)18702026/10/27 08:43:33 INFO Uploading 95jrs6n5zy4baq0b14qh3g90mkzcy05p-a (216B)18712026/10/27 08:43:33 INFO Uploading lva1xbspr8rwrryxwqss36csa87wardd-shared-dep (136B)18722026/10/27 08:43:33 WARN Failed to register uploaded object key=a963zsay97vwxwh8ybqavz0wn5zwv3mh.ls error="server returned 404: 404 page not found\n"18732026/10/27 08:43:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18742026/10/27 08:43:33 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"18752026/10/27 08:43:33 WARN Failed to register uploaded object key=734sx0iprf23z252dlxwjbfq0ggkpg14.ls error="server returned 404: 404 page not found\n"18762026/10/27 08:43:33 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18772026/10/27 08:43:33 INFO Signed narinfos id=1 count=118782026/10/27 08:43:33 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18792026/10/27 08:43:33 WARN Failed to register uploaded object key=95jrs6n5zy4baq0b14qh3g90mkzcy05p.ls error="server returned 404: 404 page not found\n"18802026/10/27 08:43:33 WARN Failed to register uploaded object key=lva1xbspr8rwrryxwqss36csa87wardd.ls error="server returned 404: 404 page not found\n"18812026/10/27 08:43:33 INFO Uploading 1 narinfos18822026/10/27 08:43:33 WARN Failed to register uploaded object key=nar/00y1s42lv7pzlrvffb39v7mn46mypkfsw1rvshh6b3fvxvz8s2yn.nar.zst error="server returned 404: 404 page not found\n"18832026/10/27 08:43:33 INFO Signed narinfos id=1 count=218842026/10/27 08:43:33 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18852026/10/27 08:43:33 INFO Signed narinfos id=2 count=218862026/10/27 08:43:33 INFO Uploading 4 narinfos18872026/10/27 08:43:33 INFO Received complete push request method=POST path=/api/pushes/1/complete18882026/10/27 08:43:33 WARN Failed to register uploaded object key=a963zsay97vwxwh8ybqavz0wn5zwv3mh.narinfo error="server returned 404: 404 page not found\n"18892026/10/27 08:43:33 WARN Failed to register uploaded object key=lva1xbspr8rwrryxwqss36csa87wardd.narinfo error="server returned 404: 404 page not found\n"18902026/10/27 08:43:33 WARN Failed to register uploaded object key=734sx0iprf23z252dlxwjbfq0ggkpg14.narinfo error="server returned 404: 404 page not found\n"18912026/10/27 08:43:33 WARN Failed to register uploaded object key=95jrs6n5zy4baq0b14qh3g90mkzcy05p.narinfo error="server returned 404: 404 page not found\n"18922026/10/27 08:43:33 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18932026/10/27 08:43:33 WARN Failed to register uploaded object key=lva1xbspr8rwrryxwqss36csa87wardd.narinfo error="server returned 404: 404 page not found\n"18942026/10/27 08:43:33 INFO Completed push id=1 objects=3 duration=7.832649ms18952026/10/27 08:43:33 INFO Upload complete. (616ms)18962026/10/27 08:43:33 INFO Completed upload id=1 objects=6 duration=6.582118ms18972026/10/27 08:43:33 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18982026/10/27 08:43:33 INFO Completed upload id=2 objects=6 duration=1.09621ms18992026/10/27 08:43:33 INFO Upload complete. (301ms)1900=== NAME TestClientFallsBackToClosures1901 client_pushes_test.go:112: Retrieved narinfo from S3:1902 StorePath: /build/TestClientFallsBackToClosures4267036890/001/store/lva1xbspr8rwrryxwqss36csa87wardd-shared-dep1903 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1904 Compression: zstd1905 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821906 NarSize: 1361907 References: 1908 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1909 client_pushes_test.go:112: Retrieved narinfo from S3:1910 StorePath: /build/TestClientFallsBackToClosures4267036890/001/store/95jrs6n5zy4baq0b14qh3g90mkzcy05p-a1911 URL: nar/00y1s42lv7pzlrvffb39v7mn46mypkfsw1rvshh6b3fvxvz8s2yn.nar.zst1912 Compression: zstd1913 NarHash: sha256:00y1s42lv7pzlrvffb39v7mn46mypkfsw1rvshh6b3fvxvz8s2yn1914 NarSize: 2161915 References: /build/TestClientFallsBackToClosures4267036890/001/store/lva1xbspr8rwrryxwqss36csa87wardd-shared-dep1916 CA: text:sha256:113dbp0xynv48dd5f5ywagk8gwdfjk71h8a2h2cl40qym0bwxlrn1917 client_pushes_test.go:112: Retrieved narinfo from S3:1918 StorePath: /build/TestClientFallsBackToClosures4267036890/001/store/734sx0iprf23z252dlxwjbfq0ggkpg14-b1919 URL: nar/00y1s42lv7pzlrvffb39v7mn46mypkfsw1rvshh6b3fvxvz8s2yn.nar.zst1920 Compression: zstd1921 NarHash: sha256:00y1s42lv7pzlrvffb39v7mn46mypkfsw1rvshh6b3fvxvz8s2yn1922 NarSize: 2161923 References: /build/TestClientFallsBackToClosures4267036890/001/store/lva1xbspr8rwrryxwqss36csa87wardd-shared-dep1924 CA: text:sha256:113dbp0xynv48dd5f5ywagk8gwdfjk71h8a2h2cl40qym0bwxlrn1925--- PASS: TestClientFallsBackToClosures (2.33s)19262026/10/27 08:43:33 INFO Received uploads request method=POST path=/api/pending_closures19272026/10/27 08:43:33 WARN Request failed, retrying attempt=2 backoff=217.902561ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1928--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)1929 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (1.27s)1930 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (1.23s)19312026/10/27 08:43:33 WARN Request failed, retrying attempt=3 backoff=426.47586ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19322026/10/27 08:43:34 INFO Received push request method=POST path=/api/pushes19332026/10/27 08:43:34 INFO Received push request method=POST path=/api/pushes19342026/10/27 08:43:34 INFO Received push request method=POST path=/api/pushes19352026/10/27 08:43:34 INFO Received push request method=POST path=/api/pushes19362026/10/27 08:43:34 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19372026/10/27 08:43:34 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19382026/10/27 08:43:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19392026/10/27 08:43:34 INFO Uploading mxg47lywjywq8iilwzscmai0vsblg2l8-test-script (136B)19402026/10/27 08:43:34 INFO Object in database but missing from S3 key=x0lq4bm9qyflgjm0f7vz85ijm34fiyyk.ls19412026/10/27 08:43:34 WARN Found objects in DB but missing from S3, will re-upload count=119422026/10/27 08:43:34 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19432026/10/27 08:43:34 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)19442026/10/27 08:43:34 INFO Uploading dr853gbg02r37zkf9yqpg5s9byf85xga-test-file-2.txt (160B)19452026/10/27 08:43:34 INFO Uploading np8y20bkil04sp3dz4xgh8n2f4vnfqnw-test-file-1.txt (160B)19462026/10/27 08:43:34 INFO Uploading ywa3p588f85jdy0kjahkfi8d7sdgb5sr-test-file-0.txt (160B)19472026/10/27 08:43:34 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign19482026/10/27 08:43:34 WARN Failed to register uploaded object key=i9hdvs70gbd1ba2p1y0cjwgq2a93mygm.ls error="server returned 404: 404 page not found\n"19492026/10/27 08:43:34 WARN Failed to register uploaded object key=mxg47lywjywq8iilwzscmai0vsblg2l8.ls error="server returned 404: 404 page not found\n"19502026/10/27 08:43:34 INFO Received complete push request method=POST path=/api/pushes/2/complete19512026/10/27 08:43:34 INFO Signed narinfos id=2 count=119522026/10/27 08:43:34 INFO Uploading 1 narinfos19532026/10/27 08:43:34 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"19542026/10/27 08:43:34 WARN Failed to register uploaded object key=x0lq4bm9qyflgjm0f7vz85ijm34fiyyk.ls error="server returned 404: 404 page not found\n"19552026/10/27 08:43:34 WARN Failed to register uploaded object key=log/yylb1xs3a7h967sdpdav8kf01m9hd5hy-test-script.drv error="server returned 404: 404 page not found\n"19562026/10/27 08:43:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19572026/10/27 08:43:34 INFO Signed narinfos id=1 count=119582026/10/27 08:43:34 INFO Completed push id=2 objects=3 duration=1.819396ms19592026/10/27 08:43:34 INFO Uploading 1 narinfos19602026/10/27 08:43:34 INFO Upload complete. (481ms)19612026/10/27 08:43:34 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"19622026/10/27 08:43:34 WARN Failed to register uploaded object key=np8y20bkil04sp3dz4xgh8n2f4vnfqnw.ls error="server returned 404: 404 page not found\n"19632026/10/27 08:43:34 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"19642026/10/27 08:43:34 WARN Failed to register uploaded object key=ywa3p588f85jdy0kjahkfi8d7sdgb5sr.ls error="server returned 404: 404 page not found\n"19652026/10/27 08:43:34 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"19662026/10/27 08:43:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19672026/10/27 08:43:34 WARN Failed to register uploaded object key=dr853gbg02r37zkf9yqpg5s9byf85xga.ls error="server returned 404: 404 page not found\n"19682026/10/27 08:43:34 INFO Signed narinfos id=1 count=319692026/10/27 08:43:34 INFO Uploading 3 narinfos1970=== NAME TestClientIntegration1971 client_integration_test.go:335: Retrieved .ls file from S3 (compressed size: 62 bytes)1972 client_integration_test.go:335: Decompressed .ls content (49 bytes):1973 {"version":1,"root":{"type":"regular","size":39}}19742026/10/27 08:43:34 INFO Received complete push request method=POST path=/api/pushes/2/complete19752026/10/27 08:43:34 WARN Failed to register uploaded object key=i9hdvs70gbd1ba2p1y0cjwgq2a93mygm.narinfo error="server returned 404: 404 page not found\n"19762026/10/27 08:43:34 INFO Received complete push request method=POST path=/api/pushes/1/complete19772026/10/27 08:43:34 WARN Failed to register uploaded object key=mxg47lywjywq8iilwzscmai0vsblg2l8.narinfo error="server returned 404: 404 page not found\n"19782026/10/27 08:43:34 INFO Completed push id=2 objects=3 duration=1.782836ms19792026/10/27 08:43:34 INFO Upload complete. (486ms)19802026/10/27 08:43:34 WARN Failed to register uploaded object key=dr853gbg02r37zkf9yqpg5s9byf85xga.narinfo error="server returned 404: 404 page not found\n"19812026/10/27 08:43:34 WARN Failed to register uploaded object key=np8y20bkil04sp3dz4xgh8n2f4vnfqnw.narinfo error="server returned 404: 404 page not found\n"19822026/10/27 08:43:34 INFO Received complete push request method=POST path=/api/pushes/1/complete19832026/10/27 08:43:34 WARN Failed to register uploaded object key=ywa3p588f85jdy0kjahkfi8d7sdgb5sr.narinfo error="server returned 404: 404 page not found\n"1984=== NAME TestNARDeduplicationMetadataUploadBug1985 metadata_upload_test.go:76: Retrieved narinfo from S3:1986 StorePath: /build/TestNARDeduplicationMetadataUploadBug1985021238/001/store/i9hdvs70gbd1ba2p1y0cjwgq2a93mygm-file2.txt1987 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1988 Compression: zstd1989 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1990 NarSize: 1601991 References: 1992 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1993 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)19942026/10/27 08:43:34 INFO Completed push id=1 objects=4 duration=6.79834ms19952026/10/27 08:43:34 INFO Upload complete. (492ms)19962026/10/27 08:43:34 INFO Completed push id=1 objects=9 duration=126.077428ms1997--- PASS: TestUploadHandlersRejectOversizedBody (0.19s)1998 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)1999 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)2000 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.06s)20012026/10/27 08:43:34 INFO Upload complete. (1.065s)2002=== NAME TestNARDeduplicationMetadataUploadBug2003 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2004 {"version":1,"root":{"type":"regular","size":44}}2005=== NAME TestClientMultipleUploads2006 client_integration_test.go:416: Uploaded 3 paths in 1.382943148s20072026/10/27 08:43:34 WARN Request failed, retrying attempt=4 backoff=875.748278ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2008=== NAME TestClientWithDependencies2009 client_integration_test.go:664: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3800147774/001/store) requires matching store prefix20102026/10/27 08:43:34 WARN Rate limiter enabled after throttle name=s3-test rate=520112026/10/27 08:43:34 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2012=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2013 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102014 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002015--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.99s)2016--- PASS: TestNARDeduplicationMetadataUploadBug (3.55s)2017--- PASS: TestClientWithDependencies (3.11s)2018--- PASS: TestClientMultipleUploads (3.01s)20192026/10/27 08:43:34 INFO Received push request method=POST path=/api/pushes20202026/10/27 08:43:34 INFO Received push request method=POST path=/api/pushes20212026/10/27 08:43:34 INFO Received push request method=POST path=/api/pushes20222026/10/27 08:43:34 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20232026/10/27 08:43:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20242026/10/27 08:43:34 INFO Uploading swwqv6chgm2ylrc6y2yn3bfk3lr7dxzg-unpinned-file.txt (128B)20252026/10/27 08:43:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20262026/10/27 08:43:34 INFO Uploading j6wykxn4rbyk3pgjfhwsiwmybk8jy80c-ca-test (144B)20272026/10/27 08:43:34 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)20282026/10/27 08:43:34 INFO Uploading czakm3bbhvpwga3h1gvqi6c5jjh1aa3b-b (216B)20292026/10/27 08:43:34 INFO Uploading 8fawasgyxydlc91i2zaiq27syhk31nnn-shared-dep (136B)20302026/10/27 08:43:34 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"20312026/10/27 08:43:34 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign20322026/10/27 08:43:34 WARN Failed to register uploaded object key=swwqv6chgm2ylrc6y2yn3bfk3lr7dxzg.ls error="server returned 404: 404 page not found\n"20332026/10/27 08:43:34 INFO Signed narinfos id=2 count=120342026/10/27 08:43:34 INFO Uploading 1 narinfos20352026/10/27 08:43:34 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"20362026/10/27 08:43:34 WARN Failed to register uploaded object key=j6wykxn4rbyk3pgjfhwsiwmybk8jy80c.ls error="server returned 404: 404 page not found\n"20372026/10/27 08:43:34 WARN Failed to register uploaded object key=7n0q8x32pbfmrjil8r8a5csm6y4845cw.ls error="server returned 404: 404 page not found\n"20382026/10/27 08:43:34 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"20392026/10/27 08:43:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20402026/10/27 08:43:34 WARN Failed to register uploaded object key=log/nlb3s7im4vh5gd6i8lwrxqr2d47j7n3q-ca-test.drv error="server returned 404: 404 page not found\n"20412026/10/27 08:43:34 WARN Failed to register uploaded object key=8fawasgyxydlc91i2zaiq27syhk31nnn.ls error="server returned 404: 404 page not found\n"20422026/10/27 08:43:34 INFO Signed narinfos id=1 count=120432026/10/27 08:43:34 WARN Failed to register uploaded object key=nar/13p6416mskbi7jwrgdk7wzp6qzx19xhn4xb4hzj3zrjxzd1z3iy6.nar.zst error="server returned 404: 404 page not found\n"20442026/10/27 08:43:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20452026/10/27 08:43:34 INFO Uploading 1 narinfos20462026/10/27 08:43:34 WARN Failed to register uploaded object key=czakm3bbhvpwga3h1gvqi6c5jjh1aa3b.ls error="server returned 404: 404 page not found\n"20472026/10/27 08:43:34 INFO Signed narinfos id=1 count=320482026/10/27 08:43:34 INFO Uploading 3 narinfos20492026/10/27 08:43:34 INFO Received complete push request method=POST path=/api/pushes/2/complete20502026/10/27 08:43:34 WARN Failed to register uploaded object key=swwqv6chgm2ylrc6y2yn3bfk3lr7dxzg.narinfo error="server returned 404: 404 page not found\n"20512026/10/27 08:43:34 INFO Received complete push request method=POST path=/api/pushes/1/complete20522026/10/27 08:43:34 WARN Failed to register uploaded object key=j6wykxn4rbyk3pgjfhwsiwmybk8jy80c.narinfo error="server returned 404: 404 page not found\n"20532026/10/27 08:43:34 WARN Failed to register uploaded object key=czakm3bbhvpwga3h1gvqi6c5jjh1aa3b.narinfo error="server returned 404: 404 page not found\n"20542026/10/27 08:43:34 INFO Received complete push request method=POST path=/api/pushes/1/complete20552026/10/27 08:43:34 WARN Failed to register uploaded object key=7n0q8x32pbfmrjil8r8a5csm6y4845cw.narinfo error="server returned 404: 404 page not found\n"20562026/10/27 08:43:34 WARN Failed to register uploaded object key=8fawasgyxydlc91i2zaiq27syhk31nnn.narinfo error="server returned 404: 404 page not found\n"20572026/10/27 08:43:34 INFO Completed push id=2 objects=3 duration=3.164527ms20582026/10/27 08:43:34 INFO Upload complete. (179ms)20592026/10/27 08:43:34 INFO Completed push id=1 objects=8 duration=6.480637ms20602026/10/27 08:43:34 INFO Upload complete. (184ms)20612026/10/27 08:43:34 INFO Completed push id=1 objects=4 duration=7.327444ms20622026/10/27 08:43:34 INFO Upload complete. (658ms)2063=== NAME TestClientPushesUseOnePush2064 client_pushes_test.go:97: Retrieved narinfo from S3:2065 StorePath: /build/TestClientPushesUseOnePush2913795610/001/store/8fawasgyxydlc91i2zaiq27syhk31nnn-shared-dep2066 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2067 Compression: zstd2068 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822069 NarSize: 1362070 References: 2071 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2072=== NAME TestClientCADerivations2073 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3822590238/001/store/j6wykxn4rbyk3pgjfhwsiwmybk8jy80c-ca-test2074 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2075 Compression: zstd2076 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2077 NarSize: 1442078 References: 2079 Deriver: /build/TestClientCADerivations3822590238/001/store/nlb3s7im4vh5gd6i8lwrxqr2d47j7n3q-ca-test.drv2080 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2081 client_ca_test.go:185: Checking for realisation files in S3...2082=== NAME TestClientPushesUseOnePush2083 client_pushes_test.go:97: Retrieved narinfo from S3:2084 StorePath: /build/TestClientPushesUseOnePush2913795610/001/store/7n0q8x32pbfmrjil8r8a5csm6y4845cw-a2085 URL: nar/13p6416mskbi7jwrgdk7wzp6qzx19xhn4xb4hzj3zrjxzd1z3iy6.nar.zst2086 Compression: zstd2087 NarHash: sha256:13p6416mskbi7jwrgdk7wzp6qzx19xhn4xb4hzj3zrjxzd1z3iy62088 NarSize: 2162089 References: /build/TestClientPushesUseOnePush2913795610/001/store/8fawasgyxydlc91i2zaiq27syhk31nnn-shared-dep2090 CA: text:sha256:1s7m52smp8xawl2p39xlhxv5x8sdi3f39bh9k279r9mp43dwiwng2091 client_pushes_test.go:97: Retrieved narinfo from S3:2092 StorePath: /build/TestClientPushesUseOnePush2913795610/001/store/czakm3bbhvpwga3h1gvqi6c5jjh1aa3b-b2093 URL: nar/13p6416mskbi7jwrgdk7wzp6qzx19xhn4xb4hzj3zrjxzd1z3iy6.nar.zst2094 Compression: zstd2095 NarHash: sha256:13p6416mskbi7jwrgdk7wzp6qzx19xhn4xb4hzj3zrjxzd1z3iy62096 NarSize: 2162097 References: /build/TestClientPushesUseOnePush2913795610/001/store/8fawasgyxydlc91i2zaiq27syhk31nnn-shared-dep2098 CA: text:sha256:1s7m52smp8xawl2p39xlhxv5x8sdi3f39bh9k279r9mp43dwiwng2099=== NAME TestClientCADerivations2100 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2101 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache2102--- PASS: TestClientPushesUseOnePush (2.78s)2103--- PASS: TestPendingClosureWriteTimeout (0.00s)2104 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2105 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2106 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2107 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.09s)2108--- PASS: TestDeleteClosuresRacingPins (3.21s)21092026/10/27 08:43:34 INFO Starting cleanup of old closures method=DELETE path=/api/closures21102026/10/27 08:43:34 INFO Garbage collection started21112026/10/27 08:43:34 INFO Aborted multipart uploads count=0 kept=021122026/10/27 08:43:34 WARN Force mode enabled - objects will be deleted immediately without grace period21132026/10/27 08:43:34 INFO Received push request method=POST path=/api/pushes21142026/10/27 08:43:34 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)21152026/10/27 08:43:34 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=021162026/10/27 08:43:34 INFO Vacuumed table table=pending_closures21172026/10/27 08:43:34 INFO Received complete push request method=POST path=/api/pushes/3/complete21182026/10/27 08:43:34 WARN Failed to register uploaded object key=x0lq4bm9qyflgjm0f7vz85ijm34fiyyk.ls error="server returned 404: 404 page not found\n"21192026/10/27 08:43:34 INFO Completed push id=3 objects=3 duration=2.117579ms21202026/10/27 08:43:34 INFO Upload complete. (57ms)21212026/10/27 08:43:34 INFO Vacuumed table table=pending_objects21222026/10/27 08:43:34 INFO Vacuumed table table=multipart_uploads2123=== NAME TestClientIntegration2124 client_integration_test.go:352: Retrieved .ls file from S3 (compressed size: 62 bytes)2125 client_integration_test.go:352: Decompressed .ls content (49 bytes):2126 {"version":1,"root":{"type":"regular","size":39}}2127 client_integration_test.go:363: Testing garbage collection...21282026/10/27 08:43:34 INFO Vacuumed table table=closures21292026/10/27 08:43:34 INFO Vacuumed table table=objects2130--- PASS: TestConnectWaitsForAPeerMigration (5.57s)21312026/10/27 08:43:34 INFO Starting cleanup of old closures method=DELETE path=/api/closures21322026/10/27 08:43:34 INFO Garbage collection started21332026/10/27 08:43:34 INFO Aborted multipart uploads count=0 kept=021342026/10/27 08:43:35 WARN Request failed, retrying attempt=5 backoff=1.471544279s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21352026/10/27 08:43:35 WARN Force mode enabled - objects will be deleted immediately without grace period21362026/10/27 08:43:35 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=021372026/10/27 08:43:35 INFO Vacuumed table table=pending_closures21382026/10/27 08:43:35 INFO Vacuumed table table=pending_objects21392026/10/27 08:43:35 INFO Vacuumed table table=multipart_uploads21402026/10/27 08:43:35 INFO Vacuumed table table=closures21412026/10/27 08:43:35 INFO Vacuumed table table=objects2142--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.57s)2143=== NAME TestClientCADerivations2144 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2145 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2146 error: binary cache 's3://bucket84?endpoint=http://localhost:40943&region=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3822590238/001/store'2147 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12148--- PASS: TestClientCADerivations (4.35s)21492026/10/27 08:43:36 INFO Aborted multipart uploads count=1 kept=021502026/10/27 08:43:36 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=021512026/10/27 08:43:36 INFO Received create pin request method=POST path=/api/pins/myapp21522026/10/27 08:43:36 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1676887441/001/store/a963zsay97vwxwh8ybqavz0wn5zwv3mh-pinned-file.txt narinfo_key=a963zsay97vwxwh8ybqavz0wn5zwv3mh.narinfo21532026/10/27 08:43:36 INFO Received cleanup request method=DELETE path=/api/pending_closures21542026/10/27 08:43:36 INFO Starting cleanup of old closures method=DELETE path=/api/closures21552026/10/27 08:43:36 INFO Garbage collection started21562026/10/27 08:43:36 INFO Aborted multipart uploads count=1 kept=021572026/10/27 08:43:36 INFO Aborted multipart uploads count=0 kept=02158--- PASS: TestPendingCleanupUsesOneCutoff (6.40s)21592026/10/27 08:43:36 WARN Force mode enabled - objects will be deleted immediately without grace period21602026/10/27 08:43:36 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=021612026/10/27 08:43:36 INFO Vacuumed table table=pending_closures21622026/10/27 08:43:36 INFO Vacuumed table table=pending_objects21632026/10/27 08:43:36 INFO Vacuumed table table=multipart_uploads21642026/10/27 08:43:36 INFO Vacuumed table table=closures21652026/10/27 08:43:36 INFO Vacuumed table table=objects21662026/10/27 08:43:36 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02167=== NAME TestClientIntegration2168 client_integration_test.go:370: Objects in database after GC:2169 client_integration_test.go:370: Successfully deleted all objects with GC --force2170--- PASS: TestClientIntegration (5.62s)21712026/10/27 08:43:37 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-config21722026/10/27 08:43:37 WARN Request failed, retrying attempt=2 backoff=209.957229ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21732026/10/27 08:43:37 WARN Request failed, retrying attempt=3 backoff=392.681878ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21742026/10/27 08:43:37 WARN Request failed, retrying attempt=4 backoff=761.639988ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21752026/10/27 08:43:38 WARN Request failed, retrying attempt=5 backoff=1.66447397s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2176=== NAME TestPinProtectsFromGC2177 client_integration_test.go:887: Pin successfully protected closure from garbage collection2178--- PASS: TestPinProtectsFromGC (7.43s)21792026/10/27 08:43:40 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"21802026/10/27 08:43:40 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-config21812026/10/27 08:43:40 WARN Request failed, retrying attempt=2 backoff=198.272817ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21822026/10/27 08:43:40 WARN Request failed, retrying attempt=3 backoff=374.02828ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21832026/10/27 08:43:40 WARN Request failed, retrying attempt=4 backoff=791.578412ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21842026/10/27 08:43:41 WARN Request failed, retrying attempt=5 backoff=1.628531012s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21852026/10/27 08:43:43 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_closures21862026/10/27 08:43:43 WARN Request failed, retrying attempt=2 backoff=191.481607ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21872026/10/27 08:43:43 WARN Request failed, retrying attempt=3 backoff=439.970478ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21882026/10/27 08:43:44 WARN Request failed, retrying attempt=4 backoff=858.891425ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21892026/10/27 08:43:44 WARN Request failed, retrying attempt=5 backoff=1.466594892s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2190--- PASS: TestClientErrorHandling (0.00s)2191 --- PASS: TestClientErrorHandling/InvalidStorePath (0.54s)2192 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.25s)2193 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.37s)2194PASS2195{"timestamp":"2026-10-27T08:43:46.344695082Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:40952","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(201)"}21962026-10-27 08:43:46.588 UTC [128] LOG: received smart shutdown request21972026-10-27 08:43:46.594 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 121982026-10-27 08:43:46.606 UTC [133] LOG: shutting down21992026-10-27 08:43:46.606 UTC [133] LOG: checkpoint starting: shutdown immediate22002026-10-27 08:43:47.732 UTC [133] LOG: checkpoint complete: wrote 10629 buffers (64.9%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 30 recycled; write=0.264 s, sync=0.818 s, total=1.126 s; sync files=34045, longest=0.003 s, average=0.001 s; distance=494037 kB, estimate=494037 kB; lsn=0/1F9DB2F0, redo lsn=0/1F9DB2F022012026-10-27 08:43:47.825 UTC [128] LOG: database system is shut down2202Running OIDC tests...2203=== RUN TestAudienceForIssuer2204=== PAUSE TestAudienceForIssuer2205=== RUN TestGlobMatch2206=== PAUSE TestGlobMatch2207=== RUN TestValidateToken_ValidToken2208=== PAUSE TestValidateToken_ValidToken2209=== RUN TestValidateToken_WrongAudience2210=== PAUSE TestValidateToken_WrongAudience2211=== RUN TestValidateToken_Expired2212=== PAUSE TestValidateToken_Expired2213=== RUN TestValidateToken_BoundClaimsMismatch2214=== PAUSE TestValidateToken_BoundClaimsMismatch2215=== RUN TestValidateToken_BoundSubjectMismatch2216=== PAUSE TestValidateToken_BoundSubjectMismatch2217=== RUN TestValidateToken_MultipleProviders2218=== PAUSE TestValidateToken_MultipleProviders2219=== RUN TestValidateToken_NoMatchingProvider2220=== PAUSE TestValidateToken_NoMatchingProvider2221=== RUN TestValidateToken_KubernetesServiceAccount2222=== PAUSE TestValidateToken_KubernetesServiceAccount2223=== RUN TestNewValidator_KubernetesRequiresCA2224=== PAUSE TestNewValidator_KubernetesRequiresCA2225=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2226=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2227=== RUN TestPins_ReservedForMatchingRule2228=== PAUSE TestPins_ReservedForMatchingRule2229=== RUN TestPins_TopLevelShorthand2230=== PAUSE TestPins_TopLevelShorthand2231=== RUN TestPins_ConfigValidation2232=== PAUSE TestPins_ConfigValidation2233=== RUN TestScopes_LegacyProviderDefaultsToWrite2234=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2235=== RUN TestScopes_Rules2236=== PAUSE TestScopes_Rules2237=== RUN TestScopes_ConfigValidation2238=== PAUSE TestScopes_ConfigValidation2239=== CONT TestAudienceForIssuer2240--- PASS: TestAudienceForIssuer (0.00s)2241=== CONT TestValidateToken_NoMatchingProvider2242=== CONT TestPins_ConfigValidation2243=== CONT TestValidateToken_KubernetesServiceAccount2244--- PASS: TestPins_ConfigValidation (0.00s)2245=== CONT TestScopes_ConfigValidation2246--- PASS: TestScopes_ConfigValidation (0.00s)2247=== CONT TestScopes_Rules2248=== CONT TestPins_TopLevelShorthand2249=== CONT TestValidateToken_MultipleProviders2250=== CONT TestScopes_LegacyProviderDefaultsToWrite2251=== CONT TestValidateToken_BoundSubjectMismatch2252=== CONT TestValidateToken_BoundClaimsMismatch2253=== CONT TestValidateToken_Expired2254=== CONT TestValidateToken_WrongAudience2255=== CONT TestValidateToken_ValidToken2256=== CONT TestGlobMatch2257=== RUN TestGlobMatch/foo_foo2258=== PAUSE TestGlobMatch/foo_foo2259=== CONT TestPins_ReservedForMatchingRule2260=== RUN TestGlobMatch/foo_bar2261=== PAUSE TestGlobMatch/foo_bar2262=== RUN TestGlobMatch/*_2263=== PAUSE TestGlobMatch/*_2264=== RUN TestGlobMatch/*_anything2265=== PAUSE TestGlobMatch/*_anything2266=== RUN TestGlobMatch/foo*_foo2267=== PAUSE TestGlobMatch/foo*_foo2268=== RUN TestGlobMatch/foo*_foobar2269=== PAUSE TestGlobMatch/foo*_foobar2270=== RUN TestGlobMatch/foo*_bar2271=== PAUSE TestGlobMatch/foo*_bar2272=== RUN TestGlobMatch/*bar_bar2273=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2274=== PAUSE TestGlobMatch/*bar_bar2275=== CONT TestNewValidator_KubernetesRequiresCA2276=== RUN TestGlobMatch/*bar_foobar2277=== PAUSE TestGlobMatch/*bar_foobar2278=== RUN TestGlobMatch/*bar_foo2279=== PAUSE TestGlobMatch/*bar_foo2280=== RUN TestGlobMatch/foo*bar_foobar2281=== PAUSE TestGlobMatch/foo*bar_foobar2282=== RUN TestGlobMatch/foo*bar_foo123bar2283=== PAUSE TestGlobMatch/foo*bar_foo123bar2284=== RUN TestGlobMatch/foo*bar_foobarbaz2285=== PAUSE TestGlobMatch/foo*bar_foobarbaz2286=== RUN TestGlobMatch/*/*_foo/bar2287=== PAUSE TestGlobMatch/*/*_foo/bar2288=== RUN TestGlobMatch/*/*_foo2289=== PAUSE TestGlobMatch/*/*_foo2290=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2291=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2292=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02293=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02294=== RUN TestGlobMatch/refs/*/main_refs/heads/main2295=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2296=== RUN TestGlobMatch/fo?_foo2297=== PAUSE TestGlobMatch/fo?_foo2298=== RUN TestGlobMatch/fo?_fo2299=== PAUSE TestGlobMatch/fo?_fo2300=== RUN TestGlobMatch/fo?_fooo2301=== PAUSE TestGlobMatch/fo?_fooo2302=== RUN TestGlobMatch/?oo_foo2303=== PAUSE TestGlobMatch/?oo_foo2304=== RUN TestGlobMatch/?oo_boo2305=== PAUSE TestGlobMatch/?oo_boo2306=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2307=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2308=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2309=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2310=== CONT TestGlobMatch/foo_foo2311=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2312=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2313=== CONT TestGlobMatch/?oo_boo2314=== CONT TestGlobMatch/?oo_foo2315=== CONT TestGlobMatch/fo?_fooo2316=== CONT TestGlobMatch/fo?_fo2317=== CONT TestGlobMatch/fo?_foo2318=== CONT TestGlobMatch/refs/*/main_refs/heads/main2319=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02320=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2321=== CONT TestGlobMatch/*/*_foo2322=== CONT TestGlobMatch/*/*_foo/bar2323=== CONT TestGlobMatch/foo*bar_foobarbaz2324=== CONT TestGlobMatch/foo*bar_foo123bar2325=== CONT TestGlobMatch/foo*bar_foobar2326=== CONT TestGlobMatch/*bar_foo2327=== CONT TestGlobMatch/*bar_foobar2328=== CONT TestGlobMatch/*bar_bar2329=== CONT TestGlobMatch/foo*_bar2330=== CONT TestGlobMatch/foo*_foobar2331=== CONT TestGlobMatch/foo*_foo2332=== CONT TestGlobMatch/*_anything2333=== CONT TestGlobMatch/*_2334=== CONT TestGlobMatch/foo_bar2335--- PASS: TestGlobMatch (0.12s)2336 --- PASS: TestGlobMatch/foo_foo (0.00s)2337 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2338 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2339 --- PASS: TestGlobMatch/?oo_boo (0.00s)2340 --- PASS: TestGlobMatch/?oo_foo (0.00s)2341 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2342 --- PASS: TestGlobMatch/fo?_fo (0.00s)2343 --- PASS: TestGlobMatch/fo?_foo (0.00s)2344 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2345 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2346 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2347 --- PASS: TestGlobMatch/*/*_foo (0.00s)2348 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2349 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2350 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2351 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2352 --- PASS: TestGlobMatch/*bar_foo (0.00s)2353 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2354 --- PASS: TestGlobMatch/*bar_bar (0.00s)2355 --- PASS: TestGlobMatch/foo*_bar (0.00s)2356 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2357 --- PASS: TestGlobMatch/foo*_foo (0.00s)2358 --- PASS: TestGlobMatch/*_anything (0.00s)2359 --- PASS: TestGlobMatch/*_ (0.00s)2360 --- PASS: TestGlobMatch/foo_bar (0.00s)23612026/10/27 08:43:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40947/oidc2362--- PASS: TestValidateToken_WrongAudience (0.16s)23632026/10/27 08:43:49 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:3447523642026/10/27 08:43:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34307/oidc2365--- PASS: TestPins_TopLevelShorthand (0.30s)2366--- PASS: TestValidateToken_KubernetesServiceAccount (0.31s)23672026/10/27 08:43:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42515/oidc2368--- PASS: TestValidateToken_ValidToken (0.21s)23692026/10/27 08:43:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33511/oidc2370--- PASS: TestValidateToken_Expired (0.25s)23712026/10/27 08:43:49 http: TLS handshake error from 127.0.0.1:55752: remote error: tls: bad certificate2372--- PASS: TestNewValidator_KubernetesRequiresCA (0.09s)23732026/10/27 08:43:49 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:40169/oidc23742026/10/27 08:43:49 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:34123/oidc23752026/10/27 08:43:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44729/oidc2376--- PASS: TestValidateToken_MultipleProviders (0.32s)2377--- PASS: TestValidateToken_BoundClaimsMismatch (0.29s)23782026/10/27 08:43:50 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232379--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.12s)23802026/10/27 08:43:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41349/oidc2381--- PASS: TestScopes_Rules (0.38s)23822026/10/27 08:43:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42769/oidc2383--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.42s)23842026/10/27 08:43:50 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:45445/oidc2385--- PASS: TestValidateToken_NoMatchingProvider (0.57s)23862026/10/27 08:43:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42307/oidc2387--- PASS: TestValidateToken_BoundSubjectMismatch (0.55s)23882026/10/27 08:43:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34029/oidc2389--- PASS: TestPins_ReservedForMatchingRule (0.46s)2390PASS2391Running hook tests...2392=== RUN TestSendPathsEmpty2393=== PAUSE TestSendPathsEmpty2394=== RUN TestQueueEnqueueAndFetch2395=== PAUSE TestQueueEnqueueAndFetch2396=== RUN TestQueueDeduplication2397=== PAUSE TestQueueDeduplication2398=== RUN TestQueueRemove2399=== PAUSE TestQueueRemove2400=== RUN TestQueueFetchBatchLimit2401=== PAUSE TestQueueFetchBatchLimit2402=== RUN TestQueueRetryMovesToBack2403=== PAUSE TestQueueRetryMovesToBack2404=== RUN TestQueueFetchRemoveLifecycle2405=== PAUSE TestQueueFetchRemoveLifecycle2406=== RUN TestQueueConcurrentWriters2407=== PAUSE TestQueueConcurrentWriters2408=== RUN TestQueueRemoveLargeClosure2409=== PAUSE TestQueueRemoveLargeClosure2410=== RUN TestServerClientIntegration2411--- PASS: TestServerClientIntegration (0.00s)2412=== RUN TestServerQueueError24132026/10/27 08:43:50 ERROR Failed to queue paths error="permission denied" count=12414--- PASS: TestServerQueueError (0.00s)2415=== RUN TestGetListenerSocketActivation2416 server_test.go:218: === RUN TestGetListenerSocketActivation2417 --- PASS: TestGetListenerSocketActivation (0.00s)2418 PASS2419 2420--- PASS: TestGetListenerSocketActivation (0.25s)2421=== RUN TestServerStalledClientDoesNotBlockShutdown2422=== PAUSE TestServerStalledClientDoesNotBlockShutdown2423=== RUN TestServerBacksOffOnAcceptErrors2424=== PAUSE TestServerBacksOffOnAcceptErrors2425=== RUN TestDrainIsolatesPoisonPath2426=== PAUSE TestDrainIsolatesPoisonPath2427=== RUN TestRunNotBlockedByPoisonHead2428=== PAUSE TestRunNotBlockedByPoisonHead2429=== RUN TestDrainGivesUpWhenServerDown2430=== PAUSE TestDrainGivesUpWhenServerDown2431=== RUN TestFailedPathPrunedByLaterClosure2432=== PAUSE TestFailedPathPrunedByLaterClosure2433=== RUN TestWorkerUploadsAndRemoves2434=== PAUSE TestWorkerUploadsAndRemoves2435=== RUN TestWorkerSkipsGCdPaths2436=== PAUSE TestWorkerSkipsGCdPaths2437=== RUN TestWorkerPrunesClosureDeps2438=== PAUSE TestWorkerPrunesClosureDeps2439=== RUN TestDrainTimeout2440=== PAUSE TestDrainTimeout2441=== RUN TestWorkerRemoveFailureIsNotProgress2442=== PAUSE TestWorkerRemoveFailureIsNotProgress2443=== RUN TestWorkerKeepsPathItCannotStat2444=== PAUSE TestWorkerKeepsPathItCannotStat2445=== CONT TestSendPathsEmpty2446=== CONT TestServerBacksOffOnAcceptErrors2447=== CONT TestWorkerUploadsAndRemoves24482026/10/27 08:43:50 ERROR Accept failed error="too many open files"2449--- PASS: TestSendPathsEmpty (0.00s)2450=== CONT TestWorkerKeepsPathItCannotStat2451=== CONT TestWorkerRemoveFailureIsNotProgress2452=== CONT TestServerStalledClientDoesNotBlockShutdown2453=== CONT TestQueueRemoveLargeClosure2454=== CONT TestQueueConcurrentWriters2455=== CONT TestQueueFetchRemoveLifecycle2456=== CONT TestQueueRetryMovesToBack2457=== CONT TestQueueFetchBatchLimit2458=== CONT TestQueueRemove2459=== CONT TestQueueDeduplication2460=== CONT TestQueueEnqueueAndFetch2461=== CONT TestDrainGivesUpWhenServerDown2462=== CONT TestFailedPathPrunedByLaterClosure2463=== CONT TestRunNotBlockedByPoisonHead2464=== CONT TestDrainIsolatesPoisonPath2465=== CONT TestWorkerPrunesClosureDeps24662026/10/27 08:43:50 ERROR Accept failed error="too many open files"2467=== CONT TestDrainTimeout2468=== CONT TestWorkerSkipsGCdPaths24692026/10/27 08:43:50 ERROR Accept failed error="too many open files"24702026/10/27 08:43:50 INFO Uploading batch count=224712026/10/27 08:43:50 ERROR Upload failed error="upload failed" count=224722026/10/27 08:43:50 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3473074932/002/a24732026/10/27 08:43:50 INFO Uploading batch count=424742026/10/27 08:43:50 ERROR Upload failed error="upload failed" count=42475--- PASS: TestQueueRetryMovesToBack (0.02s)24762026/10/27 08:43:50 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath66916495/002/bbb24772026/10/27 08:43:50 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3473074932/002/b24782026/10/27 08:43:50 INFO Upload queue status pending=324792026/10/27 08:43:50 INFO Uploading batch count=224802026/10/27 08:43:50 INFO Uploading batch count=124812026/10/27 08:43:50 ERROR Upload failed error="upload failed" count=124822026/10/27 08:43:50 INFO Uploading batch count=224832026/10/27 08:43:50 ERROR Upload failed error="upload failed" count=224842026/10/27 08:43:50 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3473074932/002/c2485--- PASS: TestQueueRemove (0.02s)24862026/10/27 08:43:50 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3473074932/002/d24872026/10/27 08:43:50 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3122659133/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat3122659133/002/locked/aaa: permission denied"24882026/10/27 08:43:50 INFO Uploading batch count=224892026/10/27 08:43:50 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3122659133/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat3122659133/002/locked/aaa: permission denied"24902026/10/27 08:43:50 ERROR Upload failed error="upload failed" count=224912026/10/27 08:43:50 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3473074932/002/e2492--- PASS: TestQueueFetchBatchLimit (0.02s)2493--- PASS: TestQueueDeduplication (0.02s)2494--- PASS: TestQueueFetchRemoveLifecycle (0.02s)24952026/10/27 08:43:50 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress3510998446/002/nonexistent24962026/10/27 08:43:50 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=124972026/10/27 08:43:50 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress3510998446/002/nonexistent24982026/10/27 08:43:50 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=124992026/10/27 08:43:50 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3473074932/002/f25002026/10/27 08:43:50 INFO Uploading batch count=125012026/10/27 08:43:50 INFO Upload queue status pending=225022026/10/27 08:43:50 INFO Upload queue status pending=225032026/10/27 08:43:50 INFO Uploading batch count=225042026/10/27 08:43:50 INFO Uploading batch count=125052026/10/27 08:43:50 ERROR Upload failed error="upload failed" count=125062026/10/27 08:43:50 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress3510998446/002/nonexistent2507--- PASS: TestQueueEnqueueAndFetch (0.02s)25082026/10/27 08:43:50 ERROR Drain finished with paths left in queue remaining=1025092026/10/27 08:43:50 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125102026/10/27 08:43:50 ERROR Drain finished with paths left in queue remaining=125112026/10/27 08:43:50 INFO Uploading batch count=125122026/10/27 08:43:50 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3122659133/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat3122659133/002/locked/aaa: permission denied"2513--- PASS: TestWorkerRemoveFailureIsNotProgress (0.03s)25142026/10/27 08:43:50 ERROR Drain finished with paths left in queue remaining=125152026/10/27 08:43:50 INFO Upload queue status pending=225162026/10/27 08:43:50 INFO Uploading batch count=125172026/10/27 08:43:50 ERROR Upload failed error="upload failed" count=125182026/10/27 08:43:50 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths877496073/002/nonexistent25192026/10/27 08:43:50 INFO Uploading batch count=12520--- PASS: TestDrainGivesUpWhenServerDown (0.03s)25212026/10/27 08:43:50 INFO Uploading batch count=125222026/10/27 08:43:50 INFO Uploading batch count=125232026/10/27 08:43:50 ERROR Upload failed error="upload failed" count=12524--- PASS: TestWorkerKeepsPathItCannotStat (0.03s)25252026/10/27 08:43:50 INFO Uploading batch count=125262026/10/27 08:43:50 ERROR Upload failed error="upload failed" count=125272026/10/27 08:43:50 ERROR Drain finished with paths left in queue remaining=12528--- PASS: TestFailedPathPrunedByLaterClosure (0.03s)2529--- PASS: TestDrainIsolatesPoisonPath (0.03s)25302026/10/27 08:43:50 ERROR Accept failed error="too many open files"2531--- PASS: TestWorkerUploadsAndRemoves (0.04s)2532--- PASS: TestWorkerPrunesClosureDeps (0.04s)2533--- PASS: TestWorkerSkipsGCdPaths (0.04s)25342026/10/27 08:43:50 ERROR Accept failed error="too many open files"2535--- PASS: TestQueueRemoveLargeClosure (0.12s)25362026/10/27 08:43:50 ERROR Accept failed error="too many open files"25372026/10/27 08:43:50 ERROR Failed to decode request error="read unix /build/hook1082459481/test.sock->@: i/o timeout"25382026/10/27 08:43:50 ERROR Failed to write response error="write unix /build/hook1082459481/test.sock->@: i/o timeout"2539--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)25402026/10/27 08:43:50 ERROR Upload failed error="context deadline exceeded" count=225412026/10/27 08:43:50 ERROR Drain finished with paths left in queue remaining=42542--- PASS: TestQueueConcurrentWriters (0.22s)2543--- PASS: TestDrainTimeout (0.22s)25442026/10/27 08:43:50 ERROR Accept failed error="too many open files"25452026/10/27 08:43:51 ERROR Accept failed error="too many open files"2546--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)25472026/10/27 08:43:51 INFO Uploading batch count=125482026/10/27 08:43:51 INFO Uploading batch count=125492026/10/27 08:43:51 INFO Uploading batch count=125502026/10/27 08:43:51 ERROR Upload failed error="upload failed" count=125512026/10/27 08:43:51 INFO Uploading batch count=125522026/10/27 08:43:51 ERROR Upload failed error="upload failed" count=125532026/10/27 08:43:51 INFO Uploading batch count=125542026/10/27 08:43:51 ERROR Upload failed error="upload failed" count=125552026/10/27 08:43:51 INFO Uploading batch count=125562026/10/27 08:43:51 ERROR Upload failed error="upload failed" count=125572026/10/27 08:43:51 ERROR Drain finished with paths left in queue remaining=12558--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2559PASS2560Running signing tests...2561=== RUN TestExternalSigner2562=== PAUSE TestExternalSigner2563=== RUN TestExternalSignerWrongPublicKey2564=== PAUSE TestExternalSignerWrongPublicKey2565=== RUN TestExternalSignerErrors2566=== PAUSE TestExternalSignerErrors2567=== RUN TestExternalSignerRestartsAfterCrash2568=== PAUSE TestExternalSignerRestartsAfterCrash2569=== RUN TestExternalSignerProgramErrorKeepsProcess2570=== PAUSE TestExternalSignerProgramErrorKeepsProcess2571=== RUN TestExternalSignerClose2572=== PAUSE TestExternalSignerClose2573=== RUN TestExternalSignerRejectsInvalidPublicKey2574=== PAUSE TestExternalSignerRejectsInvalidPublicKey2575=== RUN TestExternalSignerCancellation2576=== PAUSE TestExternalSignerCancellation2577=== RUN TestGenerateFingerprint2578=== PAUSE TestGenerateFingerprint2579=== RUN TestParseSigningKey2580=== PAUSE TestParseSigningKey2581=== RUN TestSign2582=== PAUSE TestSign2583=== RUN TestSignBatch2584=== PAUSE TestSignBatch2585=== RUN TestNilKeyPublicKey2586=== PAUSE TestNilKeyPublicKey2587=== RUN TestSignErrors2588=== PAUSE TestSignErrors2589=== CONT TestExternalSigner2590=== CONT TestSignBatch2591=== CONT TestExternalSignerCancellation2592=== CONT TestSignErrors2593=== CONT TestSign2594=== CONT TestParseSigningKey2595=== CONT TestNilKeyPublicKey2596--- PASS: TestNilKeyPublicKey (0.00s)2597=== RUN TestParseSigningKey/valid_32-byte_key2598=== PAUSE TestParseSigningKey/valid_32-byte_key2599=== CONT TestExternalSignerProgramErrorKeepsProcess2600=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2601=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2602=== RUN TestParseSigningKey/no_colon2603=== PAUSE TestParseSigningKey/no_colon2604=== RUN TestParseSigningKey/empty_name2605=== PAUSE TestParseSigningKey/empty_name2606=== RUN TestParseSigningKey/invalid_base642607=== PAUSE TestParseSigningKey/invalid_base642608=== RUN TestParseSigningKey/wrong_length2609=== PAUSE TestParseSigningKey/wrong_length2610=== CONT TestExternalSignerRejectsInvalidPublicKey2611=== RUN TestExternalSignerRejectsInvalidPublicKey/#002612=== CONT TestExternalSignerClose2613=== CONT TestExternalSignerErrors2614=== RUN TestExternalSignerErrors/exit_on_request2615=== PAUSE TestExternalSignerErrors/exit_on_request2616=== RUN TestExternalSignerErrors/invalid_JSON2617=== PAUSE TestExternalSignerErrors/invalid_JSON2618=== RUN TestExternalSignerErrors/wrong_id2619=== PAUSE TestExternalSignerErrors/wrong_id2620=== CONT TestExternalSignerRestartsAfterCrash2621=== CONT TestExternalSignerWrongPublicKey2622=== CONT TestGenerateFingerprint2623=== CONT TestParseSigningKey/valid_32-byte_key2624=== CONT TestParseSigningKey/wrong_length2625=== CONT TestParseSigningKey/invalid_base642626=== CONT TestParseSigningKey/empty_name2627=== CONT TestParseSigningKey/no_colon2628=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2629=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002630=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2631=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2632=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2633=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2634=== RUN TestGenerateFingerprint/basic_with_references2635=== RUN TestExternalSignerErrors/wrong_signatures_shape2636=== PAUSE TestGenerateFingerprint/basic_with_references2637=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2638=== RUN TestGenerateFingerprint/no_references2639=== PAUSE TestGenerateFingerprint/no_references2640=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2641=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2642=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2643=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2644=== RUN TestExternalSignerErrors/unrequested_key2645=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2646=== PAUSE TestExternalSignerErrors/unrequested_key2647=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2648=== CONT TestExternalSignerRejectsInvalidPublicKey/#002649=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2650=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2651=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2652=== RUN TestExternalSignerErrors/program_error2653=== PAUSE TestExternalSignerErrors/program_error2654=== RUN TestExternalSignerErrors/wrong_shape2655=== RUN TestGenerateFingerprint/invalid_nar_hash_length2656=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2657=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2658=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2659=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2660--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2661 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2662 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2663 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2664 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2665 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2666=== PAUSE TestExternalSignerErrors/wrong_shape2667=== RUN TestExternalSignerErrors/null2668=== PAUSE TestExternalSignerErrors/null2669=== RUN TestGenerateFingerprint/invalid_store_path_prefix2670=== RUN TestExternalSignerErrors/missing_signatures2671=== PAUSE TestExternalSignerErrors/missing_signatures2672=== RUN TestExternalSignerErrors/null_signatures2673=== PAUSE TestExternalSignerErrors/null_signatures2674=== RUN TestExternalSignerErrors/missing_signature_name2675=== PAUSE TestExternalSignerErrors/missing_signature_name2676=== RUN TestExternalSignerErrors/wrong_signature_name2677=== PAUSE TestExternalSignerErrors/wrong_signature_name2678=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2679=== RUN TestGenerateFingerprint/invalid_reference_prefix2680=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2681=== CONT TestGenerateFingerprint/basic_with_references2682=== RUN TestSignErrors/nil_key2683=== PAUSE TestSignErrors/nil_key2684=== RUN TestSignErrors/nil_narinfo2685=== CONT TestGenerateFingerprint/invalid_reference_prefix2686--- PASS: TestParseSigningKey (0.00s)2687 --- PASS: TestParseSigningKey/wrong_length (0.00s)2688 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2689 --- PASS: TestParseSigningKey/empty_name (0.00s)2690 --- PASS: TestParseSigningKey/no_colon (0.00s)2691 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2692 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2693--- PASS: TestSign (0.00s)2694=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2695=== CONT TestGenerateFingerprint/invalid_store_path_prefix2696=== PAUSE TestSignErrors/nil_narinfo2697=== CONT TestGenerateFingerprint/invalid_nar_hash_length2698=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2699=== RUN TestExternalSignerErrors/invalid_signature_base642700=== PAUSE TestExternalSignerErrors/invalid_signature_base642701=== CONT TestGenerateFingerprint/no_references2702--- PASS: TestGenerateFingerprint (0.00s)2703 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2704 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2705 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2706 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2707 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2708 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2709 --- PASS: TestGenerateFingerprint/no_references (0.00s)2710=== RUN TestSignErrors/invalid_narinfo2711=== PAUSE TestSignErrors/invalid_narinfo2712=== RUN TestSignErrors/canceled2713=== PAUSE TestSignErrors/canceled2714=== CONT TestSignErrors/nil_key2715=== CONT TestSignErrors/canceled2716=== RUN TestExternalSignerErrors/wrong_signature_length2717=== PAUSE TestExternalSignerErrors/wrong_signature_length2718--- PASS: TestSignBatch (0.00s)2719=== CONT TestSignErrors/invalid_narinfo2720=== RUN TestExternalSignerErrors/exit_at_startup2721=== PAUSE TestExternalSignerErrors/exit_at_startup2722=== RUN TestExternalSignerErrors/too_few_signatures2723=== PAUSE TestExternalSignerErrors/too_few_signatures2724=== CONT TestSignErrors/nil_narinfo2725=== CONT TestExternalSignerErrors/wrong_signature_name2726--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2727=== CONT TestExternalSignerErrors/exit_on_request2728=== CONT TestExternalSignerErrors/null2729=== CONT TestExternalSignerErrors/missing_signatures2730=== CONT TestExternalSignerErrors/wrong_shape2731=== CONT TestExternalSignerErrors/too_few_signatures2732=== CONT TestExternalSignerErrors/program_error2733=== CONT TestExternalSignerErrors/unrequested_key2734=== CONT TestExternalSignerErrors/exit_at_startup2735=== CONT TestExternalSignerErrors/wrong_signatures_shape2736=== CONT TestExternalSignerErrors/wrong_signature_length2737=== CONT TestExternalSignerErrors/wrong_id2738=== CONT TestExternalSignerErrors/invalid_signature_base642739=== CONT TestExternalSignerErrors/invalid_JSON2740=== CONT TestExternalSignerErrors/null_signatures2741=== CONT TestExternalSignerErrors/missing_signature_name2742--- PASS: TestSignErrors (0.00s)2743 --- PASS: TestSignErrors/nil_key (0.00s)2744 --- PASS: TestSignErrors/canceled (0.00s)2745 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2746 --- PASS: TestSignErrors/nil_narinfo (0.00s)2747--- PASS: TestExternalSignerWrongPublicKey (0.00s)2748--- PASS: TestExternalSignerClose (0.01s)2749--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2750--- PASS: TestExternalSigner (0.01s)2751--- PASS: TestExternalSignerErrors (0.00s)2752 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.00s)2753 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2754 --- PASS: TestExternalSignerErrors/null (0.01s)2755 --- PASS: TestExternalSignerErrors/program_error (0.01s)2756 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2757 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2758 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2759 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2760 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2761 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)2762 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2763 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2764 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2765 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2766 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2767 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2768--- PASS: TestExternalSignerCancellation (0.02s)2769PASS2770Running OpenBao signer tests...2771=== RUN TestSign2772=== PAUSE TestSign2773=== RUN TestSignErrors2774=== PAUSE TestSignErrors2775=== RUN TestServe2776=== PAUSE TestServe2777=== RUN TestServeRejectsGarbage2778=== PAUSE TestServeRejectsGarbage2779=== CONT TestSign2780=== CONT TestSignErrors2781=== CONT TestServe2782=== RUN TestSignErrors/invalid_json2783=== PAUSE TestSignErrors/invalid_json2784=== RUN TestSignErrors/no_prefix2785=== PAUSE TestSignErrors/no_prefix2786=== RUN TestSignErrors/invalid_base642787=== PAUSE TestSignErrors/invalid_base642788=== RUN TestSignErrors/http_error2789=== PAUSE TestSignErrors/http_error2790=== CONT TestSignErrors/invalid_json2791=== CONT TestServeRejectsGarbage2792=== CONT TestSignErrors/invalid_base642793=== CONT TestSignErrors/http_error2794=== CONT TestSignErrors/no_prefix2795--- PASS: TestServeRejectsGarbage (0.00s)2796--- PASS: TestServe (0.00s)2797--- PASS: TestSign (0.40s)2798--- PASS: TestSignErrors (0.00s)2799 --- PASS: TestSignErrors/http_error (0.40s)2800 --- PASS: TestSignErrors/no_prefix (0.40s)2801 --- PASS: TestSignErrors/invalid_base64 (0.40s)2802 --- PASS: TestSignErrors/invalid_json (0.40s)2803PASS

succeeded niks3-go-unit-tests checks.aarch64-linux.go-unit-tests · build #441 · raw

succeeded `niks3-go-unit-tests` `checks.aarch64-linux.go-unit-tests` · build #441 · raw