niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #405
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica8=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica9=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun10=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun11=== RUN TestCaseHackSuffix12=== PAUSE TestCaseHackSuffix13=== RUN TestFilterOversizedClosures14=== PAUSE TestFilterOversizedClosures15=== RUN TestUploadMultipart_PartsInParallel16=== PAUSE TestUploadMultipart_PartsInParallel17=== RUN TestPartSizeForNAR18=== PAUSE TestPartSizeForNAR19=== RUN TestUploadMultipart_SupersededByPeer20=== PAUSE TestUploadMultipart_SupersededByPeer21=== RUN TestDumpPathCaseHackMatchesNix22--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestSupersededNARStillUploadsListing26=== PAUSE TestSupersededNARStillUploadsListing27=== RUN TestDumpPathMatchesNix28=== PAUSE TestDumpPathMatchesNix29=== RUN TestDumpPathSingleFile30=== PAUSE TestDumpPathSingleFile31=== RUN TestDumpPathWriterError32=== PAUSE TestDumpPathWriterError33=== RUN TestEncodeNixBase3234=== PAUSE TestEncodeNixBase3235=== RUN TestEncodeNixBase32WithRealHash36=== PAUSE TestEncodeNixBase32WithRealHash37=== RUN TestConvertHashToNix3238=== PAUSE TestConvertHashToNix3239=== RUN TestGetStorePathHash40=== PAUSE TestGetStorePathHash41=== RUN TestPathInfoHashCompatibility42=== PAUSE TestPathInfoHashCompatibility43=== RUN TestParsePathInfoJSON44=== PAUSE TestParsePathInfoJSON45=== RUN TestParsePathInfoJSONMultiplePaths46=== PAUSE TestParsePathInfoJSONMultiplePaths47=== RUN TestPathInfoCACompatibility48=== PAUSE TestPathInfoCACompatibility49=== RUN TestRateLimiterFeedback50=== PAUSE TestRateLimiterFeedback51=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess52=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess53=== RUN TestResolveStorePath54=== PAUSE TestResolveStorePath55=== RUN TestDoWithRetry_BodyReplayedViaGetBody56=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody57=== RUN TestRetryTimeoutOutlastsMaxRetries58=== PAUSE TestRetryTimeoutOutlastsMaxRetries59=== RUN TestShellSplit60=== PAUSE TestShellSplit61=== RUN TestShellSplitErrors62=== PAUSE TestShellSplitErrors63=== RUN TestStreamPushReportsEveryPath64=== PAUSE TestStreamPushReportsEveryPath65=== RUN TestStreamPushBatchesUnderLoad66=== PAUSE TestStreamPushBatchesUnderLoad67=== RUN TestStreamPushIsolatesFailures68=== PAUSE TestStreamPushIsolatesFailures69=== RUN TestStreamPushGivesUpOnDeadServer70=== PAUSE TestStreamPushGivesUpOnDeadServer71=== RUN TestStreamPushRequestLine72=== PAUSE TestStreamPushRequestLine73=== RUN TestStreamPushReportsSignatures74=== PAUSE TestStreamPushReportsSignatures75=== RUN TestStreamPushReportsSkippedPaths76=== PAUSE TestStreamPushReportsSkippedPaths77=== RUN TestClientSignaturesByStorePath78=== PAUSE TestClientSignaturesByStorePath79=== RUN TestStreamPushStopsWhenCanceled80=== PAUSE TestStreamPushStopsWhenCanceled81=== RUN TestSetClientTLS82=== PAUSE TestSetClientTLS83=== RUN TestSetClientTLSDoesNotMutateDefaultTransport84=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport85=== RUN TestSetClientTLSErrors86=== PAUSE TestSetClientTLSErrors87=== RUN TestStaticToken88=== PAUSE TestStaticToken89=== RUN TestFileTokenReadsAndCaches90=== PAUSE TestFileTokenReadsAndCaches91=== RUN TestFileTokenMissing92=== PAUSE TestFileTokenMissing93=== RUN TestFileTokenEmpty94=== PAUSE TestFileTokenEmpty95=== RUN TestScriptTokenNoExpiryRerunsEveryCall96=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall97=== RUN TestScriptTokenCachesUntilRefresh98=== PAUSE TestScriptTokenCachesUntilRefresh99=== RUN TestScriptTokenEmptyToken100=== PAUSE TestScriptTokenEmptyToken101=== RUN TestScriptTokenBadJSON102=== PAUSE TestScriptTokenBadJSON103=== RUN TestScriptTokenScriptFails104=== PAUSE TestScriptTokenScriptFails105=== RUN TestScriptTokenEmptyCommand106=== PAUSE TestScriptTokenEmptyCommand107=== CONT TestDoServerRequestAttachesToken108=== CONT TestScriptTokenScriptFails109=== CONT TestScriptTokenEmptyCommand110--- PASS: TestScriptTokenEmptyCommand (0.00s)111=== CONT TestStreamPushReportsEveryPath112=== CONT TestStreamPushStopsWhenCanceled113=== CONT TestScriptTokenBadJSON114--- PASS: TestStreamPushStopsWhenCanceled (0.00s)115=== CONT TestShellSplitErrors116--- PASS: TestShellSplitErrors (0.00s)117=== CONT TestRateLimiterFeedback118=== RUN TestRateLimiterFeedback/429_enables_limiter119=== PAUSE TestRateLimiterFeedback/429_enables_limiter120=== RUN TestRateLimiterFeedback/503_enables_limiter121=== PAUSE TestRateLimiterFeedback/503_enables_limiter122=== CONT TestScriptTokenEmptyToken123=== CONT TestScriptTokenCachesUntilRefresh124=== CONT TestScriptTokenNoExpiryRerunsEveryCall125=== CONT TestFileTokenEmpty126=== CONT TestDoWithRetry_BodyReplayedViaGetBody127=== CONT TestFileTokenMissing128=== CONT TestClientSignaturesByStorePath129=== CONT TestFileTokenReadsAndCaches130=== CONT TestStreamPushReportsSkippedPaths131=== CONT TestStaticToken132=== CONT TestStreamPushReportsSignatures133=== CONT TestSetClientTLS134=== CONT TestStreamPushRequestLine135=== CONT TestStreamPushGivesUpOnDeadServer136=== CONT TestDumpPathWriterError137=== CONT TestStreamPushIsolatesFailures138=== CONT TestResolveStorePath139=== CONT TestStreamPushBatchesUnderLoad140=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess141=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter142=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter143=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter144=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter145--- PASS: TestFileTokenMissing (0.00s)146--- PASS: TestScriptTokenScriptFails (0.00s)147=== CONT TestRetryTimeoutOutlastsMaxRetries148--- PASS: TestStaticToken (0.00s)149=== CONT TestParsePathInfoJSONMultiplePaths150=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths151=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths152=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths153--- PASS: TestFileTokenEmpty (0.00s)154=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths155=== CONT TestSetClientTLSErrors156--- PASS: TestStreamPushReportsSkippedPaths (0.00s)157=== CONT TestConvertHashToNix32158=== RUN TestConvertHashToNix32/SRI_format_to_Nix321592026/10/10 19:00:44 ERROR Upload failed error=boom count=11602026/10/10 19:00:44 ERROR Upload failed error="bad path" count=31612026/10/10 19:00:44 WARN Rate limiter enabled after throttle name=server-test rate=5162=== CONT TestShellSplit163=== CONT TestPathInfoHashCompatibility164=== CONT TestParsePathInfoJSON165--- PASS: TestClientSignaturesByStorePath (0.00s)166--- PASS: TestShellSplit (0.00s)167=== CONT TestEncodeNixBase32WithRealHash168=== RUN TestParsePathInfoJSON/Nix_format169=== CONT TestGetStorePathHash170=== PAUSE TestParsePathInfoJSON/Nix_format171=== RUN TestParsePathInfoJSON/Lix_format172--- PASS: TestStreamPushReportsEveryPath (0.01s)173--- PASS: TestEncodeNixBase32WithRealHash (0.00s)1742026/10/10 19:00:44 ERROR Upload failed error=boom count=1175=== RUN TestGetStorePathHash/valid_store_path176=== CONT TestPathInfoCACompatibility177=== RUN TestPathInfoCACompatibility/null_ca_field178=== PAUSE TestGetStorePathHash/valid_store_path179=== PAUSE TestPathInfoCACompatibility/null_ca_field180=== RUN TestGetStorePathHash/basename_without_hyphen_should_error181=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error182=== CONT TestEncodeNixBase32183=== CONT TestSupersededNARStillUploadsListing184=== CONT TestUploadMultipart_SupersededByPeer185=== RUN TestSupersededNARStillUploadsListing/small_NAR186=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)187--- PASS: TestFileTokenReadsAndCaches (0.00s)188--- PASS: TestStreamPushIsolatesFailures (0.00s)1892026/10/10 19:00:44 ERROR Upload failed error="connection refused" count=201902026/10/10 19:00:44 ERROR Server seems unavailable, giving up on batch untried=171912026/10/10 19:00:44 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:40359192=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32193=== CONT TestUploadMultipart_PartsInParallel194=== RUN TestPathInfoCACompatibility/old_string_format_-_text195=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text196=== PAUSE TestParsePathInfoJSON/Lix_format197=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error198=== RUN TestUploadMultipart_SupersededByPeer/exists199=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica200--- PASS: TestResolveStorePath (0.00s)2012026/10/10 19:00:44 WARN Rate limiter enabled after throttle name=server-test rate=5202--- PASS: TestStreamPushReportsSignatures (0.00s)203=== RUN TestSetClientTLSErrors/missing_cert_file204=== CONT TestDumpPathMatchesNix205=== CONT TestPartSizeForNAR206=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)207=== CONT TestDumpPathSingleFile208=== RUN TestEncodeNixBase32/test_string_hash209=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun210=== RUN TestConvertHashToNix32/already_Nix32_format211=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive212=== RUN TestParsePathInfoJSON/empty_input213=== PAUSE TestUploadMultipart_SupersededByPeer/exists214=== RUN TestUploadMultipart_SupersededByPeer/missing215=== PAUSE TestSupersededNARStillUploadsListing/small_NAR216--- PASS: TestScriptTokenEmptyToken (0.01s)217=== PAUSE TestSetClientTLSErrors/missing_cert_file218=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon219=== RUN TestPartSizeForNAR/zero_stays_at_minimum220=== PAUSE TestUploadMultipart_SupersededByPeer/missing221=== PAUSE TestParsePathInfoJSON/empty_input222=== PAUSE TestEncodeNixBase32/test_string_hash223=== PAUSE TestConvertHashToNix32/already_Nix32_format224=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon2252026/10/10 19:00:44 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:33925226=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error227=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error228=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error229=== RUN TestConvertHashToNix32/invalid_format230--- PASS: TestScriptTokenBadJSON (0.01s)231--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)232--- PASS: TestDoServerRequestAttachesToken (0.01s)233=== CONT TestFilterOversizedClosures234=== RUN TestFilterOversizedClosures/no_limit_keeps_everything2352026/10/10 19:00:44 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:40359236=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive237=== RUN TestSupersededNARStillUploadsListing/dump_cut_short238=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum239=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short240=== RUN TestParsePathInfoJSON/whitespace_only241=== RUN TestPartSizeForNAR/small_stays_at_minimum242=== PAUSE TestPartSizeForNAR/small_stays_at_minimum243=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum244=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum245--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)246=== RUN TestEncodeNixBase32/empty_input247=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts2482026/10/10 19:00:44 WARN Rate limiter backed off name=server-test rate=5249=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts2502026/10/10 19:00:44 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:33925251=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI252=== RUN TestPartSizeForNAR/1_TiB2532026/10/10 19:00:44 INFO Garbage collection started254=== PAUSE TestPartSizeForNAR/1_TiB255=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI256=== RUN TestPartSizeForNAR/5_TiB_S3_max_object257=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object258=== RUN TestPartSizeForNAR/capped_at_5_GiB259=== PAUSE TestConvertHashToNix32/invalid_format260=== RUN TestSetClientTLS/rejects_connection_without_client_cert261=== CONT TestRateLimiterFeedback/429_enables_limiter262=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter2632026/10/10 19:00:44 INFO Garbage collection started264=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert265=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA266=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA267=== RUN TestSetClientTLS/preserves_debug_logging_transport268=== PAUSE TestSetClientTLS/preserves_debug_logging_transport269=== RUN TestSetClientTLSErrors/missing_key_file270=== PAUSE TestSetClientTLSErrors/missing_key_file271=== RUN TestSetClientTLSErrors/missing_ca_file272=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter273=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails274=== PAUSE TestParsePathInfoJSON/whitespace_only275=== CONT TestRegisterUploadedObjectReusesConnections276=== RUN TestParsePathInfoJSON/invalid_JSON277=== PAUSE TestParsePathInfoJSON/invalid_JSON278=== CONT TestRateLimiterFeedback/503_enables_limiter2792026/10/10 19:00:44 WARN Rate limiter enabled after throttle name=server-test rate=52802026/10/10 19:00:44 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:43665281=== PAUSE TestEncodeNixBase32/empty_input2822026/10/10 19:00:44 WARN Rate limiter backed off name=server-test rate=5283=== CONT TestCaseHackSuffix284=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths285=== CONT TestUploadMultipart_SupersededByPeer/exists286=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths287=== CONT TestUploadMultipart_SupersededByPeer/missing288=== CONT TestGetStorePathHash/valid_store_path2892026/10/10 19:00:44 WARN Rate limiter enabled after throttle name=server-test rate=5290=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error2912026/10/10 19:00:44 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:33341292--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)293=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512294=== PAUSE TestPartSizeForNAR/capped_at_5_GiB295=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything296=== RUN TestPathInfoCACompatibility/new_structured_format_-_text297=== PAUSE TestSetClientTLSErrors/missing_ca_file298=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails2992026/10/10 19:00:44 WARN Rate limiter backed off name=server-test rate=5300=== CONT TestSetClientTLSDoesNotMutateDefaultTransport301=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped302=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped303=== RUN TestFilterOversizedClosures/all_closures_skipped304=== PAUSE TestFilterOversizedClosures/all_closures_skipped305=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text306=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method307=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method308=== RUN TestSetClientTLSErrors/invalid_ca_file309=== PAUSE TestSetClientTLSErrors/invalid_ca_file310=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error311=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA3122026/10/10 19:00:44 INFO Garbage collection progress phase=running_on_another_replica failed_uploads_deleted=0 old_closures_deleted=0 objects_marked=0 objects_deleted=0 objects_failed=0313=== CONT TestParsePathInfoJSON/Nix_format314=== CONT TestParsePathInfoJSON/whitespace_only315=== CONT TestParsePathInfoJSON/invalid_JSON316=== CONT TestParsePathInfoJSON/empty_input317=== CONT TestParsePathInfoJSON/Lix_format318=== CONT TestEncodeNixBase32/test_string_hash319=== CONT TestEncodeNixBase32/empty_input320=== CONT TestSupersededNARStillUploadsListing/small_NAR321=== CONT TestConvertHashToNix32/already_Nix32_format322=== CONT TestPartSizeForNAR/zero_stays_at_minimum323=== CONT TestSetClientTLS/rejects_connection_without_client_cert324=== CONT TestSetClientTLSErrors/missing_cert_file3252026/10/10 19:00:44 INFO Uploading abc-hello (1.0GB)326=== CONT TestFilterOversizedClosures/all_closures_skipped327=== CONT TestSetClientTLS/preserves_debug_logging_transport3282026/10/10 19:00:44 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50329=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3302026/10/10 19:00:44 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000331=== CONT TestGetStorePathHash/basename_without_hyphen_should_error332=== CONT TestSupersededNARStillUploadsListing/dump_cut_short333=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails334=== CONT TestConvertHashToNix32/invalid_format335=== CONT TestFilterOversizedClosures/no_limit_keeps_everything336--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)337=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512338--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)339=== CONT TestConvertHashToNix32/SRI_format_to_Nix32340=== CONT TestPathInfoCACompatibility/null_ca_field341=== CONT TestPartSizeForNAR/capped_at_5_GiB342--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)343--- PASS: TestGetStorePathHash (0.03s)344 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)345 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)346 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)347 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)3482026/10/10 19:00:44 INFO Uploading abc-hello (1.0GB)349--- PASS: TestParsePathInfoJSON (0.03s)350 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)351 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)352 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)353 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)354 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)355=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts356=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum357=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method358=== CONT TestPartSizeForNAR/small_stays_at_minimum3592026/10/10 19:00:44 WARN Garbage collection finished on another replica. Its statistics are not available here360=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive361=== CONT TestPathInfoCACompatibility/old_string_format_-_text362--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.04s)363=== CONT TestSetClientTLSErrors/invalid_ca_file364=== CONT TestSetClientTLSErrors/missing_key_file365=== CONT TestSetClientTLSErrors/missing_ca_file366=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)367=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI368=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512369=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon370--- PASS: TestPathInfoHashCompatibility (0.04s)371 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)372 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)373 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)374 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)375=== CONT TestPartSizeForNAR/1_TiB376=== CONT TestPathInfoCACompatibility/new_structured_format_-_text377--- PASS: TestPathInfoCACompatibility (0.03s)378 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)379 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)380 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)381 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)382 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)383--- PASS: TestSetClientTLSErrors (0.04s)384 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)385 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)386 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)387 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)388--- PASS: TestDumpPathSingleFile (0.26s)389--- PASS: TestFilterOversizedClosures (0.00s)390 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)391 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)392 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)393--- PASS: TestParsePathInfoJSONMultiplePaths (0.26s)394 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)395 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)396=== CONT TestPartSizeForNAR/5_TiB_S3_max_object397--- PASS: TestPartSizeForNAR (0.03s)398 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)399 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)400 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)401 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)402 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)403 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)404 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)4052026/10/10 19:00:44 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:40359406--- PASS: TestEncodeNixBase32 (0.29s)407 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)408 --- PASS: TestEncodeNixBase32/empty_input (0.00s)409--- PASS: TestRateLimiterFeedback (0.26s)410 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)411 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)412 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)413 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)414--- PASS: TestConvertHashToNix32 (0.04s)415 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)416 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)417 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)4182026/10/10 19:00:44 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:40359419--- PASS: TestUploadMultipart_SupersededByPeer (0.03s)420 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)421 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.27s)4222026/10/10 19:00:44 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:403594232026/10/10 19:00:44 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:40359424--- PASS: TestCaseHackSuffix (0.27s)4252026/10/10 19:00:44 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:403594262026/10/10 19:00:44 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:403594272026/10/10 19:00:44 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:403594282026/10/10 19:00:44 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:403594292026/10/10 19:00:44 http: TLS handshake error from 127.0.0.1:35092: remote error: tls: bad certificate430--- PASS: TestStreamPushRequestLine (0.31s)431--- PASS: TestSetClientTLS (0.03s)432 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.26s)433 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.27s)434 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.27s)4352026/10/10 19:00:44 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:403594362026/10/10 19:00:44 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:403594372026/10/10 19:00:44 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:40359438--- PASS: TestRegisterUploadedObjectReusesConnections (0.28s)4392026/10/10 19:00:44 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:403594402026/10/10 19:00:44 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:403594412026/10/10 19:00:44 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:40359442--- PASS: TestDumpPathWriterError (0.32s)4432026/10/10 19:00:44 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:403594442026/10/10 19:00:44 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:403594452026/10/10 19:00:44 INFO Uploading abc-hello (1.0GB)4462026/10/10 19:00:44 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:40359447--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.32s)448--- PASS: TestStreamPushBatchesUnderLoad (0.34s)4492026/10/10 19:00:44 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:37507/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:37507/part/24502026/10/10 19:00:44 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"451--- PASS: TestDumpPathMatchesNix (0.33s)452--- PASS: TestSupersededNARStillUploadsListing (0.03s)453 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.27s)454 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.26s)455 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.80s)456--- PASS: TestUploadMultipart_PartsInParallel (0.90s)457--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)458PASS459Running server tests...460The files belonging to this database system will be owned by user "nixbld".461This user must also own the server process.462463The database cluster will be initialized with locale "C".464The default database encoding has accordingly been set to "SQL_ASCII".465The default text search configuration will be set to "english".466467Data page checksums are enabled.468469creating directory /build/postgres4172550390/data ... ok470creating subdirectories ... ok471selecting dynamic shared memory implementation ... posix472selecting default "max_connections" ... 100473selecting default "shared_buffers" ... 128MB474selecting default time zone ... UTC475creating configuration files ... ok476running bootstrap script ... ok477performing post-bootstrap initialization ... ok478syncing data to disk ... ok479480initdb: warning: enabling "trust" authentication for local connections481initdb: 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.482483Success. You can now start the database server using:484485 pg_ctl -D /build/postgres4172550390/data -l logfile start486487/build/postgres4172550390:5432 - no response4882026-10-10 19:00:46.088 UTC [130] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4892026-10-10 19:00:46.088 UTC [130] LOG: listening on Unix socket "/build/postgres4172550390/.s.PGSQL.5432"4902026-10-10 19:00:46.092 UTC [137] LOG: database system was shut down at 2026-10-10 19:00:45 UTC4912026-10-10 19:00:46.096 UTC [130] LOG: database system is ready to accept connections492/build/postgres4172550390:5432 - accepting connections493{"timestamp":"2026-10-10T19:00:46.390569329Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"96557510-8d50-461a-8634-2a048eee8e7d","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":1,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(204)"}494=== RUN TestService_AuthMiddleware495=== PAUSE TestService_AuthMiddleware496=== RUN TestService_AuthMiddleware_MTLSProxyHeader497=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader498=== RUN TestService_AuthMiddleware_MTLSBoundSubjects499=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects500=== RUN TestService_ReadAuthMiddleware501=== PAUSE TestService_ReadAuthMiddleware502=== RUN TestService_AuthMiddleware_OIDC503=== PAUSE TestService_AuthMiddleware_OIDC504=== RUN TestService_RequireScope_OIDC505=== PAUSE TestService_RequireScope_OIDC506=== RUN TestService_ReadScope_PublicByDefault507=== PAUSE TestService_ReadScope_PublicByDefault508=== RUN TestCacheConfigHandler509=== PAUSE TestCacheConfigHandler510=== RUN TestCacheStatsHandler511=== PAUSE TestCacheStatsHandler512=== RUN TestClientCADerivations513=== PAUSE TestClientCADerivations514=== RUN TestClientErrorHandling515=== PAUSE TestClientErrorHandling516=== RUN TestClientIntegration517=== PAUSE TestClientIntegration518=== RUN TestClientMultipleUploads519=== PAUSE TestClientMultipleUploads520=== RUN TestClientWithDependencies521=== PAUSE TestClientWithDependencies522=== RUN TestClientSharedPathCommittedMidPush523=== PAUSE TestClientSharedPathCommittedMidPush524=== RUN TestPinProtectsFromGC525=== PAUSE TestPinProtectsFromGC526=== RUN TestClientPushesUseOnePush527=== PAUSE TestClientPushesUseOnePush528=== RUN TestClientFallsBackToClosures529=== PAUSE TestClientFallsBackToClosures530=== RUN TestDeleteClosuresRacingPins531=== PAUSE TestDeleteClosuresRacingPins532=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock533=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock534=== RUN TestResolveDBConnectionString535=== PAUSE TestResolveDBConnectionString536=== RUN TestConnectWaitsForAPeerMigration537=== PAUSE TestConnectWaitsForAPeerMigration538=== RUN TestLeadElectsOneAndHandsOver539=== PAUSE TestLeadElectsOneAndHandsOver540=== RUN TestLeadIncumbentWinsAfterRestart5412026/10/10 19:00:46 INFO lead: acquired remote=192.0.2.1:12345422026/10/10 19:00:47 INFO lead: released remote=192.0.2.1:12345432026/10/10 19:00:47 INFO lead: acquired remote=192.0.2.1:12345442026/10/10 19:00:48 INFO lead: released remote=192.0.2.1:1234545--- PASS: TestLeadIncumbentWinsAfterRestart (1.84s)546=== RUN TestLeadIncumbentAnnouncesAtOnce547=== PAUSE TestLeadIncumbentAnnouncesAtOnce548=== RUN TestLeadEndsOnShutdown549=== PAUSE TestLeadEndsOnShutdown550=== RUN TestLeadEndsWhenItsConnectionHangs5512026/10/10 19:00:48 INFO lead: acquired remote=192.0.2.1:12345522026-10-10 19:00:49.853 UTC [386] FATAL: terminating connection due to administrator command5532026/10/10 19:00:50 INFO lead: acquired remote=192.0.2.1:12345542026/10/10 19:00:51 WARN lead: lock connection lost error="timeout: context deadline exceeded"5552026/10/10 19:00:51 INFO lead: released remote=192.0.2.1:12345562026/10/10 19:00:51 INFO lead: released remote=192.0.2.1:1234557--- PASS: TestLeadEndsWhenItsConnectionHangs (3.11s)558=== RUN TestGCAdvisoryLockBlocksConcurrentRun559=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun560=== RUN TestGCBugBareHashReferences561=== PAUSE TestGCBugBareHashReferences562=== RUN TestGCMetrics563=== PAUSE TestGCMetrics564=== RUN TestPushDedupSurvivesConcurrentGC565=== PAUSE TestPushDedupSurvivesConcurrentGC566=== RUN TestDeduplicatedObjectsRecordedAsPending567=== PAUSE TestDeduplicatedObjectsRecordedAsPending568=== RUN TestGCSweepSkipsPendingObjects569=== PAUSE TestGCSweepSkipsPendingObjects570=== RUN TestTombstonedObjectOfferedWithoutWaiting571=== PAUSE TestTombstonedObjectOfferedWithoutWaiting572=== RUN TestGCSweepDeliversEachKeyOnce573=== PAUSE TestGCSweepDeliversEachKeyOnce574=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection575=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection576=== RUN TestForceGCDuringPushOffersSweptObject577=== PAUSE TestForceGCDuringPushOffersSweptObject578=== RUN TestFailedS3DeleteKeepsTombstone579=== PAUSE TestFailedS3DeleteKeepsTombstone580=== RUN TestSweepSkipsRowsLockedByPush581=== PAUSE TestSweepSkipsRowsLockedByPush582=== RUN TestRegisterCompletedObjectNeedsPendingRow583=== PAUSE TestRegisterCompletedObjectNeedsPendingRow584=== RUN TestGetExistingObjectsLocksRows585=== PAUSE TestGetExistingObjectsLocksRows586=== RUN TestSweepRechecksPendingAfterLocking587=== PAUSE TestSweepRechecksPendingAfterLocking588=== RUN TestPushWaitsForSweepHoldingRow589=== PAUSE TestPushWaitsForSweepHoldingRow590=== RUN TestCommitRacingPendingCleanupKeepsObjects591=== PAUSE TestCommitRacingPendingCleanupKeepsObjects592=== RUN TestGCEndsOnShutdown593=== PAUSE TestGCEndsOnShutdown594=== RUN TestGCTaskStore_StartNew595=== PAUSE TestGCTaskStore_StartNew596=== RUN TestGCTaskStore_DeduplicateSameParams597=== PAUSE TestGCTaskStore_DeduplicateSameParams598=== RUN TestGCTaskStore_ConflictDifferentParams599=== PAUSE TestGCTaskStore_ConflictDifferentParams600=== RUN TestGCTaskStore_GetEmpty601=== PAUSE TestGCTaskStore_GetEmpty602=== RUN TestGCTaskStore_GetReturnsLatest603=== PAUSE TestGCTaskStore_GetReturnsLatest604=== RUN TestGCTaskStore_CompletedAllowsNewTask605=== PAUSE TestGCTaskStore_CompletedAllowsNewTask606=== RUN TestGCTaskStore_PhaseUpdates607=== PAUSE TestGCTaskStore_PhaseUpdates608=== RUN TestGCTaskStore_Fail609=== PAUSE TestGCTaskStore_Fail610=== RUN TestGracefulShutdownDrainsInflight611=== PAUSE TestGracefulShutdownDrainsInflight612=== RUN TestService_healthCheckHandler613=== PAUSE TestService_healthCheckHandler614=== RUN TestService_readinessHandler615=== PAUSE TestService_readinessHandler616=== RUN TestGenerateLandingPage617=== PAUSE TestGenerateLandingPage618=== RUN TestCacheConfigHandlerMaxNarSize619=== PAUSE TestCacheConfigHandlerMaxNarSize620=== RUN TestCreatePendingClosureRejectsOversizedNAR621=== PAUSE TestCreatePendingClosureRejectsOversizedNAR622=== RUN TestNARDeduplicationMetadataUploadBug623=== PAUSE TestNARDeduplicationMetadataUploadBug624=== RUN TestMetricsInventory625=== PAUSE TestMetricsInventory626=== RUN TestMetricsCommit627=== PAUSE TestMetricsCommit628=== RUN TestService_NativeMTLS629=== PAUSE TestService_NativeMTLS630=== RUN TestServerTLSConfig631=== PAUSE TestServerTLSConfig632=== RUN TestMultipartCleanup633=== PAUSE TestMultipartCleanup634=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded635=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded636=== RUN TestPendingCleanupUsesOneCutoff637=== PAUSE TestPendingCleanupUsesOneCutoff638=== RUN TestObjectStatsTrigger639=== PAUSE TestObjectStatsTrigger640=== RUN TestObjectStatsLargeCommit641=== PAUSE TestObjectStatsLargeCommit642=== RUN TestOrphanedObjectsGC643=== PAUSE TestOrphanedObjectsGC644=== RUN TestOrphanedObjectsGCStressTest645=== PAUSE TestOrphanedObjectsGCStressTest646=== RUN TestCreatePin_ReservedPins647=== PAUSE TestCreatePin_ReservedPins648=== RUN TestPresentReportsOnlyClosureRoots649=== PAUSE TestPresentReportsOnlyClosureRoots650=== RUN TestPresentRefreshesOnlyStaleClosures651=== PAUSE TestPresentRefreshesOnlyStaleClosures652=== RUN TestPresentNotReportedWhileGCDeletesClosure653=== PAUSE TestPresentNotReportedWhileGCDeletesClosure654=== RUN TestParseSingleRange655=== PAUSE TestParseSingleRange656=== RUN TestProxyHeadersOnlyTrustedOnSocket6572026/10/10 19:00:51 INFO Starting HTTP server address=127.0.0.1:374536582026/10/10 19:00:51 INFO Starting HTTP server address=proxy.sock6592026/10/10 19:00:51 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6602026/10/10 19:00:51 INFO Shutdown signal received, draining in-flight requests timeout=10s661--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.10s)662=== RUN TestIsValidCachePath663=== PAUSE TestIsValidCachePath664=== RUN TestReadProxyNarinfo665=== PAUSE TestReadProxyNarinfo666=== RUN TestReadProxyNarinfoAlreadyDecompressed667=== PAUSE TestReadProxyNarinfoAlreadyDecompressed668=== RUN TestReadProxyContentNegotiation669=== PAUSE TestReadProxyContentNegotiation670=== RUN TestReadProxyNarStreaming671=== PAUSE TestReadProxyNarStreaming672=== RUN TestReadProxy404673=== PAUSE TestReadProxy404674=== RUN TestReadProxyInvalidPath675=== PAUSE TestReadProxyInvalidPath676=== RUN TestReadProxyHead677=== PAUSE TestReadProxyHead678=== RUN TestReadProxyOutlastsServerWriteTimeout679=== PAUSE TestReadProxyOutlastsServerWriteTimeout680=== RUN TestReadProxyConditionalGet681=== PAUSE TestReadProxyConditionalGet682=== RUN TestReadProxyRootRedirectsToIndexHTML683=== PAUSE TestReadProxyRootRedirectsToIndexHTML684=== RUN TestReadProxyDisabled685=== PAUSE TestReadProxyDisabled686=== RUN TestReadRedirectNar687=== PAUSE TestReadRedirectNar688=== RUN TestReadRedirectKeepsNarinfoProxied689=== PAUSE TestReadRedirectKeepsNarinfoProxied690=== RUN TestReadProxyRangeRequest691=== PAUSE TestReadProxyRangeRequest692=== RUN TestReadRedirectUsesPublicS3URL693=== PAUSE TestReadRedirectUsesPublicS3URL694=== RUN TestPush_OverlappingRootsStoreOneRowPerKey695=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey696=== RUN TestPush_CompleteCommitsEveryRoot697=== PAUSE TestPush_CompleteCommitsEveryRoot698=== RUN TestPush_RepeatedRootCommitsOnce699=== PAUSE TestPush_RepeatedRootCommitsOnce700=== RUN TestPush_CompleteWaitsForCleanupOfThePush701=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush702=== RUN TestPush_RootsAreLockedInByteOrder703=== PAUSE TestPush_RootsAreLockedInByteOrder704=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit705=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit706=== RUN TestPush_RejectsBadRequests707=== PAUSE TestPush_RejectsBadRequests708=== RUN TestPush_SignsNarinfosOfItsPendingObjects709=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects710=== RUN TestRedundantMultipartUpload711=== PAUSE TestRedundantMultipartUpload712=== RUN TestCompleteMultipartUpload_ErrorButObjectExists713=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists714=== RUN TestCompletedNarNotReofferedAcrossClosures715=== PAUSE TestCompletedNarNotReofferedAcrossClosures716=== RUN TestPresignedUploadRegisteredBeforeCommit717=== PAUSE TestPresignedUploadRegisteredBeforeCommit718=== RUN TestService_Rustfstest719=== PAUSE TestService_Rustfstest720=== RUN TestParseSize721=== PAUSE TestParseSize722=== RUN TestSkippedUploadsHandler723=== PAUSE TestSkippedUploadsHandler724=== RUN TestSystemdListenerNotActivated725--- PASS: TestSystemdListenerNotActivated (0.00s)726=== RUN TestWatchdogBeatsWhenHealthy727--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)728=== RUN TestWatchdogSkipsWhenUnhealthy7292026/10/10 19:00:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7302026/10/10 19:00:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7312026/10/10 19:00:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7322026/10/10 19:00:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7332026/10/10 19:00:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7342026/10/10 19:00:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7352026/10/10 19:00:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7362026/10/10 19:00:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7372026/10/10 19:00:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7382026/10/10 19:00:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"739--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)740=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle741=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle742=== RUN TestProxyWriteTimeout743=== PAUSE TestProxyWriteTimeout744=== RUN TestPendingClosureWriteTimeout745=== PAUSE TestPendingClosureWriteTimeout746=== RUN TestIsValidUploadKey747=== PAUSE TestIsValidUploadKey748=== RUN TestUploadHandlersRejectInvalidKeys749=== PAUSE TestUploadHandlersRejectInvalidKeys750=== RUN TestUploadHandlersRejectOversizedBody751=== PAUSE TestUploadHandlersRejectOversizedBody752=== RUN TestService_cleanupPendingClosuresHandler753=== PAUSE TestService_cleanupPendingClosuresHandler754=== RUN TestService_createPendingClosureHandler755=== PAUSE TestService_createPendingClosureHandler756=== RUN TestService_verifyS3Integrity757=== PAUSE TestService_verifyS3Integrity758=== RUN TestCompleteMultipartUnregistered759=== PAUSE TestCompleteMultipartUnregistered760=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT761=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT762=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle763=== CONT TestRedundantMultipartUpload764=== CONT TestService_cleanupPendingClosuresHandler765=== CONT TestGCTaskStore_PhaseUpdates766=== CONT TestPush_OverlappingRootsStoreOneRowPerKey767=== CONT TestGCAdvisoryLockBlocksConcurrentRun768=== CONT TestIsValidCachePath769=== CONT TestService_AuthMiddleware770--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)771=== CONT TestSkippedUploadsHandler772=== CONT TestParseSize773--- PASS: TestParseSize (0.00s)774=== CONT TestCreatePin_ReservedPins775=== CONT TestService_Rustfstest7762026/10/10 19:00:51 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000777=== CONT TestPresignedUploadRegisteredBeforeCommit778=== CONT TestCompletedNarNotReofferedAcrossClosures779=== CONT TestCompleteMultipartUpload_ErrorButObjectExists780=== CONT TestPush_SignsNarinfosOfItsPendingObjects781=== CONT TestPush_RejectsBadRequests782=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit783=== CONT TestPush_RootsAreLockedInByteOrder784=== CONT TestPush_CompleteWaitsForCleanupOfThePush785=== CONT TestPush_RepeatedRootCommitsOnce786=== CONT TestPush_CompleteCommitsEveryRoot787=== CONT TestParseSingleRange788=== RUN TestParseSingleRange/none789=== PAUSE TestParseSingleRange/none790=== RUN TestParseSingleRange/unknown_unit791=== PAUSE TestParseSingleRange/unknown_unit792=== RUN TestParseSingleRange/multi-range_ignored793=== PAUSE TestParseSingleRange/multi-range_ignored794=== RUN TestParseSingleRange/malformed_no_dash795=== PAUSE TestParseSingleRange/malformed_no_dash796=== RUN TestParseSingleRange/malformed_both_empty797=== PAUSE TestParseSingleRange/malformed_both_empty798=== RUN TestParseSingleRange/malformed_end_before_start799=== PAUSE TestParseSingleRange/malformed_end_before_start800=== RUN TestParseSingleRange/closed801=== PAUSE TestParseSingleRange/closed802=== CONT TestPresentNotReportedWhileGCDeletesClosure803=== CONT TestPresentRefreshesOnlyStaleClosures804=== CONT TestPresentReportsOnlyClosureRoots805=== RUN TestIsValidCachePath/narinfo806--- PASS: TestSkippedUploadsHandler (0.01s)807=== CONT TestOrphanedObjectsGCStressTest808=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale809=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale810=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh811=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh812=== RUN TestParseSingleRange/open-ended813=== PAUSE TestParseSingleRange/open-ended814=== RUN TestParseSingleRange/end_clamped_to_size815=== PAUSE TestParseSingleRange/end_clamped_to_size816=== RUN TestParseSingleRange/suffix817=== PAUSE TestParseSingleRange/suffix818=== RUN TestParseSingleRange/suffix_exceeds_size819=== PAUSE TestParseSingleRange/suffix_exceeds_size820=== RUN TestParseSingleRange/single_byte821=== PAUSE TestParseSingleRange/single_byte822=== RUN TestParseSingleRange/start_past_EOF823=== PAUSE TestParseSingleRange/start_past_EOF824=== RUN TestParseSingleRange/start_far_past_EOF825=== PAUSE TestParseSingleRange/start_far_past_EOF826=== CONT TestObjectStatsLargeCommit827=== CONT TestOrphanedObjectsGC828=== PAUSE TestIsValidCachePath/narinfo829=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars830=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars831=== RUN TestIsValidCachePath/nar_zst832=== PAUSE TestIsValidCachePath/nar_zst833=== RUN TestIsValidCachePath/nar_xz834=== PAUSE TestIsValidCachePath/nar_xz835=== RUN TestIsValidCachePath/nar_bz2836=== PAUSE TestIsValidCachePath/nar_bz2837=== RUN TestIsValidCachePath/nar_uncompressed838=== PAUSE TestIsValidCachePath/nar_uncompressed839=== RUN TestIsValidCachePath/ls840=== PAUSE TestIsValidCachePath/ls841=== RUN TestIsValidCachePath/log842=== PAUSE TestIsValidCachePath/log843=== RUN TestIsValidCachePath/realisation844=== PAUSE TestIsValidCachePath/realisation845=== RUN TestIsValidCachePath/nix-cache-info846=== PAUSE TestIsValidCachePath/nix-cache-info847=== RUN TestIsValidCachePath/index.html848=== PAUSE TestIsValidCachePath/index.html849=== RUN TestIsValidCachePath/traversal_parent850=== PAUSE TestIsValidCachePath/traversal_parent851=== RUN TestIsValidCachePath/traversal_in_middle852=== PAUSE TestIsValidCachePath/traversal_in_middle853=== RUN TestIsValidCachePath/invalid_char_e854=== PAUSE TestIsValidCachePath/invalid_char_e855=== RUN TestIsValidCachePath/invalid_char_u856=== PAUSE TestIsValidCachePath/invalid_char_u857=== RUN TestIsValidCachePath/random_path858=== PAUSE TestIsValidCachePath/random_path859=== RUN TestIsValidCachePath/empty860=== PAUSE TestIsValidCachePath/empty861=== RUN TestIsValidCachePath/leading_slash862=== PAUSE TestIsValidCachePath/leading_slash863=== RUN TestIsValidCachePath/wrong_extension864=== PAUSE TestIsValidCachePath/wrong_extension865=== RUN TestIsValidCachePath/short_hash866=== PAUSE TestIsValidCachePath/short_hash867=== CONT TestObjectStatsTrigger8682026/10/10 19:00:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34767/oidc8692026/10/10 19:00:52 INFO Received push request method=POST path=/api/pushes8702026/10/10 19:00:52 INFO Received uploads request method=POST path=/api/pending_closures871--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.29s)872=== CONT TestClientWithDependencies8732026/10/10 19:00:52 INFO Received uploads request method=POST path=/api/pending_closures8742026/10/10 19:00:52 INFO Received cleanup request method=DELETE path=/api/pending_closures8752026/10/10 19:00:52 INFO Aborted multipart uploads count=0 kept=08762026/10/10 19:00:52 INFO Received uploads request method=POST path=/api/pending_closures8772026/10/10 19:00:52 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst8782026/10/10 19:00:52 INFO Received uploads request method=POST path=/api/pending_closures879--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.33s)880=== CONT TestPendingCleanupUsesOneCutoff8812026/10/10 19:00:52 INFO Received cleanup request method=DELETE path=/api/pending_closures8822026/10/10 19:00:52 INFO Aborted multipart uploads count=1 kept=08832026/10/10 19:00:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8842026-10-10 19:00:52.126 UTC [466] ERROR: Closure does not exist: id=18852026-10-10 19:00:52.126 UTC [466] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE8862026-10-10 19:00:52.126 UTC [466] STATEMENT: -- name: CommitPendingClosure :one887 SELECT commit_pending_closure($1::bigint)::bigint888 889--- PASS: TestService_cleanupPendingClosuresHandler (0.34s)890=== CONT TestLeadEndsOnShutdown8912026/10/10 19:00:52 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"892--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.35s)893=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded8942026/10/10 19:00:52 INFO Received uploads request method=POST path=/api/pending_closures8952026/10/10 19:00:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8962026/10/10 19:00:52 INFO Received push request method=POST path=/api/pushes8972026/10/10 19:00:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8982026/10/10 19:00:52 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YzEzNzY0MTEtZDA0OC00ZWY0LWE4NjYtYzM2YjM5OTc1NTEwLjIyOTYwYjEzLTU3ZGUtNGYwOC1iYTM4LWYzMWNhZjNjNWM1ZHgxNzkxNjU4ODUyMTUxNzgzNjI08992026/10/10 19:00:52 INFO Received complete push request method=POST path=/api/pushes/1/complete9002026/10/10 19:00:52 INFO Received uploads request method=POST path=/api/pending_closures9012026/10/10 19:00:52 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YzEzNzY0MTEtZDA0OC00ZWY0LWE4NjYtYzM2YjM5OTc1NTEwLjIyOTYwYjEzLTU3ZGUtNGYwOC1iYTM4LWYzMWNhZjNjNWM1ZHgxNzkxNjU4ODUyMTUxNzgzNjI0 parts=1902--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.40s)903=== CONT TestLeadIncumbentAnnouncesAtOnce9042026/10/10 19:00:52 INFO Completed push id=1 objects=4 duration=8.768935ms9052026/10/10 19:00:52 INFO Received push request method=POST path=/api/pushes9062026/10/10 19:00:52 INFO Received uploads request method=POST path=/api/pending_closures9072026/10/10 19:00:52 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"908--- PASS: TestService_AuthMiddleware (0.42s)909=== CONT TestMultipartCleanup9102026/10/10 19:00:52 INFO Received uploads request method=POST path=/api/pending_closures911=== RUN TestPush_RejectsBadRequests/no_objects912=== PAUSE TestPush_RejectsBadRequests/no_objects913=== RUN TestPush_RejectsBadRequests/bad_root914=== PAUSE TestPush_RejectsBadRequests/bad_root915=== RUN TestPush_RejectsBadRequests/root_not_in_objects916=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects917=== RUN TestPush_RejectsBadRequests/no_roots918=== PAUSE TestPush_RejectsBadRequests/no_roots919=== CONT TestLeadElectsOneAndHandsOver9202026/10/10 19:00:52 INFO Aborted multipart uploads count=0 kept=09212026/10/10 19:00:52 WARN Force mode enabled - objects will be deleted immediately without grace period9222026/10/10 19:00:52 INFO Received push request method=POST path=/api/pushes9232026/10/10 19:00:52 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=09242026/10/10 19:00:52 INFO Vacuumed table table=pending_closures9252026/10/10 19:00:52 INFO Vacuumed table table=pending_objects9262026/10/10 19:00:52 INFO Vacuumed table table=multipart_uploads9272026/10/10 19:00:52 INFO Vacuumed table table=closures9282026/10/10 19:00:52 INFO Vacuumed table table=objects9292026/10/10 19:00:52 INFO Received complete push request method=POST path=/api/pushes/2/complete9302026/10/10 19:00:52 INFO Completed push id=2 objects=4 duration=3.287589ms9312026/10/10 19:00:52 INFO Received complete push request method=POST path=/api/pushes/1/complete932--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.51s)933=== CONT TestServerTLSConfig934=== RUN TestServerTLSConfig/no_client_CA935=== PAUSE TestServerTLSConfig/no_client_CA936=== RUN TestServerTLSConfig/missing_CA_file937=== PAUSE TestServerTLSConfig/missing_CA_file938=== RUN TestServerTLSConfig/not_a_PEM_file939=== PAUSE TestServerTLSConfig/not_a_PEM_file940=== CONT TestMetricsCommit9412026/10/10 19:00:52 INFO Received push request method=POST path=/api/pushes9422026/10/10 19:00:52 INFO Completed push id=1 objects=6 duration=9.144079ms943--- PASS: TestPush_CompleteCommitsEveryRoot (0.52s)944=== CONT TestConnectWaitsForAPeerMigration9452026/10/10 19:00:52 INFO Received push request method=POST path=/api/pushes9462026-10-10 19:00:52.334 UTC [523] ERROR: could not obtain lock on row in relation "closures"9472026-10-10 19:00:52.334 UTC [523] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9482026-10-10 19:00:52.334 UTC [523] ERROR: could not obtain lock on row in relation "closures"9492026-10-10 19:00:52.334 UTC [523] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9502026-10-10 19:00:52.334 UTC [523] ERROR: could not obtain lock on row in relation "closures"9512026-10-10 19:00:52.334 UTC [523] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9522026-10-10 19:00:52.335 UTC [523] ERROR: could not obtain lock on row in relation "closures"9532026-10-10 19:00:52.335 UTC [523] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9542026-10-10 19:00:52.335 UTC [523] ERROR: could not obtain lock on row in relation "closures"9552026-10-10 19:00:52.335 UTC [523] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT956--- PASS: TestPush_RootsAreLockedInByteOrder (0.55s)957=== CONT TestMetricsInventory958--- PASS: TestService_Rustfstest (0.56s)959=== CONT TestNARDeduplicationMetadataUploadBug960--- PASS: TestObjectStatsTrigger (0.61s)961=== CONT TestService_NativeMTLS962--- PASS: TestPresentRefreshesOnlyStaleClosures (0.63s)963=== CONT TestResolveDBConnectionString964=== RUN TestResolveDBConnectionString/flag_wins965=== PAUSE TestResolveDBConnectionString/flag_wins966=== RUN TestResolveDBConnectionString/file_when_flag_empty967=== PAUSE TestResolveDBConnectionString/file_when_flag_empty968=== RUN TestResolveDBConnectionString/missing_file_is_an_error969=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error970=== RUN TestResolveDBConnectionString/PGHOST_allows_empty971=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty972=== RUN TestResolveDBConnectionString/nothing_configured973=== PAUSE TestResolveDBConnectionString/nothing_configured974=== CONT TestCreatePendingClosureRejectsOversizedNAR9752026/10/10 19:00:52 INFO Received uploads request method=POST path=/api/pending_closures976--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)977=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock978--- PASS: TestPresentReportsOnlyClosureRoots (0.65s)979=== CONT TestCacheConfigHandlerMaxNarSize980--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)981=== CONT TestDeleteClosuresRacingPins9822026/10/10 19:00:52 INFO Received push request method=POST path=/api/pushes9832026/10/10 19:00:52 INFO Received complete push request method=POST path=/api/pushes/1/complete9842026/10/10 19:00:52 INFO Completed push id=1 objects=4 duration=10.855413ms985--- PASS: TestPush_RepeatedRootCommitsOnce (0.69s)986=== CONT TestGenerateLandingPage9872026/10/10 19:00:52 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux9882026/10/10 19:00:52 WARN Refused reserved pin name=worker-x86_64-linux9892026/10/10 19:00:52 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux9902026/10/10 19:00:52 INFO Received create pin request method=POST path=/api/pins/my-app9912026/10/10 19:00:52 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux992--- PASS: TestCreatePin_ReservedPins (0.69s)993=== CONT TestClientFallsBackToClosures994--- PASS: TestGenerateLandingPage (0.00s)995=== CONT TestService_readinessHandler9962026/10/10 19:00:52 INFO Received push request method=POST path=/api/pushes9972026/10/10 19:00:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9982026/10/10 19:00:52 INFO Signed narinfos id=1 count=19992026/10/10 19:00:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10002026/10/10 19:00:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10012026/10/10 19:00:52 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"10022026/10/10 19:00:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10032026/10/10 19:00:52 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"10042026/10/10 19:00:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10052026/10/10 19:00:52 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=110062026/10/10 19:00:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10072026/10/10 19:00:52 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1008--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.74s)1009=== CONT TestClientPushesUseOnePush10102026/10/10 19:00:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10112026/10/10 19:00:52 INFO Received uploads request method=POST path=/api/pending_closures10122026/10/10 19:00:52 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YzEzNzY0MTEtZDA0OC00ZWY0LWE4NjYtYzM2YjM5OTc1NTEwLmMwMjQ0NWMzLWY5MzctNDhiYS1iMThhLTA2YjI2MDA3NDRhZXgxNzkxNjU4ODUyMTkwMjQ1NjE0 parts=1210132026/10/10 19:00:52 INFO Received uploads request method=POST path=/api/pending_closures10142026/10/10 19:00:52 INFO Received uploads request method=POST path=/api/pending_closures10152026/10/10 19:00:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10162026/10/10 19:00:52 INFO Received uploads request method=POST path=/api/pending_closures10172026/10/10 19:00:52 INFO Received cleanup request method=DELETE path=/api/pending_closures10182026/10/10 19:00:52 INFO Received uploads request method=POST path=/api/pending_closures10192026/10/10 19:00:52 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YzEzNzY0MTEtZDA0OC00ZWY0LWE4NjYtYzM2YjM5OTc1NTEwLmQ1OWU3OGU0LThiOTQtNDRhZS1iNjQyLTk2MjZlZjI2OTkwYXgxNzkxNjU4ODUyMjMzOTMyMDkw parts=1210202026/10/10 19:00:52 INFO Received uploads request method=POST path=/api/pending_closures1021--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.83s)1022=== CONT TestService_healthCheckHandler10232026/10/10 19:00:52 INFO lead: acquired remote=192.0.2.1:12341024--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.49s)1025=== CONT TestPinProtectsFromGC10262026-10-10 19:00:52.639 UTC [526] ERROR: Push does not exist: id=110272026-10-10 19:00:52.639 UTC [526] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE10282026-10-10 19:00:52.639 UTC [526] STATEMENT: SELECT commit_push($1)1029--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.85s)1030=== CONT TestGracefulShutdownDrainsInflight10312026/10/10 19:00:52 INFO Starting HTTP server address=127.0.0.1:4228310322026/10/10 19:00:52 INFO Shutdown signal received, draining in-flight requests timeout=10s10332026/10/10 19:00:52 INFO lead: acquired remote=192.0.2.1:12341034=== NAME TestClientWithDependencies10352026/10/10 19:00:52 INFO lead: released remote=192.0.2.1:12341036 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies1771778653/001/store/584nbxqj4wxg9qsc104f0vl4p1w34j64-test-script1037--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.46s)1038=== CONT TestClientSharedPathCommittedMidPush10392026/10/10 19:00:52 INFO Received uploads request method=POST path=/api/pending_closures1040=== NAME TestClientWithDependencies1041 client_integration_test.go:615: Found 1 dependencies (including self)10422026/10/10 19:00:52 INFO lead: acquired remote=192.0.2.1:12341043--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1044=== CONT TestGCTaskStore_Fail1045--- PASS: TestGCTaskStore_Fail (0.00s)1046=== CONT TestIsValidUploadKey1047=== RUN TestIsValidUploadKey/narinfo1048=== PAUSE TestIsValidUploadKey/narinfo1049=== RUN TestIsValidUploadKey/nar_zst1050=== PAUSE TestIsValidUploadKey/nar_zst1051=== RUN TestIsValidUploadKey/nar_xz1052=== PAUSE TestIsValidUploadKey/nar_xz1053=== RUN TestIsValidUploadKey/nar_plain1054=== PAUSE TestIsValidUploadKey/nar_plain1055=== RUN TestIsValidUploadKey/listing1056=== PAUSE TestIsValidUploadKey/listing1057=== RUN TestIsValidUploadKey/build_log1058=== PAUSE TestIsValidUploadKey/build_log1059=== RUN TestIsValidUploadKey/build_log_home-manager_file1060=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1061=== RUN TestIsValidUploadKey/build_log_plus_in_name1062=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1063=== RUN TestIsValidUploadKey/build_log_question_mark1064=== PAUSE TestIsValidUploadKey/build_log_question_mark1065=== RUN TestIsValidUploadKey/build_log_equals1066=== PAUSE TestIsValidUploadKey/build_log_equals1067=== RUN TestIsValidUploadKey/realisation1068=== PAUSE TestIsValidUploadKey/realisation1069=== RUN TestIsValidUploadKey/realisation_plus_in_output1070=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1071=== RUN TestIsValidUploadKey/nix-cache-info1072=== PAUSE TestIsValidUploadKey/nix-cache-info1073=== RUN TestIsValidUploadKey/index.html1074=== PAUSE TestIsValidUploadKey/index.html1075=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1076=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1077=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1078=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1079=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1080=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1081=== RUN TestIsValidUploadKey/traversal1082=== PAUSE TestIsValidUploadKey/traversal1083=== RUN TestIsValidUploadKey/traversal_nar1084=== PAUSE TestIsValidUploadKey/traversal_nar1085=== RUN TestIsValidUploadKey/absolute1086=== PAUSE TestIsValidUploadKey/absolute1087=== RUN TestIsValidUploadKey/empty_key1088=== PAUSE TestIsValidUploadKey/empty_key1089=== RUN TestIsValidUploadKey/unknown_type1090=== PAUSE TestIsValidUploadKey/unknown_type1091=== CONT TestPendingClosureWriteTimeout1092=== RUN TestPendingClosureWriteTimeout/empty1093=== PAUSE TestPendingClosureWriteTimeout/empty1094=== RUN TestPendingClosureWriteTimeout/400_objects1095=== PAUSE TestPendingClosureWriteTimeout/400_objects1096=== RUN TestPendingClosureWriteTimeout/670k_objects1097=== PAUSE TestPendingClosureWriteTimeout/670k_objects1098=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1099=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1100=== CONT TestUploadHandlersRejectOversizedBody11012026/10/10 19:00:52 INFO Received push request method=POST path=/api/pushes11022026/10/10 19:00:52 INFO Received complete push request method=POST path=/api/pushes/1/complete11032026/10/10 19:00:52 INFO Completed push id=1 objects=4 duration=8.487333ms11042026/10/10 19:00:52 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11052026/10/10 19:00:52 INFO Completed upload id=2 objects=2 duration=1.759715ms11062026/10/10 19:00:52 INFO Received push request method=POST path=/api/pushes1107--- PASS: TestMetricsCommit (0.47s)1108=== CONT TestCompleteMultipartUnregistered11092026/10/10 19:00:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11102026/10/10 19:00:52 INFO Uploading 584nbxqj4wxg9qsc104f0vl4p1w34j64-test-script (136B)11112026/10/10 19:00:52 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"11122026/10/10 19:00:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11132026/10/10 19:00:52 WARN Failed to register uploaded object key=584nbxqj4wxg9qsc104f0vl4p1w34j64.ls error="server returned 404: 404 page not found\n"11142026/10/10 19:00:52 WARN Failed to register uploaded object key=log/7kibwza0j734wi4isrd1hnb5v37wsf98-test-script.drv error="server returned 404: 404 page not found\n"11152026/10/10 19:00:52 INFO Signed narinfos id=1 count=111162026/10/10 19:00:52 INFO Uploading 1 narinfos11172026/10/10 19:00:52 INFO Received complete push request method=POST path=/api/pushes/1/complete11182026/10/10 19:00:52 WARN Failed to register uploaded object key=584nbxqj4wxg9qsc104f0vl4p1w34j64.narinfo error="server returned 404: 404 page not found\n"11192026/10/10 19:00:52 INFO Completed push id=1 objects=4 duration=5.388187ms11202026/10/10 19:00:52 INFO Upload complete. (59ms)1121=== NAME TestClientWithDependencies1122 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1771778653/001/store) requires matching store prefix1123--- PASS: TestClientWithDependencies (0.71s)1124=== CONT TestUploadHandlersRejectInvalidKeys1125=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1126=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1127=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1128=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1129=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1130=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1131=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1132=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1133=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT1134--- PASS: TestMetricsInventory (0.45s)1135=== CONT TestCacheConfigHandler1136=== RUN TestCacheConfigHandler/full_config,_no_issuer1137=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1138=== RUN TestCacheConfigHandler/no_cache_url_configured1139=== PAUSE TestCacheConfigHandler/no_cache_url_configured1140=== RUN TestCacheConfigHandler/no_signing_keys1141=== PAUSE TestCacheConfigHandler/no_signing_keys1142=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1143=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1144=== CONT TestProxyWriteTimeout1145=== RUN TestProxyWriteTimeout/narinfo1146=== PAUSE TestProxyWriteTimeout/narinfo1147=== RUN TestProxyWriteTimeout/1_GiB_nar1148=== PAUSE TestProxyWriteTimeout/1_GiB_nar1149=== RUN TestProxyWriteTimeout/10_GiB_nar1150=== PAUSE TestProxyWriteTimeout/10_GiB_nar1151=== RUN TestProxyWriteTimeout/unknown_size1152=== PAUSE TestProxyWriteTimeout/unknown_size1153=== CONT TestClientMultipleUploads1154=== NAME TestNARDeduplicationMetadataUploadBug1155 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2823563790/001/store/w16kr7ah45niihc1xqzviqs3m5bkrg3x-file1.txt11562026/10/10 19:00:52 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11572026/10/10 19:00:52 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1158--- PASS: TestService_NativeMTLS (0.39s)1159=== CONT TestService_AuthMiddleware_OIDC11602026/10/10 19:00:52 INFO Received cleanup request method=DELETE path=/api/pending_closures11612026/10/10 19:00:52 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket33/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""11622026/10/10 19:00:52 INFO Aborted multipart uploads count=0 kept=111632026/10/10 19:00:52 INFO Received cleanup request method=DELETE path=/api/pending_closures11642026/10/10 19:00:52 INFO Aborted multipart uploads count=1 kept=01165--- PASS: TestMultipartCleanup (0.61s)1166=== CONT TestClientIntegration1167=== NAME TestOrphanedObjectsGC1168 orphaned_objects_gc_test.go:287: GC Test Summary:1169 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1170 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1171 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1172 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1173 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1174--- PASS: TestOrphanedObjectsGC (1.06s)1175=== CONT TestService_ReadScope_PublicByDefault11762026/10/10 19:00:52 WARN readiness check failed error="closed pool"1177--- PASS: TestService_readinessHandler (0.38s)1178=== CONT TestClientErrorHandling1179=== RUN TestClientErrorHandling/InvalidStorePath1180=== PAUSE TestClientErrorHandling/InvalidStorePath1181=== RUN TestClientErrorHandling/InvalidAuthToken1182=== PAUSE TestClientErrorHandling/InvalidAuthToken1183=== RUN TestClientErrorHandling/ServerNotAvailable1184=== PAUSE TestClientErrorHandling/ServerNotAvailable1185=== CONT TestService_RequireScope_OIDC1186=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1187=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1188=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1189=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1190=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1191=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1192=== CONT TestClientCADerivations11932026/10/10 19:00:52 INFO Received push request method=POST path=/api/pushes11942026/10/10 19:00:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11952026/10/10 19:00:52 INFO Uploading w16kr7ah45niihc1xqzviqs3m5bkrg3x-file1.txt (160B)11962026/10/10 19:00:52 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11972026/10/10 19:00:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11982026/10/10 19:00:52 WARN Failed to register uploaded object key=w16kr7ah45niihc1xqzviqs3m5bkrg3x.ls error="server returned 404: 404 page not found\n"11992026/10/10 19:00:52 INFO Signed narinfos id=1 count=112002026/10/10 19:00:52 INFO Uploading 1 narinfos12012026/10/10 19:00:52 INFO Received complete push request method=POST path=/api/pushes/1/complete12022026/10/10 19:00:52 WARN Failed to register uploaded object key=w16kr7ah45niihc1xqzviqs3m5bkrg3x.narinfo error="server returned 404: 404 page not found\n"12032026/10/10 19:00:52 INFO Completed push id=1 objects=3 duration=8.22461ms12042026/10/10 19:00:52 INFO Upload complete. (69ms)1205=== NAME TestNARDeduplicationMetadataUploadBug1206 metadata_upload_test.go:54: Retrieved narinfo from S3:1207 StorePath: /build/TestNARDeduplicationMetadataUploadBug2823563790/001/store/w16kr7ah45niihc1xqzviqs3m5bkrg3x-file1.txt1208 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1209 Compression: zstd1210 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1211 NarSize: 1601212 References: 1213 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1214 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1215 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1216 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1217 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2823563790/001/store/hvlqhyvhkx586820v03xpshja6rrny20-file2.txt1218--- PASS: TestService_healthCheckHandler (0.33s)1219=== CONT TestRegisterCompletedObjectNeedsPendingRow12202026/10/10 19:00:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35807/oidc12212026/10/10 19:00:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12222026/10/10 19:00:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12232026/10/10 19:00:52 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1224--- PASS: TestCompleteMultipartUnregistered (0.23s)1225=== CONT TestCacheStatsHandler1226=== NAME TestPinProtectsFromGC1227 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC3808175492/001/store/0pqwzybnz1ar67g851ndggindgw6kgm1-pinned-file.txt1228 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC3808175492/001/store/n0i4l5w47lrs3jzibris9nkjc3v6rb1l-unpinned-file.txt12292026/10/10 19:00:53 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YzEzNzY0MTEtZDA0OC00ZWY0LWE4NjYtYzM2YjM5OTc1NTEwLmQ5Yzg2M2QwLTYyNzEtNDdlNy1hZDBjLWFjOWUwOTMyZTRmYngxNzkxNjU4ODUyNTk2NzQyODMw error="Get \"http://127.0.0.1:1/bucket11/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"12302026/10/10 19:00:53 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YzEzNzY0MTEtZDA0OC00ZWY0LWE4NjYtYzM2YjM5OTc1NTEwLmIwODU0MWMyLWU0ZGYtNGViMS1hNzNjLWZhNGIxOTBmYTZlZngxNzkxNjU4ODUyNTkwMTkyNjM0 parts=1212312026/10/10 19:00:53 INFO Received cleanup request method=DELETE path=/api/pending_closures12322026/10/10 19:00:53 INFO Received push request method=POST path=/api/pushes12332026/10/10 19:00:53 INFO Aborted multipart uploads count=1 kept=012342026/10/10 19:00:53 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1235--- PASS: TestRedundantMultipartUpload (1.23s)1236=== CONT TestGCTaskStore_CompletedAllowsNewTask1237--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1238=== CONT TestTombstonedObjectOfferedWithoutWaiting12392026/10/10 19:00:53 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12402026/10/10 19:00:53 INFO Signed narinfos id=2 count=112412026/10/10 19:00:53 WARN Failed to register uploaded object key=hvlqhyvhkx586820v03xpshja6rrny20.ls error="server returned 404: 404 page not found\n"12422026/10/10 19:00:53 INFO Uploading 1 narinfos12432026/10/10 19:00:53 INFO Received uploads request method=POST path=/api/pending_closures12442026/10/10 19:00:53 INFO Received complete push request method=POST path=/api/pushes/2/complete12452026/10/10 19:00:53 WARN Failed to register uploaded object key=hvlqhyvhkx586820v03xpshja6rrny20.narinfo error="server returned 404: 404 page not found\n"12462026/10/10 19:00:53 INFO Completed push id=2 objects=3 duration=2.808385ms12472026/10/10 19:00:53 INFO Upload complete. (51ms)1248=== NAME TestNARDeduplicationMetadataUploadBug1249 metadata_upload_test.go:76: Retrieved narinfo from S3:1250 StorePath: /build/TestNARDeduplicationMetadataUploadBug2823563790/001/store/hvlqhyvhkx586820v03xpshja6rrny20-file2.txt1251 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1252 Compression: zstd1253 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1254 NarSize: 1601255 References: 1256 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1257 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1258 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1259 {"version":1,"root":{"type":"regular","size":44}}1260--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.24s)1261=== CONT TestGCTaskStore_GetReturnsLatest1262--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1263=== CONT TestSweepSkipsRowsLockedByPush1264--- PASS: TestNARDeduplicationMetadataUploadBug (0.69s)1265=== CONT TestGCTaskStore_GetEmpty1266--- PASS: TestGCTaskStore_GetEmpty (0.00s)1267=== CONT TestFailedS3DeleteKeepsTombstone12682026/10/10 19:00:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43139/oidc12692026/10/10 19:00:53 INFO Received uploads request method=POST path=/api/pending_closures12702026/10/10 19:00:53 INFO Received push request method=POST path=/api/pushes12712026/10/10 19:00:53 INFO Received uploads request method=POST path=/api/pending_closures12722026/10/10 19:00:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12732026/10/10 19:00:53 INFO Uploading 0pqwzybnz1ar67g851ndggindgw6kgm1-pinned-file.txt (128B)12742026/10/10 19:00:53 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12752026/10/10 19:00:53 INFO Uploading l7hc92aswgrlwhyhn1qvxcw50hwrsgan-shared-dep (136B)12762026/10/10 19:00:53 INFO Uploading l9bl4lw6fjydv3a3nnnplqlfq2gnm5dj-b (216B)12772026/10/10 19:00:53 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"12782026/10/10 19:00:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12792026/10/10 19:00:53 WARN Failed to register uploaded object key=0pqwzybnz1ar67g851ndggindgw6kgm1.ls error="server returned 404: 404 page not found\n"12802026/10/10 19:00:53 INFO Signed narinfos id=1 count=112812026/10/10 19:00:53 INFO Uploading 1 narinfos12822026/10/10 19:00:53 INFO Received push request method=POST path=/api/pushes12832026/10/10 19:00:53 WARN Failed to register uploaded object key=nar/0q9c0sh1s6x2af3040gil47y3bdv8x2b6cq42l3nvh3jwz0m0q5r.nar.zst error="server returned 404: 404 page not found\n"12842026/10/10 19:00:53 WARN Failed to register uploaded object key=6kjdqdgniiv43q5n55qhvi0cdch24f70.ls error="server returned 404: 404 page not found\n"12852026/10/10 19:00:53 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12862026/10/10 19:00:53 WARN Failed to register uploaded object key=l7hc92aswgrlwhyhn1qvxcw50hwrsgan.ls error="server returned 404: 404 page not found\n"12872026/10/10 19:00:53 WARN Failed to register uploaded object key=l9bl4lw6fjydv3a3nnnplqlfq2gnm5dj.ls error="server returned 404: 404 page not found\n"12882026/10/10 19:00:53 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12892026/10/10 19:00:53 INFO Signed narinfos id=2 count=212902026/10/10 19:00:53 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12912026/10/10 19:00:53 INFO Signed narinfos id=1 count=212922026/10/10 19:00:53 INFO Uploading 4 narinfos12932026/10/10 19:00:53 INFO Received complete push request method=POST path=/api/pushes/1/complete12942026/10/10 19:00:53 WARN Failed to register uploaded object key=0pqwzybnz1ar67g851ndggindgw6kgm1.narinfo error="server returned 404: 404 page not found\n"1295=== NAME TestClientMultipleUploads1296 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads1909800959/001/store/v3pidcy6mzfwp5j72gcgdvhqrbjf5lk1-test-file-0.txt12972026/10/10 19:00:53 WARN Failed to register uploaded object key=6kjdqdgniiv43q5n55qhvi0cdch24f70.narinfo error="server returned 404: 404 page not found\n"12982026/10/10 19:00:53 WARN Failed to register uploaded object key=l7hc92aswgrlwhyhn1qvxcw50hwrsgan.narinfo error="server returned 404: 404 page not found\n"12992026/10/10 19:00:53 WARN Failed to register uploaded object key=l9bl4lw6fjydv3a3nnnplqlfq2gnm5dj.narinfo error="server returned 404: 404 page not found\n"13002026/10/10 19:00:53 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)1301--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.67s)13022026/10/10 19:00:53 INFO Uploading a1zw265fzk5i55skzhyblqv8ldj38zhj-shared-dep (136B)1303=== CONT TestGCTaskStore_ConflictDifferentParams1304--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1305=== CONT TestForceGCDuringPushOffersSweptObject13062026/10/10 19:00:53 INFO Uploading ivq9g884746zmnp41d9mbfm35qgdid3h-b (216B)1307=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1308=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1309=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1310=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1311=== CONT TestGCTaskStore_DeduplicateSameParams1312--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1313=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection13142026/10/10 19:00:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13152026/10/10 19:00:53 WARN Failed to register uploaded object key=l7hc92aswgrlwhyhn1qvxcw50hwrsgan.narinfo error="server returned 404: 404 page not found\n"1316--- PASS: TestService_ReadScope_PublicByDefault (0.24s)1317=== CONT TestGCTaskStore_StartNew1318--- PASS: TestGCTaskStore_StartNew (0.00s)1319=== CONT TestGCSweepDeliversEachKeyOnce13202026/10/10 19:00:53 INFO Completed push id=1 objects=3 duration=6.9445ms13212026/10/10 19:00:53 INFO Upload complete. (59ms)13222026/10/10 19:00:53 WARN Failed to register uploaded object key=ki63hyinffcizlc1j3pqg8inpcql9lai.ls error="server returned 404: 404 page not found\n"13232026/10/10 19:00:53 WARN Failed to register uploaded object key=ivq9g884746zmnp41d9mbfm35qgdid3h.ls error="server returned 404: 404 page not found\n"13242026/10/10 19:00:53 WARN Failed to register uploaded object key=a1zw265fzk5i55skzhyblqv8ldj38zhj.ls error="server returned 404: 404 page not found\n"13252026/10/10 19:00:53 WARN Failed to register uploaded object key=nar/0b46c341dr8rz0fq77c1n782m5rrjjkhqc7aqcvd4xsplksyg12r.nar.zst error="server returned 404: 404 page not found\n"13262026/10/10 19:00:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13272026/10/10 19:00:53 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13282026/10/10 19:00:53 INFO Signed narinfos id=1 count=313292026/10/10 19:00:53 INFO Uploading 3 narinfos13302026/10/10 19:00:53 INFO Completed upload id=1 objects=6 duration=5.682628ms13312026/10/10 19:00:53 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13322026/10/10 19:00:53 INFO Completed upload id=2 objects=6 duration=1.853036ms13332026/10/10 19:00:53 INFO Upload complete. (64ms)13342026/10/10 19:00:53 WARN Failed to register uploaded object key=a1zw265fzk5i55skzhyblqv8ldj38zhj.narinfo error="server returned 404: 404 page not found\n"13352026/10/10 19:00:53 WARN Failed to register uploaded object key=ki63hyinffcizlc1j3pqg8inpcql9lai.narinfo error="server returned 404: 404 page not found\n"13362026/10/10 19:00:53 INFO Received complete push request method=POST path=/api/pushes/1/complete13372026/10/10 19:00:53 WARN Failed to register uploaded object key=ivq9g884746zmnp41d9mbfm35qgdid3h.narinfo error="server returned 404: 404 page not found\n"1338=== NAME TestClientFallsBackToClosures1339 client_pushes_test.go:112: Retrieved narinfo from S3:1340 StorePath: /build/TestClientFallsBackToClosures52436822/001/store/l7hc92aswgrlwhyhn1qvxcw50hwrsgan-shared-dep1341 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1342 Compression: zstd1343 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821344 NarSize: 1361345 References: 1346 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1347 client_pushes_test.go:112: Retrieved narinfo from S3:1348 StorePath: /build/TestClientFallsBackToClosures52436822/001/store/6kjdqdgniiv43q5n55qhvi0cdch24f70-a1349 URL: nar/0q9c0sh1s6x2af3040gil47y3bdv8x2b6cq42l3nvh3jwz0m0q5r.nar.zst1350 Compression: zstd1351 NarHash: sha256:0q9c0sh1s6x2af3040gil47y3bdv8x2b6cq42l3nvh3jwz0m0q5r1352 NarSize: 2161353 References: /build/TestClientFallsBackToClosures52436822/001/store/l7hc92aswgrlwhyhn1qvxcw50hwrsgan-shared-dep1354 CA: text:sha256:04h2ihq2ndy7mk1wbs763672qd0hhil0d52lbw0bs3qf497lq76q1355 client_pushes_test.go:112: Retrieved narinfo from S3:1356 StorePath: /build/TestClientFallsBackToClosures52436822/001/store/l9bl4lw6fjydv3a3nnnplqlfq2gnm5dj-b1357 URL: nar/0q9c0sh1s6x2af3040gil47y3bdv8x2b6cq42l3nvh3jwz0m0q5r.nar.zst1358 Compression: zstd1359 NarHash: sha256:0q9c0sh1s6x2af3040gil47y3bdv8x2b6cq42l3nvh3jwz0m0q5r1360 NarSize: 2161361 References: /build/TestClientFallsBackToClosures52436822/001/store/l7hc92aswgrlwhyhn1qvxcw50hwrsgan-shared-dep1362 CA: text:sha256:04h2ihq2ndy7mk1wbs763672qd0hhil0d52lbw0bs3qf497lq76q13632026/10/10 19:00:53 INFO Received push request method=POST path=/api/pushes1364--- PASS: TestClientFallsBackToClosures (0.63s)1365=== CONT TestGCEndsOnShutdown1366=== RUN TestGCEndsOnShutdown/before_the_run1367=== PAUSE TestGCEndsOnShutdown/before_the_run1368=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1369=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1370=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1371=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1372=== CONT TestService_ReadAuthMiddleware13732026/10/10 19:00:53 INFO Completed push id=1 objects=8 duration=13.609278ms1374=== NAME TestClientIntegration1375 client_integration_test.go:286: Created store path: /build/TestClientIntegration4172821188/002/store/whiapwv9zc1pprhy0w2q7i1g6zwidlq9-test-file.txt13762026/10/10 19:00:53 INFO Upload complete. (72ms)1377=== NAME TestClientPushesUseOnePush1378 client_pushes_test.go:97: Retrieved narinfo from S3:1379 StorePath: /build/TestClientPushesUseOnePush1970098038/001/store/a1zw265fzk5i55skzhyblqv8ldj38zhj-shared-dep1380 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1381 Compression: zstd1382 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821383 NarSize: 1361384 References: 1385 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n13862026/10/10 19:00:53 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)13872026/10/10 19:00:53 INFO Uploading 9mm4dr8h9bw712jkkdli9yps9v82w39r-shared-dep (136B)13882026/10/10 19:00:53 INFO Uploading zn5dj9bmm0ly7hbf0vaakrb6qapk3ss5-top (224B)1389 client_pushes_test.go:97: Retrieved narinfo from S3:1390 StorePath: /build/TestClientPushesUseOnePush1970098038/001/store/ki63hyinffcizlc1j3pqg8inpcql9lai-a1391 URL: nar/0b46c341dr8rz0fq77c1n782m5rrjjkhqc7aqcvd4xsplksyg12r.nar.zst1392 Compression: zstd1393 NarHash: sha256:0b46c341dr8rz0fq77c1n782m5rrjjkhqc7aqcvd4xsplksyg12r1394 NarSize: 2161395 References: /build/TestClientPushesUseOnePush1970098038/001/store/a1zw265fzk5i55skzhyblqv8ldj38zhj-shared-dep1396 CA: text:sha256:1hrjwk9yip2gslmcxqlz7yf8wlnqwbdjhw62m0pxiarykqq36hv51397 client_pushes_test.go:97: Retrieved narinfo from S3:1398 StorePath: /build/TestClientPushesUseOnePush1970098038/001/store/ivq9g884746zmnp41d9mbfm35qgdid3h-b1399 URL: nar/0b46c341dr8rz0fq77c1n782m5rrjjkhqc7aqcvd4xsplksyg12r.nar.zst1400 Compression: zstd1401 NarHash: sha256:0b46c341dr8rz0fq77c1n782m5rrjjkhqc7aqcvd4xsplksyg12r1402 NarSize: 2161403 References: /build/TestClientPushesUseOnePush1970098038/001/store/a1zw265fzk5i55skzhyblqv8ldj38zhj-shared-dep1404 CA: text:sha256:1hrjwk9yip2gslmcxqlz7yf8wlnqwbdjhw62m0pxiarykqq36hv514052026/10/10 19:00:53 WARN Failed to register uploaded object key=9mm4dr8h9bw712jkkdli9yps9v82w39r.ls error="server returned 404: 404 page not found\n"14062026/10/10 19:00:53 WARN Failed to register uploaded object key=nar/016c5yci0qjd76f74w9ra0v9bj1lns4fzap0356k6ggg78xz8qan.nar.zst error="server returned 404: 404 page not found\n"14072026/10/10 19:00:53 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14082026/10/10 19:00:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14092026/10/10 19:00:53 WARN Failed to register uploaded object key=zn5dj9bmm0ly7hbf0vaakrb6qapk3ss5.ls error="server returned 404: 404 page not found\n"14102026/10/10 19:00:53 INFO Signed narinfos id=1 count=214112026/10/10 19:00:53 INFO Uploading 2 narinfos1412=== NAME TestClientMultipleUploads1413 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads1909800959/001/store/yg65ydkfjw9ari7crk2z87mkhjn9h9a1-test-file-1.txt1414--- PASS: TestClientPushesUseOnePush (0.60s)1415=== CONT TestCommitRacingPendingCleanupKeepsObjects14162026/10/10 19:00:53 WARN Failed to register uploaded object key=zn5dj9bmm0ly7hbf0vaakrb6qapk3ss5.narinfo error="server returned 404: 404 page not found\n"14172026/10/10 19:00:53 INFO Received complete push request method=POST path=/api/pushes/1/complete14182026/10/10 19:00:53 WARN Failed to register uploaded object key=9mm4dr8h9bw712jkkdli9yps9v82w39r.narinfo error="server returned 404: 404 page not found\n"14192026/10/10 19:00:53 INFO Completed push id=1 objects=6 duration=7.934788ms14202026/10/10 19:00:53 INFO Upload complete. (64ms)1421=== NAME TestClientSharedPathCommittedMidPush1422 client_integration_test.go:680: Retrieved narinfo from S3:1423 StorePath: /build/TestClientSharedPathCommittedMidPush850685332/001/store/9mm4dr8h9bw712jkkdli9yps9v82w39r-shared-dep1424 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1425 Compression: zstd1426 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821427 NarSize: 1361428 References: 1429 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1430 client_integration_test.go:680: Retrieved narinfo from S3:1431 StorePath: /build/TestClientSharedPathCommittedMidPush850685332/001/store/zn5dj9bmm0ly7hbf0vaakrb6qapk3ss5-top1432 URL: nar/016c5yci0qjd76f74w9ra0v9bj1lns4fzap0356k6ggg78xz8qan.nar.zst1433 Compression: zstd1434 NarHash: sha256:016c5yci0qjd76f74w9ra0v9bj1lns4fzap0356k6ggg78xz8qan1435 NarSize: 2241436 References: /build/TestClientSharedPathCommittedMidPush850685332/001/store/9mm4dr8h9bw712jkkdli9yps9v82w39r-shared-dep1437 CA: text:sha256:1ffiaivggfgvkinc1mjvk2pnm6alh94b0a1frzvgzx4n4cgii73s1438--- PASS: TestClientSharedPathCommittedMidPush (0.50s)1439=== CONT TestService_verifyS3Integrity1440--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.20s)1441=== CONT TestPushWaitsForSweepHoldingRow1442=== NAME TestClientMultipleUploads1443 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads1909800959/001/store/055l96bd9jp6mgsl1sg35lf5yvxy80bz-test-file-2.txt14442026/10/10 19:00:53 INFO Received push request method=POST path=/api/pushes14452026/10/10 19:00:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14462026/10/10 19:00:53 INFO Uploading n0i4l5w47lrs3jzibris9nkjc3v6rb1l-unpinned-file.txt (128B)14472026/10/10 19:00:53 WARN Failed to register uploaded object key=n0i4l5w47lrs3jzibris9nkjc3v6rb1l.ls error="server returned 404: 404 page not found\n"14482026/10/10 19:00:53 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14492026/10/10 19:00:53 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"14502026/10/10 19:00:53 INFO Signed narinfos id=2 count=114512026/10/10 19:00:53 INFO Uploading 1 narinfos14522026/10/10 19:00:53 INFO Received complete push request method=POST path=/api/pushes/2/complete14532026/10/10 19:00:53 WARN Failed to register uploaded object key=n0i4l5w47lrs3jzibris9nkjc3v6rb1l.narinfo error="server returned 404: 404 page not found\n"14542026/10/10 19:00:53 INFO Completed push id=2 objects=3 duration=2.31432ms14552026/10/10 19:00:53 INFO Upload complete. (55ms)1456=== RUN TestService_RequireScope_OIDC/builder_may_write1457=== PAUSE TestService_RequireScope_OIDC/builder_may_write1458=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1459=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1460=== RUN TestService_RequireScope_OIDC/ops_may_admin1461=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1462=== RUN TestService_RequireScope_OIDC/ops_may_not_write1463=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1464=== RUN TestService_RequireScope_OIDC/reader_may_not_write1465=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1466=== RUN TestService_RequireScope_OIDC/static_token_may_admin1467=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1468=== RUN TestService_RequireScope_OIDC/static_token_may_write1469=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1470=== RUN TestService_RequireScope_OIDC/reader_may_read1471=== PAUSE TestService_RequireScope_OIDC/reader_may_read1472=== RUN TestService_RequireScope_OIDC/writer_implies_read1473=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1474=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1475=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1476=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1477=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1478=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1479=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1480=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1481=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1482=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1483=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1484=== CONT TestSweepRechecksPendingAfterLocking14852026/10/10 19:00:53 INFO Received push request method=POST path=/api/pushes14862026/10/10 19:00:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14872026/10/10 19:00:53 INFO Uploading whiapwv9zc1pprhy0w2q7i1g6zwidlq9-test-file.txt (152B)1488--- PASS: TestCacheStatsHandler (0.21s)1489=== CONT TestGetExistingObjectsLocksRows14902026/10/10 19:00:53 WARN Failed to register uploaded object key=whiapwv9zc1pprhy0w2q7i1g6zwidlq9.ls error="server returned 404: 404 page not found\n"14912026/10/10 19:00:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14922026/10/10 19:00:53 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"14932026/10/10 19:00:53 INFO Signed narinfos id=1 count=114942026/10/10 19:00:53 INFO Uploading 1 narinfos14952026/10/10 19:00:53 INFO Received complete push request method=POST path=/api/pushes/1/complete14962026/10/10 19:00:53 WARN Failed to register uploaded object key=whiapwv9zc1pprhy0w2q7i1g6zwidlq9.narinfo error="server returned 404: 404 page not found\n"1497=== NAME TestClientCADerivations1498 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1224767548/001/store/60822ccy4gmxrwy791g69ldh2qdn3gbl-ca-test14992026/10/10 19:00:53 INFO Completed push id=1 objects=3 duration=8.336951ms15002026/10/10 19:00:53 INFO Upload complete. (68ms)15012026/10/10 19:00:53 INFO Received uploads request method=POST path=/api/pending_closures15022026/10/10 19:00:53 INFO Starting cleanup of old closures method=DELETE path=/api/closures15032026/10/10 19:00:53 INFO Garbage collection started1504--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.21s)1505=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15062026/10/10 19:00:53 INFO Received push request method=POST path=/api/pushes15072026/10/10 19:00:53 INFO Aborted multipart uploads count=0 kept=015082026/10/10 19:00:53 INFO Received uploads request method=POST path=/api/pending_closures15092026/10/10 19:00:53 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15102026/10/10 19:00:53 INFO Uploading 055l96bd9jp6mgsl1sg35lf5yvxy80bz-test-file-2.txt (160B)15112026/10/10 19:00:53 INFO Uploading yg65ydkfjw9ari7crk2z87mkhjn9h9a1-test-file-1.txt (160B)15122026/10/10 19:00:53 INFO Uploading v3pidcy6mzfwp5j72gcgdvhqrbjf5lk1-test-file-0.txt (160B)15132026/10/10 19:00:53 WARN Force mode enabled - objects will be deleted immediately without grace period15142026/10/10 19:00:53 WARN Failed to register uploaded object key=055l96bd9jp6mgsl1sg35lf5yvxy80bz.ls error="server returned 404: 404 page not found\n"15152026/10/10 19:00:53 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15162026/10/10 19:00:53 WARN Failed to register uploaded object key=yg65ydkfjw9ari7crk2z87mkhjn9h9a1.ls error="server returned 404: 404 page not found\n"15172026/10/10 19:00:53 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15182026/10/10 19:00:53 WARN Failed to register uploaded object key=v3pidcy6mzfwp5j72gcgdvhqrbjf5lk1.ls error="server returned 404: 404 page not found\n"15192026/10/10 19:00:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15202026/10/10 19:00:53 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"1521=== NAME TestClientCADerivations1522 client_ca_test.go:139: Found 1 dependencies (including self)15232026/10/10 19:00:53 INFO Signed narinfos id=1 count=315242026/10/10 19:00:53 INFO Uploading 3 narinfos15252026/10/10 19:00:53 WARN Failed to register uploaded object key=055l96bd9jp6mgsl1sg35lf5yvxy80bz.narinfo error="server returned 404: 404 page not found\n"15262026/10/10 19:00:53 INFO Received complete push request method=POST path=/api/pushes/1/complete15272026/10/10 19:00:53 WARN Failed to register uploaded object key=v3pidcy6mzfwp5j72gcgdvhqrbjf5lk1.narinfo error="server returned 404: 404 page not found\n"15282026/10/10 19:00:53 WARN Failed to register uploaded object key=yg65ydkfjw9ari7crk2z87mkhjn9h9a1.narinfo error="server returned 404: 404 page not found\n"15292026/10/10 19:00:53 INFO All 1 paths already cached1530=== NAME TestClientIntegration1531 client_integration_test.go:312: Retrieved narinfo from S3:1532 StorePath: /build/TestClientIntegration4172821188/002/store/whiapwv9zc1pprhy0w2q7i1g6zwidlq9-test-file.txt1533 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1534 Compression: zstd1535 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11536 NarSize: 1521537 References: 1538 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk115392026/10/10 19:00:53 INFO Completed push id=1 objects=9 duration=6.779758ms15402026/10/10 19:00:53 INFO Upload complete. (63ms)1541=== NAME TestClientMultipleUploads1542 client_integration_test.go:369: Uploaded 3 paths in 99.185893ms1543=== NAME TestClientIntegration1544 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1545 client_integration_test.go:313: Decompressed .ls content (64 bytes):1546 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1547 client_integration_test.go:316: Testing garbage collection...15482026/10/10 19:00:53 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=015492026/10/10 19:00:53 INFO Vacuumed table table=pending_closures1550--- PASS: TestClientMultipleUploads (0.48s)1551=== CONT TestService_createPendingClosureHandler15522026/10/10 19:00:53 INFO Vacuumed table table=pending_objects15532026/10/10 19:00:53 INFO Vacuumed table table=multipart_uploads15542026/10/10 19:00:53 INFO Vacuumed table table=closures15552026/10/10 19:00:53 INFO Vacuumed table table=objects1556=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1557=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1558=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1559=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1560=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1561=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1562=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1563=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1564=== CONT TestPushDedupSurvivesConcurrentGC15652026/10/10 19:00:53 INFO Aborted multipart uploads count=0 kept=015662026/10/10 19:00:53 INFO Starting cleanup of old closures method=DELETE path=/api/closures15672026/10/10 19:00:53 INFO Garbage collection started15682026/10/10 19:00:53 WARN Force mode enabled - objects will be deleted immediately without grace period15692026/10/10 19:00:53 INFO Aborted multipart uploads count=0 kept=015702026/10/10 19:00:53 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=015712026/10/10 19:00:53 INFO Vacuumed table table=pending_closures15722026/10/10 19:00:53 INFO Vacuumed table table=pending_objects15732026/10/10 19:00:53 INFO Vacuumed table table=multipart_uploads15742026/10/10 19:00:53 INFO Vacuumed table table=closures15752026/10/10 19:00:53 INFO Vacuumed table table=objects15762026/10/10 19:00:53 INFO Received uploads request method=POST path=/api/pending_closures15772026/10/10 19:00:53 WARN Force mode enabled - objects will be deleted immediately without grace period15782026/10/10 19:00:53 INFO Aborted multipart uploads count=0 kept=015792026/10/10 19:00:53 INFO Aborted multipart uploads count=0 kept=015802026/10/10 19:00:53 WARN Force mode enabled - objects will be deleted immediately without grace period15812026/10/10 19:00:53 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=015822026/10/10 19:00:53 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=015832026/10/10 19:00:53 WARN Force mode enabled - objects will be deleted immediately without grace period15842026/10/10 19:00:53 INFO Vacuumed table table=pending_closures15852026/10/10 19:00:53 INFO Vacuumed table table=pending_objects15862026/10/10 19:00:53 INFO Vacuumed table table=multipart_uploads15872026/10/10 19:00:53 INFO Vacuumed table table=pending_closures15882026/10/10 19:00:53 INFO Vacuumed table table=closures15892026/10/10 19:00:53 INFO Vacuumed table table=objects15902026/10/10 19:00:53 INFO Vacuumed table table=pending_objects15912026/10/10 19:00:53 INFO Vacuumed table table=multipart_uploads1592--- PASS: TestSweepSkipsRowsLockedByPush (0.30s)1593=== CONT TestGCSweepSkipsPendingObjects15942026/10/10 19:00:53 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."15952026/10/10 19:00:53 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."15962026/10/10 19:00:53 INFO Vacuumed table table=closures1597--- PASS: TestFailedS3DeleteKeepsTombstone (0.31s)1598=== CONT TestReadProxyOutlastsServerWriteTimeout15992026/10/10 19:00:53 INFO Vacuumed table table=objects1600--- PASS: TestService_ReadAuthMiddleware (0.24s)1601=== CONT TestDeduplicatedObjectsRecordedAsPending16022026/10/10 19:00:53 INFO Aborted multipart uploads count=0 kept=016032026/10/10 19:00:53 INFO Received push request method=POST path=/api/pushes16042026/10/10 19:00:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16052026/10/10 19:00:53 INFO Uploading 60822ccy4gmxrwy791g69ldh2qdn3gbl-ca-test (144B)16062026/10/10 19:00:53 WARN Force mode enabled - objects will be deleted immediately without grace period16072026/10/10 19:00:53 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16082026/10/10 19:00:53 WARN Failed to register uploaded object key=log/kb0nn5c2y8ylrshsyvgavhwfv8a183r3-ca-test.drv error="server returned 404: 404 page not found\n"16092026/10/10 19:00:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16102026/10/10 19:00:53 WARN Failed to register uploaded object key=60822ccy4gmxrwy791g69ldh2qdn3gbl.ls error="server returned 404: 404 page not found\n"16112026/10/10 19:00:53 INFO Signed narinfos id=1 count=116122026/10/10 19:00:53 INFO Uploading 1 narinfos16132026/10/10 19:00:53 INFO Received complete push request method=POST path=/api/pushes/1/complete16142026/10/10 19:00:53 WARN Failed to register uploaded object key=60822ccy4gmxrwy791g69ldh2qdn3gbl.narinfo error="server returned 404: 404 page not found\n"16152026/10/10 19:00:53 INFO Completed push id=1 objects=4 duration=6.476656ms16162026/10/10 19:00:53 INFO Upload complete. (95ms)16172026/10/10 19:00:53 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=016182026/10/10 19:00:53 INFO Vacuumed table table=pending_closures16192026/10/10 19:00:53 INFO Vacuumed table table=pending_objects16202026/10/10 19:00:53 INFO Vacuumed table table=multipart_uploads16212026/10/10 19:00:53 INFO Vacuumed table table=closures1622=== NAME TestClientCADerivations1623 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1224767548/001/store/60822ccy4gmxrwy791g69ldh2qdn3gbl-ca-test1624 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1625 Compression: zstd1626 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1627 NarSize: 1441628 References: 1629 Deriver: /build/TestClientCADerivations1224767548/001/store/kb0nn5c2y8ylrshsyvgavhwfv8a183r3-ca-test.drv1630 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1631 client_ca_test.go:185: Checking for realisation files in S3...1632 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1633 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache16342026/10/10 19:00:53 INFO Vacuumed table table=objects1635--- PASS: TestGCSweepDeliversEachKeyOnce (0.29s)1636=== CONT TestReadRedirectUsesPublicS3URL16372026/10/10 19:00:53 INFO Received uploads request method=POST path=/api/pending_closures16382026/10/10 19:00:53 INFO Aborted multipart uploads count=0 kept=016392026/10/10 19:00:53 WARN Force mode enabled - objects will be deleted immediately without grace period16402026/10/10 19:00:53 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=016412026/10/10 19:00:53 INFO Vacuumed table table=pending_closures16422026/10/10 19:00:53 INFO Received uploads request method=POST path=/api/pending_closures16432026/10/10 19:00:53 INFO Vacuumed table table=pending_objects16442026/10/10 19:00:53 INFO Vacuumed table table=multipart_uploads16452026/10/10 19:00:53 INFO Vacuumed table table=closures16462026/10/10 19:00:53 INFO Vacuumed table table=objects1647--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.31s)1648=== CONT TestGCMetrics1649--- PASS: TestGetExistingObjectsLocksRows (0.25s)1650=== CONT TestService_AuthMiddleware_MTLSProxyHeader16512026/10/10 19:00:53 INFO Aborted multipart uploads count=0 kept=01652=== NAME TestClientCADerivations1653 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1654 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1655 error: binary cache 's3://bucket52?endpoint=http://localhost:44485®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1224767548/001/store'1656 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 116572026/10/10 19:00:53 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16582026/10/10 19:00:53 WARN mTLS auth: bound subjects configured but subject DN unavailable16592026/10/10 19:00:53 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1660--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.27s)1661=== CONT TestReadProxyRangeRequest1662--- PASS: TestClientCADerivations (0.62s)1663=== CONT TestGCBugBareHashReferences16642026/10/10 19:00:53 WARN Force mode enabled - objects will be deleted immediately without grace period16652026/10/10 19:00:53 INFO Received uploads request method=POST path=/api/pending_closures16662026/10/10 19:00:53 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=016672026/10/10 19:00:53 INFO Received uploads request method=POST path=/api/pending_closures16682026/10/10 19:00:53 INFO Received uploads request method=POST path=/api/pending_closures16692026/10/10 19:00:53 INFO Vacuumed table table=pending_closures1670--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.43s)1671=== CONT TestReadProxyRootRedirectsToIndexHTML16722026/10/10 19:00:53 INFO Vacuumed table table=pending_objects16732026/10/10 19:00:53 INFO Vacuumed table table=multipart_uploads16742026/10/10 19:00:53 INFO Vacuumed table table=closures16752026/10/10 19:00:53 INFO Vacuumed table table=objects1676--- PASS: TestSweepRechecksPendingAfterLocking (0.33s)1677=== CONT TestReadProxyDisabled1678--- PASS: TestObjectStatsLargeCommit (1.76s)1679=== CONT TestReadProxyConditionalGet16802026/10/10 19:00:53 INFO Received uploads request method=POST path=/api/pending_closures16812026/10/10 19:00:53 INFO Received uploads request method=POST path=/api/pending_closures16822026/10/10 19:00:53 INFO Aborted multipart uploads count=0 kept=016832026/10/10 19:00:53 WARN Force mode enabled - objects will be deleted immediately without grace period16842026/10/10 19:00:53 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=016852026/10/10 19:00:53 INFO Vacuumed table table=pending_closures16862026/10/10 19:00:53 INFO Vacuumed table table=pending_objects16872026/10/10 19:00:53 INFO Vacuumed table table=multipart_uploads16882026/10/10 19:00:53 INFO Vacuumed table table=closures16892026/10/10 19:00:53 INFO Vacuumed table table=objects1690--- PASS: TestGCSweepSkipsPendingObjects (0.27s)1691=== CONT TestReadRedirectKeepsNarinfoProxied16922026/10/10 19:00:53 INFO Received uploads request method=POST path=/api/pending_closures1693--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.27s)1694=== CONT TestReadRedirectNar16952026/10/10 19:00:53 INFO Aborted multipart uploads count=0 kept=016962026/10/10 19:00:53 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=016972026/10/10 19:00:53 INFO Vacuumed table table=pending_closures16982026/10/10 19:00:53 INFO Vacuumed table table=pending_objects16992026/10/10 19:00:53 INFO Vacuumed table table=multipart_uploads17002026/10/10 19:00:53 INFO Vacuumed table table=closures17012026/10/10 19:00:53 INFO Vacuumed table table=objects1702--- PASS: TestReadRedirectUsesPublicS3URL (0.27s)1703=== CONT TestReadProxyNarStreaming17042026/10/10 19:00:53 INFO Aborted multipart uploads count=0 kept=017052026/10/10 19:00:53 WARN Force mode enabled - objects will be deleted immediately without grace period17062026/10/10 19:00:53 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=017072026/10/10 19:00:53 INFO Vacuumed table table=pending_closures17082026/10/10 19:00:53 INFO Vacuumed table table=pending_objects17092026/10/10 19:00:53 INFO Vacuumed table table=multipart_uploads17102026/10/10 19:00:53 INFO Vacuumed table table=closures17112026/10/10 19:00:53 INFO Aborted multipart uploads count=0 kept=017122026/10/10 19:00:53 INFO Vacuumed table table=objects1713--- PASS: TestPushDedupSurvivesConcurrentGC (0.38s)1714=== CONT TestReadProxyNarinfoAlreadyDecompressed17152026/10/10 19:00:53 WARN Force mode enabled - objects will be deleted immediately without grace period17162026/10/10 19:00:53 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=017172026/10/10 19:00:53 INFO Vacuumed table table=pending_closures17182026/10/10 19:00:53 INFO Vacuumed table table=pending_objects17192026/10/10 19:00:53 INFO Vacuumed table table=multipart_uploads17202026/10/10 19:00:53 INFO Vacuumed table table=closures17212026/10/10 19:00:53 INFO Vacuumed table table=objects1722--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.22s)1723=== CONT TestReadProxy4041724--- PASS: TestGCMetrics (0.25s)1725=== CONT TestReadProxyContentNegotiation1726--- PASS: TestReadProxyRangeRequest (0.22s)1727=== CONT TestReadProxyInvalidPath17282026/10/10 19:00:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17292026/10/10 19:00:53 INFO lead: released remote=192.0.2.1:12341730--- PASS: TestLeadEndsOnShutdown (1.59s)1731=== CONT TestReadProxyHead17322026/10/10 19:00:53 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YzEzNzY0MTEtZDA0OC00ZWY0LWE4NjYtYzM2YjM5OTc1NTEwLjA2YWY5MGU1LWVkNWItNGU5Yi1iNDlhLTJlNGM4YjdkMTc5MHgxNzkxNjU4ODUzNDA1MjE5OTAy parts=1017332026/10/10 19:00:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17342026/10/10 19:00:53 INFO Completed upload id=1 objects=2 duration=2.822765ms17352026/10/10 19:00:53 INFO Received uploads request method=POST path=/api/pending_closures17362026/10/10 19:00:53 INFO Received uploads request method=POST path=/api/pending_closures17372026/10/10 19:00:53 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo17382026/10/10 19:00:53 WARN Found objects in DB but missing from S3, will re-upload count=11739--- PASS: TestService_verifyS3Integrity (0.60s)1740=== CONT TestReadProxyNarinfo1741--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.23s)1742=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1743--- PASS: TestReadProxyDisabled (0.25s)1744=== CONT TestParseSingleRange/none1745=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1746--- PASS: TestReadProxyConditionalGet (0.25s)1747=== CONT TestIsValidCachePath/narinfo1748=== CONT TestIsValidCachePath/short_hash1749=== CONT TestIsValidCachePath/wrong_extension1750=== CONT TestIsValidCachePath/leading_slash1751=== CONT TestIsValidCachePath/empty1752=== CONT TestIsValidCachePath/random_path1753=== CONT TestIsValidCachePath/invalid_char_u1754=== CONT TestIsValidCachePath/invalid_char_e1755=== CONT TestIsValidCachePath/traversal_in_middle1756=== CONT TestIsValidCachePath/traversal_parent1757=== CONT TestIsValidCachePath/index.html1758=== CONT TestIsValidCachePath/nix-cache-info1759=== CONT TestIsValidCachePath/realisation1760=== CONT TestIsValidCachePath/log1761=== CONT TestIsValidCachePath/ls1762=== CONT TestIsValidCachePath/nar_uncompressed1763=== CONT TestIsValidCachePath/nar_bz21764=== CONT TestIsValidCachePath/nar_xz1765=== CONT TestIsValidCachePath/nar_zst1766=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1767--- PASS: TestIsValidCachePath (0.01s)1768 --- PASS: TestIsValidCachePath/narinfo (0.00s)1769 --- PASS: TestIsValidCachePath/short_hash (0.00s)1770 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1771 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1772 --- PASS: TestIsValidCachePath/empty (0.00s)1773 --- PASS: TestIsValidCachePath/random_path (0.00s)1774 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1775 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1776 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1777 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1778 --- PASS: TestIsValidCachePath/index.html (0.00s)1779 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1780 --- PASS: TestIsValidCachePath/realisation (0.00s)1781 --- PASS: TestIsValidCachePath/log (0.00s)1782 --- PASS: TestIsValidCachePath/ls (0.00s)1783 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1784 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1785 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1786 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1787 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1788=== CONT TestParseSingleRange/open-ended1789=== CONT TestParseSingleRange/start_far_past_EOF1790=== CONT TestParseSingleRange/start_past_EOF1791=== CONT TestParseSingleRange/single_byte1792=== CONT TestParseSingleRange/suffix_exceeds_size1793=== CONT TestParseSingleRange/suffix1794=== CONT TestParseSingleRange/end_clamped_to_size1795=== CONT TestParseSingleRange/malformed_both_empty1796=== CONT TestParseSingleRange/closed1797=== CONT TestParseSingleRange/malformed_end_before_start1798=== CONT TestParseSingleRange/multi-range_ignored1799=== CONT TestParseSingleRange/malformed_no_dash1800=== CONT TestParseSingleRange/unknown_unit1801--- PASS: TestParseSingleRange (0.00s)1802 --- PASS: TestParseSingleRange/none (0.00s)1803 --- PASS: TestParseSingleRange/open-ended (0.00s)1804 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1805 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1806 --- PASS: TestParseSingleRange/single_byte (0.00s)1807 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1808 --- PASS: TestParseSingleRange/suffix (0.00s)1809 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1810 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1811 --- PASS: TestParseSingleRange/closed (0.00s)1812 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1813 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1814 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1815 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1816=== CONT TestPush_RejectsBadRequests/no_objects18172026/10/10 19:00:53 INFO Received push request method=POST path=/api/pushes1818=== CONT TestPush_RejectsBadRequests/root_not_in_objects18192026/10/10 19:00:53 INFO Received push request method=POST path=/api/pushes1820=== CONT TestPush_RejectsBadRequests/no_roots18212026/10/10 19:00:53 INFO Received push request method=POST path=/api/pushes1822=== CONT TestPush_RejectsBadRequests/bad_root18232026/10/10 19:00:53 INFO Received push request method=POST path=/api/pushes1824=== CONT TestServerTLSConfig/no_client_CA1825=== CONT TestServerTLSConfig/missing_CA_file1826--- PASS: TestPush_RejectsBadRequests (0.46s)1827 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1828 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1829 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1830 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1831=== CONT TestServerTLSConfig/not_a_PEM_file1832--- PASS: TestServerTLSConfig (0.00s)1833 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1834 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1835 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1836=== CONT TestResolveDBConnectionString/flag_wins1837=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1838=== CONT TestResolveDBConnectionString/nothing_configured1839=== CONT TestResolveDBConnectionString/file_when_flag_empty1840=== CONT TestResolveDBConnectionString/missing_file_is_an_error1841--- PASS: TestResolveDBConnectionString (0.00s)1842 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1843 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1844 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1845 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1846 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1847=== CONT TestIsValidUploadKey/narinfo1848=== CONT TestIsValidUploadKey/unknown_type1849=== CONT TestIsValidUploadKey/empty_key1850=== CONT TestIsValidUploadKey/absolute1851=== CONT TestIsValidUploadKey/traversal_nar1852=== CONT TestIsValidUploadKey/traversal1853=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1854=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1855=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1856=== CONT TestIsValidUploadKey/index.html1857=== CONT TestIsValidUploadKey/nix-cache-info1858=== CONT TestIsValidUploadKey/realisation_plus_in_output1859=== CONT TestIsValidUploadKey/realisation1860=== CONT TestIsValidUploadKey/build_log_equals1861=== CONT TestIsValidUploadKey/build_log_question_mark1862=== CONT TestIsValidUploadKey/build_log_plus_in_name1863=== CONT TestIsValidUploadKey/build_log_home-manager_file1864=== CONT TestIsValidUploadKey/build_log1865=== CONT TestIsValidUploadKey/listing1866=== CONT TestIsValidUploadKey/nar_plain1867=== CONT TestIsValidUploadKey/nar_zst1868=== CONT TestIsValidUploadKey/nar_xz1869--- PASS: TestIsValidUploadKey (0.00s)1870 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1871 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1872 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1873 --- PASS: TestIsValidUploadKey/absolute (0.00s)1874 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1875 --- PASS: TestIsValidUploadKey/traversal (0.00s)1876 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1877 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1878 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1879 --- PASS: TestIsValidUploadKey/index.html (0.00s)1880 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1881 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1882 --- PASS: TestIsValidUploadKey/realisation (0.00s)1883 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1884 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1885 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1886 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1887 --- PASS: TestIsValidUploadKey/build_log (0.00s)1888 --- PASS: TestIsValidUploadKey/listing (0.00s)1889 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1890 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1891 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1892=== CONT TestPendingClosureWriteTimeout/empty1893=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline18942026/10/10 19:00:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1895--- PASS: TestReadRedirectKeepsNarinfoProxied (0.22s)1896=== CONT TestPendingClosureWriteTimeout/670k_objects1897=== CONT TestPendingClosureWriteTimeout/400_objects1898=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18992026/10/10 19:00:53 INFO Received uploads request method=POST path=/1900=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key19012026/10/10 19:00:53 INFO Received complete multipart upload request method=POST path=/1902=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key19032026/10/10 19:00:53 INFO Received request for more parts method=POST path=/1904=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal19052026/10/10 19:00:53 INFO Received uploads request method=POST path=/1906--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1907 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1908 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1909 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1910 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1911=== CONT TestCacheConfigHandler/full_config,_no_issuer1912=== CONT TestCacheConfigHandler/no_signing_keys1913=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1914=== CONT TestCacheConfigHandler/no_cache_url_configured1915=== CONT TestProxyWriteTimeout/narinfo1916--- PASS: TestCacheConfigHandler (0.00s)1917 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1918 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1919 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1920 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1921=== CONT TestProxyWriteTimeout/10_GiB_nar1922=== CONT TestProxyWriteTimeout/unknown_size1923=== CONT TestProxyWriteTimeout/1_GiB_nar1924--- PASS: TestProxyWriteTimeout (0.00s)1925 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1926 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1927 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1928 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1929=== CONT TestClientErrorHandling/InvalidStorePath19302026/10/10 19:00:53 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YzEzNzY0MTEtZDA0OC00ZWY0LWE4NjYtYzM2YjM5OTc1NTEwLjRlOWU1ZjI5LTU1NGQtNGZkZi05Yzk2LWI5ZTcxMjBhYzdkYXgxNzkxNjU4ODUzNTE4NzM5Njc5 parts=1019312026/10/10 19:00:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19322026/10/10 19:00:53 INFO Completed upload id=1 objects=2 duration=3.941474ms19332026/10/10 19:00:53 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001934--- PASS: TestReadRedirectNar (0.23s)1935=== CONT TestClientErrorHandling/InvalidAuthToken19362026/10/10 19:00:53 INFO Received uploads request method=POST path=/api/pending_closures19372026/10/10 19:00:53 INFO Starting cleanup of old closures method=DELETE path=/api/closures19382026/10/10 19:00:53 INFO Aborted multipart uploads count=0 kept=019392026/10/10 19:00:53 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=019402026/10/10 19:00:53 INFO Vacuumed table table=pending_closures1941--- PASS: TestReadProxyNarStreaming (0.23s)1942=== CONT TestClientErrorHandling/ServerNotAvailable19432026/10/10 19:00:53 INFO Vacuumed table table=pending_objects19442026/10/10 19:00:53 INFO Vacuumed table table=multipart_uploads19452026/10/10 19:00:53 INFO Vacuumed table table=closures19462026/10/10 19:00:53 INFO Vacuumed table table=objects1947--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.24s)1948=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19492026/10/10 19:00:53 INFO Received uploads request method=POST path=/19502026/10/10 19:00:53 INFO lead: released remote=192.0.2.1:123419512026/10/10 19:00:53 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001952--- PASS: TestService_createPendingClosureHandler (0.65s)1953=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts19542026/10/10 19:00:53 INFO Received request for more parts method=POST path=/1955--- PASS: TestPushWaitsForSweepHoldingRow (0.78s)1956=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19572026/10/10 19:00:53 INFO Received complete multipart upload request method=POST path=/1958--- PASS: TestGCBugBareHashReferences (0.45s)1959=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1960--- PASS: TestReadProxy404 (0.27s)1961=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows19622026/10/10 19:00:53 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/present19632026/10/10 19:00:53 INFO lead: acquired remote=192.0.2.1:12341964--- PASS: TestReadProxyInvalidPath (0.25s)1965=== CONT TestGCEndsOnShutdown/before_the_run1966=== NAME TestOrphanedObjectsGCStressTest1967 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1968=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1969=== NAME TestOrphanedObjectsGCStressTest1970 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion1971=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1972--- PASS: TestReadProxyHead (0.28s)1973=== CONT TestService_RequireScope_OIDC/builder_may_write1974=== CONT TestService_RequireScope_OIDC/reader_may_read1975=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1976=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19772026/10/10 19:00:54 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]1978=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1979=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1980=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1981=== CONT TestService_RequireScope_OIDC/writer_implies_read1982=== CONT TestService_RequireScope_OIDC/ops_may_admin1983=== CONT TestService_RequireScope_OIDC/reader_may_not_write1984=== CONT TestService_RequireScope_OIDC/ops_may_not_write1985=== CONT TestService_RequireScope_OIDC/static_token_may_write1986=== CONT TestService_RequireScope_OIDC/static_token_may_admin1987=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1988=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1989--- PASS: TestService_RequireScope_OIDC (0.33s)1990 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1991 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1992 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1993 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1994 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1995 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1996 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1997 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1998 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1999 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2000 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2001 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2002 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2003 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2004=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20052026/10/10 19:00:54 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]2006=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2007=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20082026/10/10 19:00:54 WARN Authentication failed token_preview=eyJhbGciOi..._eOd5HmgpQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2009--- PASS: TestService_AuthMiddleware_OIDC (0.49s)2010 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2011 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2012 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2013 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2014--- PASS: TestReadProxyContentNegotiation (0.37s)20152026/10/10 19:00:54 WARN Request failed, retrying attempt=2 backoff=187.761807ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20162026/10/10 19:00:54 INFO Received uploads request method=POST path=/api/pending_closures20172026/10/10 19:00:54 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>2018--- PASS: TestReadProxyNarinfo (0.34s)20192026/10/10 19:00:54 INFO Received uploads request method=POST path=/api/pending_closures20202026/10/10 19:00:54 INFO Aborted multipart uploads count=0 kept=020212026/10/10 19:00:54 WARN Force mode enabled - objects will be deleted immediately without grace period20222026/10/10 19:00:54 INFO Received uploads request method=POST path=/api/pending_closures20232026/10/10 19:00:54 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=020242026/10/10 19:00:54 INFO Vacuumed table table=pending_closures20252026/10/10 19:00:54 INFO Vacuumed table table=pending_objects20262026/10/10 19:00:54 INFO Vacuumed table table=multipart_uploads20272026/10/10 19:00:54 INFO Vacuumed table table=closures20282026/10/10 19:00:54 INFO Vacuumed table table=objects20292026/10/10 19:00:54 INFO Aborted multipart uploads count=0 kept=020302026/10/10 19:00:54 WARN Force mode enabled - objects will be deleted immediately without grace period20312026/10/10 19:00:54 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=020322026/10/10 19:00:54 INFO Vacuumed table table=pending_closures20332026/10/10 19:00:54 INFO Vacuumed table table=pending_objects20342026/10/10 19:00:54 INFO Vacuumed table table=multipart_uploads20352026/10/10 19:00:54 INFO Vacuumed table table=closures20362026/10/10 19:00:54 INFO Vacuumed table table=objects20372026/10/10 19:00:54 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2038--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2039 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.20s)2040 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.23s)20412026/10/10 19:00:54 INFO Aborted multipart uploads count=0 kept=020422026/10/10 19:00:54 WARN Force mode enabled - objects will be deleted immediately without grace period20432026/10/10 19:00:54 INFO Aborted multipart uploads count=0 kept=020442026/10/10 19:00:54 WARN Force mode enabled - objects will be deleted immediately without grace period20452026/10/10 19:00:54 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2046--- PASS: TestDeleteClosuresRacingPins (1.76s)20472026/10/10 19:00:54 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:44485/bucket100/?delete=\": context canceled"2048--- PASS: TestGCEndsOnShutdown (0.00s)2049 --- PASS: TestGCEndsOnShutdown/before_the_run (0.19s)2050 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.21s)2051 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.20s)20522026/10/10 19:00:54 WARN Request failed, retrying attempt=3 backoff=422.028692ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2053=== NAME TestOrphanedObjectsGCStressTest2054 orphaned_objects_gc_test.go:503: Stress test completed successfully:2055 orphaned_objects_gc_test.go:504: - Active objects preserved: 202056 orphaned_objects_gc_test.go:505: - Objects deleted: 2102057 orphaned_objects_gc_test.go:506: - Total GC'd: 2102058--- PASS: TestOrphanedObjectsGCStressTest (2.47s)2059--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2060 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.77s)2061 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.78s)20622026/10/10 19:00:54 WARN Request failed, retrying attempt=4 backoff=779.368508ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2063--- PASS: TestPendingClosureWriteTimeout (0.00s)2064 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2065 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2066 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2067 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.05s)2068--- PASS: TestUploadHandlersRejectOversizedBody (0.17s)2069 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)2070 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)2071 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.04s)20722026/10/10 19:00:55 INFO lead: released remote=192.0.2.1:12342073--- PASS: TestLeadElectsOneAndHandsOver (2.76s)20742026/10/10 19:00:55 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020752026/10/10 19:00:55 INFO Received create pin request method=POST path=/api/pins/myapp20762026/10/10 19:00:55 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3808175492/001/store/0pqwzybnz1ar67g851ndggindgw6kgm1-pinned-file.txt narinfo_key=0pqwzybnz1ar67g851ndggindgw6kgm1.narinfo20772026/10/10 19:00:55 INFO Starting cleanup of old closures method=DELETE path=/api/closures20782026/10/10 19:00:55 INFO Garbage collection started20792026/10/10 19:00:55 INFO Aborted multipart uploads count=0 kept=020802026/10/10 19:00:55 WARN Force mode enabled - objects will be deleted immediately without grace period20812026/10/10 19:00:55 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=020822026/10/10 19:00:55 INFO Vacuumed table table=pending_closures20832026/10/10 19:00:55 INFO Vacuumed table table=pending_objects20842026/10/10 19:00:55 INFO Vacuumed table table=multipart_uploads20852026/10/10 19:00:55 INFO Vacuumed table table=closures20862026/10/10 19:00:55 INFO Vacuumed table table=objects20872026/10/10 19:00:55 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02088=== NAME TestClientIntegration2089 client_integration_test.go:323: Objects in database after GC:2090 client_integration_test.go:323: Successfully deleted all objects with GC --force2091--- PASS: TestClientIntegration (2.49s)20922026/10/10 19:00:55 WARN Request failed, retrying attempt=5 backoff=1.630438103s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20932026/10/10 19:00:56 WARN Rate limiter enabled after throttle name=s3-test rate=520942026/10/10 19:00:56 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2095=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2096 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102097 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002098--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.47s)20992026/10/10 19:00:57 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-config21002026/10/10 19:00:57 WARN Request failed, retrying attempt=2 backoff=213.374146ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2101=== NAME TestPinProtectsFromGC2102 client_integration_test.go:840: Pin successfully protected closure from garbage collection2103--- PASS: TestPinProtectsFromGC (4.61s)21042026/10/10 19:00:57 WARN Request failed, retrying attempt=3 backoff=404.741191ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2105--- PASS: TestConnectWaitsForAPeerMigration (5.13s)2106--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.45s)21072026/10/10 19:00:57 WARN Request failed, retrying attempt=4 backoff=765.951694ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21082026/10/10 19:00:58 WARN Request failed, retrying attempt=5 backoff=1.5998576s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21092026/10/10 19:00:58 INFO Aborted multipart uploads count=1 kept=021102026/10/10 19:00:58 INFO Received cleanup request method=DELETE path=/api/pending_closures21112026/10/10 19:00:58 INFO Aborted multipart uploads count=1 kept=02112--- PASS: TestPendingCleanupUsesOneCutoff (6.50s)21132026/10/10 19:01:00 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"21142026/10/10 19:01:00 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-config21152026/10/10 19:01:00 WARN Request failed, retrying attempt=2 backoff=184.657302ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21162026/10/10 19:01:00 WARN Request failed, retrying attempt=3 backoff=439.281859ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21172026/10/10 19:01:00 WARN Request failed, retrying attempt=4 backoff=838.831917ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21182026/10/10 19:01:01 WARN Request failed, retrying attempt=5 backoff=1.579702655s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21192026/10/10 19:01:03 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_closures21202026/10/10 19:01:03 WARN Request failed, retrying attempt=2 backoff=185.619484ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21212026/10/10 19:01:03 WARN Request failed, retrying attempt=3 backoff=386.738789ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21222026/10/10 19:01:04 WARN Request failed, retrying attempt=4 backoff=765.476542ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21232026/10/10 19:01:04 WARN Request failed, retrying attempt=5 backoff=1.462082612s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2124--- PASS: TestClientErrorHandling (0.00s)2125 --- PASS: TestClientErrorHandling/InvalidStorePath (0.28s)2126 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.35s)2127 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.38s)2128PASS21292026-10-10 19:01:06.531 UTC [130] LOG: received smart shutdown request21302026-10-10 19:01:06.535 UTC [130] LOG: background worker "logical replication launcher" (PID 140) exited with exit code 121312026-10-10 19:01:06.550 UTC [135] LOG: shutting down21322026-10-10 19:01:06.550 UTC [135] LOG: checkpoint starting: shutdown immediate21332026-10-10 19:01:07.363 UTC [135] LOG: checkpoint complete: wrote 10946 buffers (66.8%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.193 s, sync=0.589 s, total=0.814 s; sync files=34045, longest=0.078 s, average=0.001 s; distance=531570 kB, estimate=531570 kB; lsn=0/21E825E8, redo lsn=0/21E825E821342026-10-10 19:01:07.446 UTC [130] LOG: database system is shut down2135Running OIDC tests...2136=== RUN TestAudienceForIssuer2137=== PAUSE TestAudienceForIssuer2138=== RUN TestGlobMatch2139=== PAUSE TestGlobMatch2140=== RUN TestValidateToken_ValidToken2141=== PAUSE TestValidateToken_ValidToken2142=== RUN TestValidateToken_WrongAudience2143=== PAUSE TestValidateToken_WrongAudience2144=== RUN TestValidateToken_Expired2145=== PAUSE TestValidateToken_Expired2146=== RUN TestValidateToken_BoundClaimsMismatch2147=== PAUSE TestValidateToken_BoundClaimsMismatch2148=== RUN TestValidateToken_BoundSubjectMismatch2149=== PAUSE TestValidateToken_BoundSubjectMismatch2150=== RUN TestValidateToken_MultipleProviders2151=== PAUSE TestValidateToken_MultipleProviders2152=== RUN TestValidateToken_NoMatchingProvider2153=== PAUSE TestValidateToken_NoMatchingProvider2154=== RUN TestValidateToken_KubernetesServiceAccount2155=== PAUSE TestValidateToken_KubernetesServiceAccount2156=== RUN TestNewValidator_KubernetesRequiresCA2157=== PAUSE TestNewValidator_KubernetesRequiresCA2158=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2159=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2160=== RUN TestPins_ReservedForMatchingRule2161=== PAUSE TestPins_ReservedForMatchingRule2162=== RUN TestPins_TopLevelShorthand2163=== PAUSE TestPins_TopLevelShorthand2164=== RUN TestPins_ConfigValidation2165=== PAUSE TestPins_ConfigValidation2166=== RUN TestScopes_LegacyProviderDefaultsToWrite2167=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2168=== RUN TestScopes_Rules2169=== PAUSE TestScopes_Rules2170=== RUN TestScopes_ConfigValidation2171=== PAUSE TestScopes_ConfigValidation2172=== CONT TestAudienceForIssuer2173=== CONT TestPins_ConfigValidation2174=== CONT TestValidateToken_KubernetesServiceAccount2175--- PASS: TestAudienceForIssuer (0.00s)2176=== CONT TestValidateToken_NoMatchingProvider2177=== CONT TestValidateToken_MultipleProviders2178=== CONT TestValidateToken_BoundSubjectMismatch2179=== CONT TestValidateToken_BoundClaimsMismatch2180=== CONT TestValidateToken_Expired2181--- PASS: TestPins_ConfigValidation (0.00s)2182=== CONT TestValidateToken_WrongAudience2183=== CONT TestValidateToken_ValidToken2184=== CONT TestGlobMatch2185=== RUN TestGlobMatch/foo_foo2186=== PAUSE TestGlobMatch/foo_foo2187=== RUN TestGlobMatch/foo_bar2188=== PAUSE TestGlobMatch/foo_bar2189=== RUN TestGlobMatch/*_2190=== PAUSE TestGlobMatch/*_2191=== RUN TestGlobMatch/*_anything2192=== PAUSE TestGlobMatch/*_anything2193=== RUN TestGlobMatch/foo*_foo2194=== PAUSE TestGlobMatch/foo*_foo2195=== RUN TestGlobMatch/foo*_foobar2196=== PAUSE TestGlobMatch/foo*_foobar2197=== RUN TestGlobMatch/foo*_bar2198=== PAUSE TestGlobMatch/foo*_bar2199=== RUN TestGlobMatch/*bar_bar2200=== PAUSE TestGlobMatch/*bar_bar2201=== CONT TestPins_TopLevelShorthand2202=== CONT TestScopes_Rules2203=== CONT TestScopes_ConfigValidation2204=== CONT TestScopes_LegacyProviderDefaultsToWrite2205=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2206=== CONT TestNewValidator_KubernetesRequiresCA2207=== CONT TestPins_ReservedForMatchingRule2208=== RUN TestGlobMatch/*bar_foobar2209=== PAUSE TestGlobMatch/*bar_foobar2210=== RUN TestGlobMatch/*bar_foo2211=== PAUSE TestGlobMatch/*bar_foo2212=== RUN TestGlobMatch/foo*bar_foobar2213=== PAUSE TestGlobMatch/foo*bar_foobar2214=== RUN TestGlobMatch/foo*bar_foo123bar2215=== PAUSE TestGlobMatch/foo*bar_foo123bar2216=== RUN TestGlobMatch/foo*bar_foobarbaz2217=== PAUSE TestGlobMatch/foo*bar_foobarbaz2218=== RUN TestGlobMatch/*/*_foo/bar2219=== PAUSE TestGlobMatch/*/*_foo/bar2220=== RUN TestGlobMatch/*/*_foo2221=== PAUSE TestGlobMatch/*/*_foo2222=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2223=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2224=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02225=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02226=== RUN TestGlobMatch/refs/*/main_refs/heads/main2227=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2228=== RUN TestGlobMatch/fo?_foo2229=== PAUSE TestGlobMatch/fo?_foo2230=== RUN TestGlobMatch/fo?_fo2231=== PAUSE TestGlobMatch/fo?_fo2232=== RUN TestGlobMatch/fo?_fooo2233=== PAUSE TestGlobMatch/fo?_fooo2234=== RUN TestGlobMatch/?oo_foo2235=== PAUSE TestGlobMatch/?oo_foo2236=== RUN TestGlobMatch/?oo_boo2237=== PAUSE TestGlobMatch/?oo_boo2238=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2239=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2240=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2241=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2242=== CONT TestGlobMatch/foo_foo2243=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2244=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2245=== CONT TestGlobMatch/?oo_boo2246=== CONT TestGlobMatch/?oo_foo2247=== CONT TestGlobMatch/fo?_fooo2248=== CONT TestGlobMatch/fo?_fo2249=== CONT TestGlobMatch/fo?_foo2250=== CONT TestGlobMatch/refs/*/main_refs/heads/main2251=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02252=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2253=== CONT TestGlobMatch/*/*_foo2254=== CONT TestGlobMatch/*/*_foo/bar2255=== CONT TestGlobMatch/foo*bar_foobarbaz2256=== CONT TestGlobMatch/foo*bar_foo123bar2257=== CONT TestGlobMatch/foo*bar_foobar2258=== CONT TestGlobMatch/*bar_foo2259=== CONT TestGlobMatch/*bar_foobar2260=== CONT TestGlobMatch/*bar_bar2261=== CONT TestGlobMatch/foo*_bar2262=== CONT TestGlobMatch/foo*_foobar2263=== CONT TestGlobMatch/foo*_foo2264=== CONT TestGlobMatch/*_anything2265=== CONT TestGlobMatch/*_2266=== CONT TestGlobMatch/foo_bar2267--- PASS: TestGlobMatch (0.00s)2268 --- PASS: TestGlobMatch/foo_foo (0.00s)2269 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2270 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2271 --- PASS: TestGlobMatch/?oo_boo (0.00s)2272 --- PASS: TestGlobMatch/?oo_foo (0.00s)2273 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2274 --- PASS: TestGlobMatch/fo?_fo (0.00s)2275 --- PASS: TestGlobMatch/fo?_foo (0.00s)2276 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2277 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2278 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2279 --- PASS: TestGlobMatch/*/*_foo (0.00s)2280 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2281 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2282 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2283 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2284 --- PASS: TestGlobMatch/*bar_foo (0.00s)2285 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2286 --- PASS: TestGlobMatch/*bar_bar (0.00s)2287 --- PASS: TestGlobMatch/foo*_bar (0.00s)2288 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2289 --- PASS: TestGlobMatch/foo*_foo (0.00s)2290 --- PASS: TestGlobMatch/*_anything (0.00s)2291 --- PASS: TestGlobMatch/*_ (0.00s)2292 --- PASS: TestGlobMatch/foo_bar (0.00s)2293--- PASS: TestScopes_ConfigValidation (0.00s)22942026/10/10 19:01:09 http: TLS handshake error from 127.0.0.1:48338: remote error: tls: bad certificate2295--- PASS: TestNewValidator_KubernetesRequiresCA (0.08s)22962026/10/10 19:01:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41491/oidc22972026/10/10 19:01:09 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:348032298--- PASS: TestValidateToken_BoundSubjectMismatch (0.09s)2299--- PASS: TestValidateToken_KubernetesServiceAccount (0.10s)23002026/10/10 19:01:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38319/oidc23012026/10/10 19:01:09 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232302--- PASS: TestPins_TopLevelShorthand (0.09s)2303--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.10s)23042026/10/10 19:01:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39661/oidc23052026/10/10 19:01:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41241/oidc2306--- PASS: TestValidateToken_BoundClaimsMismatch (0.10s)23072026/10/10 19:01:09 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:42207/oidc23082026/10/10 19:01:09 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:40661/oidc2309--- PASS: TestPins_ReservedForMatchingRule (0.11s)2310--- PASS: TestValidateToken_MultipleProviders (0.11s)23112026/10/10 19:01:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44985/oidc2312--- PASS: TestScopes_Rules (0.13s)23132026/10/10 19:01:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40473/oidc2314--- PASS: TestValidateToken_ValidToken (0.13s)23152026/10/10 19:01:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35367/oidc2316--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.17s)23172026/10/10 19:01:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32899/oidc2318--- PASS: TestValidateToken_WrongAudience (0.20s)23192026/10/10 19:01:09 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:33449/oidc2320--- PASS: TestValidateToken_NoMatchingProvider (0.31s)23212026/10/10 19:01:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35405/oidc2322--- PASS: TestValidateToken_Expired (0.40s)2323PASS2324Running hook tests...2325=== RUN TestSendPathsEmpty2326=== PAUSE TestSendPathsEmpty2327=== RUN TestQueueEnqueueAndFetch2328=== PAUSE TestQueueEnqueueAndFetch2329=== RUN TestQueueDeduplication2330=== PAUSE TestQueueDeduplication2331=== RUN TestQueueRemove2332=== PAUSE TestQueueRemove2333=== RUN TestQueueFetchBatchLimit2334=== PAUSE TestQueueFetchBatchLimit2335=== RUN TestQueueRetryMovesToBack2336=== PAUSE TestQueueRetryMovesToBack2337=== RUN TestQueueFetchRemoveLifecycle2338=== PAUSE TestQueueFetchRemoveLifecycle2339=== RUN TestQueueConcurrentWriters2340=== PAUSE TestQueueConcurrentWriters2341=== RUN TestQueueRemoveLargeClosure2342=== PAUSE TestQueueRemoveLargeClosure2343=== RUN TestServerClientIntegration2344--- PASS: TestServerClientIntegration (0.00s)2345=== RUN TestServerQueueError23462026/10/10 19:01:09 ERROR Failed to queue paths error="permission denied" count=12347--- PASS: TestServerQueueError (0.00s)2348=== RUN TestGetListenerSocketActivation2349 server_test.go:219: === RUN TestGetListenerSocketActivation2350 --- PASS: TestGetListenerSocketActivation (0.00s)2351 PASS2352 2353--- PASS: TestGetListenerSocketActivation (0.01s)2354=== RUN TestDrainIsolatesPoisonPath2355=== PAUSE TestDrainIsolatesPoisonPath2356=== RUN TestRunNotBlockedByPoisonHead2357=== PAUSE TestRunNotBlockedByPoisonHead2358=== RUN TestDrainGivesUpWhenServerDown2359=== PAUSE TestDrainGivesUpWhenServerDown2360=== RUN TestFailedPathPrunedByLaterClosure2361=== PAUSE TestFailedPathPrunedByLaterClosure2362=== RUN TestWorkerUploadsAndRemoves2363=== PAUSE TestWorkerUploadsAndRemoves2364=== RUN TestWorkerSkipsGCdPaths2365=== PAUSE TestWorkerSkipsGCdPaths2366=== RUN TestWorkerPrunesClosureDeps2367=== PAUSE TestWorkerPrunesClosureDeps2368=== RUN TestDrainTimeout2369=== PAUSE TestDrainTimeout2370=== CONT TestSendPathsEmpty2371=== CONT TestWorkerPrunesClosureDeps2372--- PASS: TestSendPathsEmpty (0.00s)2373=== CONT TestQueueRemoveLargeClosure2374=== CONT TestDrainTimeout2375=== CONT TestQueueConcurrentWriters2376=== CONT TestQueueFetchRemoveLifecycle2377=== CONT TestFailedPathPrunedByLaterClosure2378=== CONT TestQueueRetryMovesToBack2379=== CONT TestWorkerSkipsGCdPaths2380=== CONT TestQueueFetchBatchLimit2381=== CONT TestQueueRemove2382=== CONT TestWorkerUploadsAndRemoves2383=== CONT TestQueueDeduplication2384=== CONT TestQueueEnqueueAndFetch2385=== CONT TestRunNotBlockedByPoisonHead2386=== CONT TestDrainGivesUpWhenServerDown2387=== CONT TestDrainIsolatesPoisonPath23882026/10/10 19:01:09 INFO Uploading batch count=223892026/10/10 19:01:09 INFO Upload queue status pending=223902026/10/10 19:01:09 INFO Uploading batch count=223912026/10/10 19:01:09 ERROR Upload failed error="upload failed" count=223922026/10/10 19:01:09 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown267055087/002/a23932026/10/10 19:01:09 INFO Uploading batch count=12394--- PASS: TestQueueRetryMovesToBack (0.01s)23952026/10/10 19:01:09 INFO Uploading batch count=423962026/10/10 19:01:09 ERROR Upload failed error="upload failed" count=42397--- PASS: TestQueueFetchRemoveLifecycle (0.01s)23982026/10/10 19:01:09 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown267055087/002/b23992026/10/10 19:01:09 INFO Upload queue status pending=22400--- PASS: TestQueueFetchBatchLimit (0.01s)24012026/10/10 19:01:09 INFO Uploading batch count=124022026/10/10 19:01:09 ERROR Upload failed error="upload failed" count=124032026/10/10 19:01:09 INFO Upload queue status pending=22404--- PASS: TestQueueDeduplication (0.01s)2405--- PASS: TestQueueRemove (0.02s)24062026/10/10 19:01:09 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1535988523/002/nonexistent24072026/10/10 19:01:09 INFO Upload queue status pending=324082026/10/10 19:01:09 INFO Uploading batch count=124092026/10/10 19:01:09 INFO Uploading batch count=224102026/10/10 19:01:09 INFO Uploading batch count=124112026/10/10 19:01:09 ERROR Upload failed error="upload failed" count=124122026/10/10 19:01:09 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3961588193/002/bbb24132026/10/10 19:01:09 INFO Uploading batch count=224142026/10/10 19:01:09 INFO Uploading batch count=124152026/10/10 19:01:09 ERROR Upload failed error="upload failed" count=224162026/10/10 19:01:09 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown267055087/002/c2417--- PASS: TestQueueEnqueueAndFetch (0.02s)24182026/10/10 19:01:09 INFO Uploading batch count=124192026/10/10 19:01:09 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown267055087/002/d24202026/10/10 19:01:09 INFO Uploading batch count=224212026/10/10 19:01:09 ERROR Upload failed error="upload failed" count=224222026/10/10 19:01:09 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown267055087/002/e24232026/10/10 19:01:09 INFO Uploading batch count=124242026/10/10 19:01:09 ERROR Upload failed error="upload failed" count=124252026/10/10 19:01:09 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown267055087/002/f24262026/10/10 19:01:09 INFO Uploading batch count=124272026/10/10 19:01:09 ERROR Upload failed error="upload failed" count=124282026/10/10 19:01:09 ERROR Drain finished with paths left in queue remaining=1024292026/10/10 19:01:09 INFO Uploading batch count=124302026/10/10 19:01:09 ERROR Upload failed error="upload failed" count=12431--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)24322026/10/10 19:01:09 ERROR Drain finished with paths left in queue remaining=12433--- PASS: TestDrainIsolatesPoisonPath (0.02s)2434--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2435--- PASS: TestWorkerUploadsAndRemoves (0.03s)2436--- PASS: TestWorkerPrunesClosureDeps (0.04s)2437--- PASS: TestWorkerSkipsGCdPaths (0.04s)2438--- PASS: TestQueueRemoveLargeClosure (0.09s)24392026/10/10 19:01:09 ERROR Upload failed error="context deadline exceeded" count=224402026/10/10 19:01:09 ERROR Drain finished with paths left in queue remaining=42441--- PASS: TestDrainTimeout (0.36s)2442--- PASS: TestQueueConcurrentWriters (0.39s)24432026/10/10 19:01:10 INFO Uploading batch count=124442026/10/10 19:01:10 INFO Uploading batch count=124452026/10/10 19:01:10 INFO Uploading batch count=124462026/10/10 19:01:10 ERROR Upload failed error="upload failed" count=124472026/10/10 19:01:10 INFO Uploading batch count=124482026/10/10 19:01:10 ERROR Upload failed error="upload failed" count=124492026/10/10 19:01:10 INFO Uploading batch count=124502026/10/10 19:01:10 ERROR Upload failed error="upload failed" count=124512026/10/10 19:01:10 INFO Uploading batch count=124522026/10/10 19:01:10 ERROR Upload failed error="upload failed" count=124532026/10/10 19:01:10 ERROR Drain finished with paths left in queue remaining=12454--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2455PASS2456Running signing tests...2457=== RUN TestExternalSigner2458=== PAUSE TestExternalSigner2459=== RUN TestExternalSignerWrongPublicKey2460=== PAUSE TestExternalSignerWrongPublicKey2461=== RUN TestExternalSignerErrors2462=== PAUSE TestExternalSignerErrors2463=== RUN TestExternalSignerRestartsAfterCrash2464=== PAUSE TestExternalSignerRestartsAfterCrash2465=== RUN TestExternalSignerProgramErrorKeepsProcess2466=== PAUSE TestExternalSignerProgramErrorKeepsProcess2467=== RUN TestExternalSignerClose2468=== PAUSE TestExternalSignerClose2469=== RUN TestExternalSignerRejectsInvalidPublicKey2470=== PAUSE TestExternalSignerRejectsInvalidPublicKey2471=== RUN TestExternalSignerCancellation2472=== PAUSE TestExternalSignerCancellation2473=== RUN TestGenerateFingerprint2474=== PAUSE TestGenerateFingerprint2475=== RUN TestParseSigningKey2476=== PAUSE TestParseSigningKey2477=== RUN TestSign2478=== PAUSE TestSign2479=== RUN TestSignBatch2480=== PAUSE TestSignBatch2481=== RUN TestNilKeyPublicKey2482=== PAUSE TestNilKeyPublicKey2483=== RUN TestSignErrors2484=== PAUSE TestSignErrors2485=== CONT TestExternalSigner2486=== CONT TestExternalSignerCancellation2487=== CONT TestSignBatch2488=== CONT TestExternalSignerProgramErrorKeepsProcess2489=== CONT TestExternalSignerRejectsInvalidPublicKey2490=== RUN TestExternalSignerRejectsInvalidPublicKey/#002491=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002492=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2493=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2494=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2495=== CONT TestExternalSignerClose2496=== CONT TestParseSigningKey2497=== RUN TestParseSigningKey/valid_32-byte_key2498=== CONT TestSign2499=== CONT TestExternalSignerErrors2500=== CONT TestExternalSignerRestartsAfterCrash2501=== CONT TestExternalSignerWrongPublicKey2502=== CONT TestSignErrors2503=== CONT TestNilKeyPublicKey2504--- PASS: TestNilKeyPublicKey (0.00s)2505=== CONT TestGenerateFingerprint2506=== RUN TestGenerateFingerprint/basic_with_references2507=== PAUSE TestGenerateFingerprint/basic_with_references2508=== RUN TestGenerateFingerprint/no_references2509=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2510=== PAUSE TestParseSigningKey/valid_32-byte_key2511=== RUN TestExternalSignerErrors/exit_on_request2512=== PAUSE TestExternalSignerErrors/exit_on_request2513=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2514=== RUN TestExternalSignerErrors/wrong_shape2515=== PAUSE TestExternalSignerErrors/wrong_shape2516=== PAUSE TestGenerateFingerprint/no_references2517=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2518=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2519=== RUN TestExternalSignerErrors/too_few_signatures2520=== PAUSE TestExternalSignerErrors/too_few_signatures2521=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2522=== RUN TestExternalSignerErrors/missing_signature_name2523=== PAUSE TestExternalSignerErrors/missing_signature_name2524--- PASS: TestSign (0.00s)2525=== RUN TestParseSigningKey/no_colon2526=== RUN TestSignErrors/nil_key2527=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2528=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2529=== CONT TestExternalSignerRejectsInvalidPublicKey/#002530=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2531=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2532=== RUN TestExternalSignerErrors/wrong_signature_name2533=== PAUSE TestExternalSignerErrors/wrong_signature_name2534=== RUN TestExternalSignerErrors/invalid_signature_base642535=== PAUSE TestParseSigningKey/no_colon2536=== PAUSE TestSignErrors/nil_key2537--- PASS: TestSignBatch (0.00s)2538=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2539=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2540=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2541=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2542=== PAUSE TestExternalSignerErrors/invalid_signature_base642543=== RUN TestParseSigningKey/empty_name2544=== RUN TestSignErrors/nil_narinfo2545=== PAUSE TestSignErrors/nil_narinfo2546=== RUN TestSignErrors/invalid_narinfo2547=== PAUSE TestSignErrors/invalid_narinfo2548=== RUN TestSignErrors/canceled2549=== PAUSE TestSignErrors/canceled2550=== CONT TestSignErrors/nil_key2551=== CONT TestSignErrors/canceled2552--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2553 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2554 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2555 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2556 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2557 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2558=== PAUSE TestParseSigningKey/empty_name2559=== RUN TestParseSigningKey/invalid_base642560=== PAUSE TestParseSigningKey/invalid_base642561=== RUN TestParseSigningKey/wrong_length2562=== PAUSE TestParseSigningKey/wrong_length2563=== CONT TestParseSigningKey/valid_32-byte_key2564=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2565=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2566=== RUN TestGenerateFingerprint/invalid_nar_hash_length2567=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2568=== RUN TestGenerateFingerprint/invalid_store_path_prefix2569=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2570=== RUN TestExternalSignerErrors/program_error2571=== CONT TestSignErrors/nil_narinfo2572=== CONT TestSignErrors/invalid_narinfo2573--- PASS: TestSignErrors (0.00s)2574 --- PASS: TestSignErrors/nil_key (0.00s)2575 --- PASS: TestSignErrors/canceled (0.00s)2576 --- PASS: TestSignErrors/nil_narinfo (0.00s)2577 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2578=== CONT TestParseSigningKey/empty_name2579=== CONT TestParseSigningKey/wrong_length2580=== CONT TestParseSigningKey/invalid_base642581=== CONT TestParseSigningKey/no_colon2582=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2583--- PASS: TestParseSigningKey (0.00s)2584 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2585 --- PASS: TestParseSigningKey/empty_name (0.00s)2586 --- PASS: TestParseSigningKey/wrong_length (0.00s)2587 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2588 --- PASS: TestParseSigningKey/no_colon (0.00s)2589 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2590=== RUN TestGenerateFingerprint/invalid_reference_prefix2591=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2592=== CONT TestGenerateFingerprint/basic_with_references2593=== PAUSE TestExternalSignerErrors/program_error2594=== RUN TestExternalSignerErrors/exit_at_startup2595=== CONT TestGenerateFingerprint/invalid_nar_hash_length2596=== PAUSE TestExternalSignerErrors/exit_at_startup2597=== RUN TestExternalSignerErrors/wrong_id2598=== PAUSE TestExternalSignerErrors/wrong_id2599=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2600=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2601=== CONT TestGenerateFingerprint/invalid_reference_prefix2602=== CONT TestGenerateFingerprint/invalid_store_path_prefix2603=== CONT TestGenerateFingerprint/no_references2604--- PASS: TestGenerateFingerprint (0.00s)2605 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2606 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2607 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2608 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2609 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2610 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2611 --- PASS: TestGenerateFingerprint/no_references (0.00s)2612=== RUN TestExternalSignerErrors/missing_signatures2613=== PAUSE TestExternalSignerErrors/missing_signatures2614=== RUN TestExternalSignerErrors/unrequested_key2615=== PAUSE TestExternalSignerErrors/unrequested_key2616=== RUN TestExternalSignerErrors/invalid_JSON2617=== PAUSE TestExternalSignerErrors/invalid_JSON2618=== RUN TestExternalSignerErrors/null2619=== PAUSE TestExternalSignerErrors/null2620=== RUN TestExternalSignerErrors/null_signatures2621=== PAUSE TestExternalSignerErrors/null_signatures2622=== RUN TestExternalSignerErrors/wrong_signatures_shape2623=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2624=== RUN TestExternalSignerErrors/wrong_signature_length2625=== PAUSE TestExternalSignerErrors/wrong_signature_length2626=== CONT TestExternalSignerErrors/exit_on_request2627=== CONT TestExternalSignerErrors/invalid_JSON2628=== CONT TestExternalSignerErrors/unrequested_key2629--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2630=== CONT TestExternalSignerErrors/wrong_signature_length2631=== CONT TestExternalSignerErrors/wrong_signatures_shape2632=== CONT TestExternalSignerErrors/null2633=== CONT TestExternalSignerErrors/null_signatures2634=== CONT TestExternalSignerErrors/invalid_signature_base642635=== CONT TestExternalSignerErrors/missing_signatures2636=== CONT TestExternalSignerErrors/missing_signature_name2637=== CONT TestExternalSignerErrors/wrong_id2638=== CONT TestExternalSignerErrors/wrong_signature_name2639=== CONT TestExternalSignerErrors/exit_at_startup2640=== CONT TestExternalSignerErrors/too_few_signatures2641=== CONT TestExternalSignerErrors/wrong_shape2642=== CONT TestExternalSignerErrors/program_error2643--- PASS: TestExternalSignerClose (0.01s)2644--- PASS: TestExternalSignerWrongPublicKey (0.01s)2645--- PASS: TestExternalSigner (0.01s)2646--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2647--- PASS: TestExternalSignerErrors (0.00s)2648 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2649 --- PASS: TestExternalSignerErrors/invalid_JSON (0.00s)2650 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2651 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2652 --- PASS: TestExternalSignerErrors/null (0.01s)2653 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2654 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2655 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2656 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)2657 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2658 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2659 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2660 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2661 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2662 --- PASS: TestExternalSignerErrors/program_error (0.01s)2663 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2664--- PASS: TestExternalSignerCancellation (0.02s)2665PASS2666Running OpenBao signer tests...2667=== RUN TestSign2668=== PAUSE TestSign2669=== RUN TestSignErrors2670=== PAUSE TestSignErrors2671=== RUN TestServe2672=== PAUSE TestServe2673=== RUN TestServeRejectsGarbage2674=== PAUSE TestServeRejectsGarbage2675=== CONT TestSign2676=== CONT TestServeRejectsGarbage2677=== CONT TestServe2678=== CONT TestSignErrors2679=== RUN TestSignErrors/no_prefix2680=== PAUSE TestSignErrors/no_prefix2681--- PASS: TestServeRejectsGarbage (0.00s)2682=== RUN TestSignErrors/invalid_base642683=== PAUSE TestSignErrors/invalid_base642684=== RUN TestSignErrors/http_error2685=== PAUSE TestSignErrors/http_error2686=== RUN TestSignErrors/invalid_json2687=== PAUSE TestSignErrors/invalid_json2688=== CONT TestSignErrors/no_prefix2689=== CONT TestSignErrors/http_error2690--- PASS: TestServe (0.00s)2691=== CONT TestSignErrors/invalid_base642692=== CONT TestSignErrors/invalid_json2693--- PASS: TestSign (0.01s)2694--- PASS: TestSignErrors (0.00s)2695 --- PASS: TestSignErrors/invalid_json (0.00s)2696 --- PASS: TestSignErrors/no_prefix (0.00s)2697 --- PASS: TestSignErrors/http_error (0.00s)2698 --- PASS: TestSignErrors/invalid_base64 (0.00s)2699PASS