niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #405
· raw
1tribuchet: building on jamie2Running 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 TestRetryTimeoutOutlastsMaxRetries109=== CONT TestEncodeNixBase32110=== RUN TestEncodeNixBase32/test_string_hash111=== PAUSE TestEncodeNixBase32/test_string_hash112=== RUN TestEncodeNixBase32/empty_input113=== PAUSE TestEncodeNixBase32/empty_input114=== CONT TestEncodeNixBase32WithRealHash115=== CONT TestSetClientTLSDoesNotMutateDefaultTransport116=== CONT TestDoWithRetry_BodyReplayedViaGetBody117=== CONT TestScriptTokenEmptyCommand118=== CONT TestResolveStorePath119=== CONT TestScriptTokenScriptFails120=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess121=== CONT TestScriptTokenBadJSON122=== CONT TestCaseHackSuffix123=== CONT TestRateLimiterFeedback124=== RUN TestRateLimiterFeedback/429_enables_limiter125=== CONT TestScriptTokenEmptyToken1262026/10/10 19:01:07 WARN Rate limiter enabled after throttle name=server-test rate=5127=== CONT TestPathInfoCACompatibility128=== RUN TestPathInfoCACompatibility/null_ca_field129=== PAUSE TestPathInfoCACompatibility/null_ca_field130=== CONT TestScriptTokenCachesUntilRefresh131=== CONT TestParsePathInfoJSONMultiplePaths132=== CONT TestScriptTokenNoExpiryRerunsEveryCall133=== CONT TestParsePathInfoJSON134=== CONT TestFileTokenEmpty135=== CONT TestPathInfoHashCompatibility136=== CONT TestFileTokenMissing137=== CONT TestGetStorePathHash138=== CONT TestFileTokenReadsAndCaches139=== CONT TestConvertHashToNix32140=== CONT TestStaticToken141--- PASS: TestEncodeNixBase32WithRealHash (0.00s)142=== CONT TestSetClientTLSErrors143=== CONT TestPartSizeForNAR144=== PAUSE TestRateLimiterFeedback/429_enables_limiter145--- PASS: TestScriptTokenEmptyCommand (0.00s)146--- PASS: TestStaticToken (0.00s)147--- PASS: TestResolveStorePath (0.00s)148=== CONT TestDumpPathWriterError149--- PASS: TestScriptTokenScriptFails (0.00s)150=== RUN TestPathInfoCACompatibility/old_string_format_-_text151=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text152=== CONT TestUploadMultipart_PartsInParallel153=== RUN TestParsePathInfoJSON/Nix_format154=== PAUSE TestParsePathInfoJSON/Nix_format155=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)156=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)157=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon158=== RUN TestConvertHashToNix32/SRI_format_to_Nix32159=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon160=== RUN TestRateLimiterFeedback/503_enables_limiter161=== PAUSE TestRateLimiterFeedback/503_enables_limiter162=== RUN TestPartSizeForNAR/zero_stays_at_minimum163=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum164=== RUN TestGetStorePathHash/valid_store_path165=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter166=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive167=== RUN TestParsePathInfoJSON/Lix_format168=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths169=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI170=== RUN TestPartSizeForNAR/small_stays_at_minimum171--- PASS: TestFileTokenMissing (0.00s)172=== CONT TestDumpPathSingleFile173--- PASS: TestScriptTokenBadJSON (0.01s)174=== PAUSE TestGetStorePathHash/valid_store_path175=== CONT TestFilterOversizedClosures176=== RUN TestFilterOversizedClosures/no_limit_keeps_everything1772026/10/10 19:01:07 WARN Rate limiter enabled after throttle name=server-test rate=5178=== CONT TestDumpPathMatchesNix179=== RUN TestGetStorePathHash/basename_without_hyphen_should_error1802026/10/10 19:01:07 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:41799181=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive182=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error183=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter184=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error185--- PASS: TestFileTokenReadsAndCaches (0.00s)186=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter187=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything188=== PAUSE TestParsePathInfoJSON/Lix_format189=== RUN TestPathInfoCACompatibility/new_structured_format_-_text190=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error191=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths192=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI193=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32194=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped195=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text196=== RUN TestParsePathInfoJSON/empty_input197=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter198--- PASS: TestFileTokenEmpty (0.00s)199=== PAUSE TestPartSizeForNAR/small_stays_at_minimum200=== RUN TestSetClientTLSErrors/missing_cert_file201--- PASS: TestScriptTokenEmptyToken (0.01s)202=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error203=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method204=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error205--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)2062026/10/10 19:01:07 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:35613207=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths208=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths209=== CONT TestShellSplitErrors210--- PASS: TestShellSplitErrors (0.00s)211=== CONT TestStreamPushReportsEveryPath212--- PASS: TestDoServerRequestAttachesToken (0.05s)213=== CONT TestShellSplit214--- PASS: TestShellSplit (0.00s)215=== CONT TestClientSignaturesByStorePath216--- PASS: TestClientSignaturesByStorePath (0.00s)217=== CONT TestSetClientTLS218=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512219=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512220=== CONT TestStreamPushReportsSkippedPaths221=== RUN TestConvertHashToNix32/already_Nix32_format222=== PAUSE TestConvertHashToNix32/already_Nix32_format223=== RUN TestConvertHashToNix32/invalid_format224=== PAUSE TestConvertHashToNix32/invalid_format225--- PASS: TestStreamPushReportsSkippedPaths (0.00s)226=== CONT TestStreamPushStopsWhenCanceled227--- PASS: TestStreamPushReportsEveryPath (0.00s)228=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica229=== CONT TestStreamPushReportsSignatures2302026/10/10 19:01:07 WARN Rate limiter backed off name=server-test rate=5231=== CONT TestStreamPushBatchesUnderLoad2322026/10/10 19:01:07 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:41799233--- PASS: TestStreamPushStopsWhenCanceled (0.00s)234=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun235=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum236=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum237=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts238=== CONT TestStreamPushGivesUpOnDeadServer239=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method240=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2412026/10/10 19:01:07 ERROR Upload failed error=boom count=1242=== RUN TestFilterOversizedClosures/all_closures_skipped2432026/10/10 19:01:07 ERROR Upload failed error="connection refused" count=20244--- PASS: TestStreamPushReportsSignatures (0.00s)2452026/10/10 19:01:07 ERROR Server seems unavailable, giving up on batch untried=17246=== CONT TestRegisterUploadedObjectReusesConnections247=== CONT TestUploadMultipart_SupersededByPeer2482026/10/10 19:01:07 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:35613249=== RUN TestUploadMultipart_SupersededByPeer/exists250=== PAUSE TestUploadMultipart_SupersededByPeer/exists251=== RUN TestUploadMultipart_SupersededByPeer/missing252=== PAUSE TestUploadMultipart_SupersededByPeer/missing253=== CONT TestEncodeNixBase32/empty_input254=== CONT TestRateLimiterFeedback/503_enables_limiter255=== CONT TestRateLimiterFeedback/429_enables_limiter2562026/10/10 19:01:07 INFO Garbage collection started257=== PAUSE TestSetClientTLSErrors/missing_cert_file258=== RUN TestSetClientTLSErrors/missing_key_file2592026/10/10 19:01:07 INFO Garbage collection started260=== PAUSE TestSetClientTLSErrors/missing_key_file261=== RUN TestSetClientTLSErrors/missing_ca_file262=== PAUSE TestSetClientTLSErrors/missing_ca_file263=== PAUSE TestFilterOversizedClosures/all_closures_skipped264=== RUN TestSetClientTLS/rejects_connection_without_client_cert265=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert266=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA267=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA268=== RUN TestSetClientTLS/preserves_debug_logging_transport269=== PAUSE TestSetClientTLS/preserves_debug_logging_transport270=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter2712026/10/10 19:01:07 WARN Rate limiter enabled after throttle name=server-test rate=5272=== CONT TestGetStorePathHash/valid_store_path2732026/10/10 19:01:07 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:462112742026/10/10 19:01:07 WARN Rate limiter enabled after throttle name=server-test rate=5275=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error2762026/10/10 19:01:07 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:41147277=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error278=== CONT TestGetStorePathHash/basename_without_hyphen_should_error279=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths2802026/10/10 19:01:07 WARN Rate limiter backed off name=server-test rate=5281=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths282=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)283=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI2842026/10/10 19:01:07 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:356132852026/10/10 19:01:07 WARN Rate limiter backed off name=server-test rate=5286=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512287=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon288=== CONT TestConvertHashToNix32/invalid_format289=== CONT TestConvertHashToNix32/already_Nix32_format290=== CONT TestPathInfoCACompatibility/null_ca_field291=== CONT TestConvertHashToNix32/SRI_format_to_Nix32292=== PAUSE TestParsePathInfoJSON/empty_input293=== RUN TestParsePathInfoJSON/whitespace_only294=== PAUSE TestParsePathInfoJSON/whitespace_only295=== RUN TestParsePathInfoJSON/invalid_JSON296=== PAUSE TestParsePathInfoJSON/invalid_JSON297=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts298=== RUN TestPartSizeForNAR/1_TiB299=== PAUSE TestPartSizeForNAR/1_TiB300=== RUN TestPartSizeForNAR/5_TiB_S3_max_object301=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object302=== RUN TestPartSizeForNAR/capped_at_5_GiB303=== PAUSE TestPartSizeForNAR/capped_at_5_GiB304=== CONT TestPathInfoCACompatibility/old_string_format_-_text305=== CONT TestFilterOversizedClosures/no_limit_keeps_everything306=== CONT TestUploadMultipart_SupersededByPeer/missing307=== CONT TestFilterOversizedClosures/all_closures_skipped3082026/10/10 19:01:07 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-small nar_size=1000 max_nar_size=50309=== CONT TestSetClientTLS/rejects_connection_without_client_cert310=== CONT TestStreamPushRequestLine311--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.05s)312--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)3132026/10/10 19:01:07 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=0314--- PASS: TestCaseHackSuffix (0.05s)315=== CONT TestEncodeNixBase32/test_string_hash316=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3172026/10/10 19:01:07 ERROR Upload failed error=boom count=1318=== RUN TestSetClientTLSErrors/invalid_ca_file319=== PAUSE TestSetClientTLSErrors/invalid_ca_file320=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter3212026/10/10 19:01:07 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=2000322=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method3232026/10/10 19:01:07 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:35613324=== CONT TestParsePathInfoJSON/invalid_JSON3252026/10/10 19:01:07 WARN Garbage collection finished on another replica. Its statistics are not available here326=== CONT TestParsePathInfoJSON/empty_input327=== CONT TestParsePathInfoJSON/whitespace_only328=== CONT TestPathInfoCACompatibility/new_structured_format_-_text329=== CONT TestPartSizeForNAR/5_TiB_S3_max_object330=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum331=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts3322026/10/10 19:01:07 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:35613333=== CONT TestPartSizeForNAR/small_stays_at_minimum334=== CONT TestUploadMultipart_SupersededByPeer/exists335=== CONT TestSupersededNARStillUploadsListing336--- PASS: TestEncodeNixBase32 (0.00s)337 --- PASS: TestEncodeNixBase32/empty_input (0.00s)338 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)339=== CONT TestStreamPushIsolatesFailures340=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA341=== CONT TestSetClientTLS/preserves_debug_logging_transport342=== CONT TestParsePathInfoJSON/Nix_format3432026/10/10 19:01:07 ERROR Upload failed error="bad path" count=3344=== CONT TestPartSizeForNAR/zero_stays_at_minimum345=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive346=== CONT TestParsePathInfoJSON/Lix_format347=== CONT TestPartSizeForNAR/1_TiB348=== CONT TestPartSizeForNAR/capped_at_5_GiB349=== CONT TestSetClientTLSErrors/missing_cert_file350=== CONT TestSetClientTLSErrors/invalid_ca_file351=== RUN TestSupersededNARStillUploadsListing/small_NAR352=== PAUSE TestSupersededNARStillUploadsListing/small_NAR353=== RUN TestSupersededNARStillUploadsListing/dump_cut_short354=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short355=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails356=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails357--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)3582026/10/10 19:01:07 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:35613359=== CONT TestSetClientTLSErrors/missing_ca_file3602026/10/10 19:01:07 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:35613361=== CONT TestSetClientTLSErrors/missing_key_file362=== CONT TestSupersededNARStillUploadsListing/small_NAR363=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails364=== CONT TestSupersededNARStillUploadsListing/dump_cut_short365--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)366--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)3672026/10/10 19:01:07 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:35613368--- PASS: TestGetStorePathHash (0.00s)369 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)370 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)371 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)372 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)3732026/10/10 19:01:07 INFO Uploading abc-hello (1.0GB)374--- PASS: TestParsePathInfoJSONMultiplePaths (0.04s)375 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)376 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)3772026/10/10 19:01:07 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:35613378--- PASS: TestPathInfoHashCompatibility (0.04s)379 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)380 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)381 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)382 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)383--- PASS: TestConvertHashToNix32 (0.04s)384 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)385 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)386 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)3872026/10/10 19:01:08 INFO Uploading abc-hello (1.0GB)388--- PASS: TestStreamPushIsolatesFailures (0.00s)389--- PASS: TestScriptTokenCachesUntilRefresh (0.05s)390--- PASS: TestFilterOversizedClosures (0.04s)391 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)392 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)393 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)394--- PASS: TestRateLimiterFeedback (0.01s)395 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)396 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)397 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)398 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)3992026/10/10 19:01:08 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:35613400--- PASS: TestParsePathInfoJSON (0.05s)401 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)402 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)403 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)404 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)405 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)406--- PASS: TestPathInfoCACompatibility (0.05s)407 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)408 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)409 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)410 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)411 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)412--- PASS: TestDumpPathSingleFile (0.19s)413--- PASS: TestPartSizeForNAR (0.05s)414 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)415 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)416 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)417 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)418 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)419 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)420 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)421--- PASS: TestSetClientTLSErrors (0.05s)422 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)423 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)424 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)425 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)426--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)427 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)428 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)4292026/10/10 19:01:08 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:356134302026/10/10 19:01:08 http: TLS handshake error from 127.0.0.1:51482: remote error: tls: bad certificate4312026/10/10 19:01:08 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:35613432--- PASS: TestSetClientTLS (0.00s)433 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)434 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.15s)435 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.15s)4362026/10/10 19:01:08 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:356134372026/10/10 19:01:08 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:356134382026/10/10 19:01:08 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:356134392026/10/10 19:01:08 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:356134402026/10/10 19:01:08 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:356134412026/10/10 19:01:08 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:35613442--- PASS: TestStreamPushRequestLine (0.16s)4432026/10/10 19:01:08 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:35613444--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.22s)445--- PASS: TestRegisterUploadedObjectReusesConnections (0.17s)446--- PASS: TestDumpPathWriterError (0.22s)4472026/10/10 19:01:08 INFO Uploading abc-hello (1.0GB)448--- PASS: TestStreamPushBatchesUnderLoad (0.20s)449--- PASS: TestDumpPathMatchesNix (0.27s)4502026/10/10 19:01:08 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:41869/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:41869/part/24512026/10/10 19:01:08 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"452--- PASS: TestSupersededNARStillUploadsListing (0.00s)453 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.14s)454 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.15s)455 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.71s)456--- PASS: TestUploadMultipart_PartsInParallel (0.78s)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/postgres2578509719/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/postgres2578509719/data -l logfile start486487/build/postgres2578509719:5432 - no response4882026-10-10 19:01:09.812 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4892026-10-10 19:01:09.813 UTC [129] LOG: listening on Unix socket "/build/postgres2578509719/.s.PGSQL.5432"4902026-10-10 19:01:09.818 UTC [136] LOG: database system was shut down at 2026-10-10 19:01:09 UTC4912026-10-10 19:01:09.821 UTC [129] LOG: database system is ready to accept connections492/build/postgres2578509719:5432 - accepting connections493{"timestamp":"2026-10-10T19:01:10.222658461Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"a3c5bcd1-b7a0-48e2-b29b-c791c06102ef","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(390)"}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:01:10 INFO lead: acquired remote=192.0.2.1:12345422026/10/10 19:01:11 INFO lead: released remote=192.0.2.1:12345432026/10/10 19:01:11 INFO lead: acquired remote=192.0.2.1:12345442026/10/10 19:01:12 INFO lead: released remote=192.0.2.1:1234545--- PASS: TestLeadIncumbentWinsAfterRestart (1.86s)546=== RUN TestLeadIncumbentAnnouncesAtOnce547=== PAUSE TestLeadIncumbentAnnouncesAtOnce548=== RUN TestLeadEndsOnShutdown549=== PAUSE TestLeadEndsOnShutdown550=== RUN TestLeadEndsWhenItsConnectionHangs5512026/10/10 19:01:12 INFO lead: acquired remote=192.0.2.1:12345522026-10-10 19:01:13.709 UTC [575] FATAL: terminating connection due to administrator command5532026/10/10 19:01:13 INFO lead: acquired remote=192.0.2.1:12345542026/10/10 19:01:14 WARN lead: lock connection lost error="timeout: context deadline exceeded"5552026/10/10 19:01:14 INFO lead: released remote=192.0.2.1:12345562026/10/10 19:01:15 INFO lead: released remote=192.0.2.1:1234557--- PASS: TestLeadEndsWhenItsConnectionHangs (3.13s)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:01:15 INFO Starting HTTP server address=127.0.0.1:388996582026/10/10 19:01:15 INFO Starting HTTP server address=proxy.sock6592026/10/10 19:01:15 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6602026/10/10 19:01:15 INFO Shutdown signal received, draining in-flight requests timeout=10s661--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.12s)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:01:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7302026/10/10 19:01:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7312026/10/10 19:01:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7322026/10/10 19:01:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7332026/10/10 19:01:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7342026/10/10 19:01:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7352026/10/10 19:01:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7362026/10/10 19:01:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7372026/10/10 19:01:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7382026/10/10 19:01:15 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 TestService_AuthMiddleware763=== CONT TestReadProxyNarinfo764=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT765=== CONT TestCompleteMultipartUnregistered766=== CONT TestService_verifyS3Integrity767=== CONT TestService_createPendingClosureHandler768=== CONT TestService_cleanupPendingClosuresHandler769=== CONT TestUploadHandlersRejectOversizedBody770=== CONT TestUploadHandlersRejectInvalidKeys771=== CONT TestIsValidUploadKey772=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info773=== CONT TestPendingClosureWriteTimeout774=== CONT TestProxyWriteTimeout775=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle776=== CONT TestSkippedUploadsHandler777=== CONT TestReadRedirectUsesPublicS3URL778=== CONT TestReadProxyRangeRequest779=== CONT TestReadRedirectKeepsNarinfoProxied780=== CONT TestReadRedirectNar781=== CONT TestReadProxyDisabled782=== CONT TestPush_OverlappingRootsStoreOneRowPerKey783=== CONT TestReadProxyRootRedirectsToIndexHTML784=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info785=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal786=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal787=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key788=== CONT TestReadProxyConditionalGet789=== CONT TestService_Rustfstest790=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key7912026/10/10 19:01:15 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000792=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key793=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key794=== CONT TestReadProxyOutlastsServerWriteTimeout795=== RUN TestProxyWriteTimeout/narinfo796=== RUN TestPendingClosureWriteTimeout/empty797=== CONT TestParseSize798--- PASS: TestParseSize (0.00s)799=== CONT TestPresignedUploadRegisteredBeforeCommit800=== RUN TestIsValidUploadKey/narinfo801=== PAUSE TestPendingClosureWriteTimeout/empty802=== RUN TestPendingClosureWriteTimeout/400_objects803--- PASS: TestSkippedUploadsHandler (0.01s)804=== CONT TestReadProxyHead805=== PAUSE TestProxyWriteTimeout/narinfo806=== PAUSE TestIsValidUploadKey/narinfo807=== RUN TestProxyWriteTimeout/1_GiB_nar808=== RUN TestIsValidUploadKey/nar_zst809=== PAUSE TestPendingClosureWriteTimeout/400_objects810=== PAUSE TestProxyWriteTimeout/1_GiB_nar811=== PAUSE TestIsValidUploadKey/nar_zst812=== RUN TestPendingClosureWriteTimeout/670k_objects813=== PAUSE TestPendingClosureWriteTimeout/670k_objects814=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline815=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline816=== RUN TestProxyWriteTimeout/10_GiB_nar817=== PAUSE TestProxyWriteTimeout/10_GiB_nar818=== RUN TestProxyWriteTimeout/unknown_size819=== PAUSE TestProxyWriteTimeout/unknown_size820=== RUN TestIsValidUploadKey/nar_xz821=== CONT TestReadProxyInvalidPath822=== CONT TestCompletedNarNotReofferedAcrossClosures823=== PAUSE TestIsValidUploadKey/nar_xz824=== RUN TestIsValidUploadKey/nar_plain825=== PAUSE TestIsValidUploadKey/nar_plain826=== RUN TestIsValidUploadKey/listing827=== PAUSE TestIsValidUploadKey/listing828=== RUN TestIsValidUploadKey/build_log829=== PAUSE TestIsValidUploadKey/build_log830=== RUN TestIsValidUploadKey/build_log_home-manager_file831=== PAUSE TestIsValidUploadKey/build_log_home-manager_file832=== RUN TestIsValidUploadKey/build_log_plus_in_name833=== PAUSE TestIsValidUploadKey/build_log_plus_in_name834=== RUN TestIsValidUploadKey/build_log_question_mark835=== PAUSE TestIsValidUploadKey/build_log_question_mark836=== RUN TestIsValidUploadKey/build_log_equals837=== PAUSE TestIsValidUploadKey/build_log_equals838=== RUN TestIsValidUploadKey/realisation839=== PAUSE TestIsValidUploadKey/realisation840=== RUN TestIsValidUploadKey/realisation_plus_in_output841=== PAUSE TestIsValidUploadKey/realisation_plus_in_output842=== RUN TestIsValidUploadKey/nix-cache-info843=== PAUSE TestIsValidUploadKey/nix-cache-info844=== RUN TestIsValidUploadKey/index.html845=== PAUSE TestIsValidUploadKey/index.html846=== RUN TestIsValidUploadKey/narinfo_key,_nar_type847=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type848=== RUN TestIsValidUploadKey/nar_key,_narinfo_type849=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type850=== RUN TestIsValidUploadKey/listing_key,_narinfo_type851=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type852=== RUN TestIsValidUploadKey/traversal853=== PAUSE TestIsValidUploadKey/traversal854=== RUN TestIsValidUploadKey/traversal_nar855=== PAUSE TestIsValidUploadKey/traversal_nar856=== RUN TestIsValidUploadKey/absolute857=== PAUSE TestIsValidUploadKey/absolute858=== RUN TestIsValidUploadKey/empty_key859=== PAUSE TestIsValidUploadKey/empty_key860=== RUN TestIsValidUploadKey/unknown_type861=== PAUSE TestIsValidUploadKey/unknown_type862=== CONT TestCompleteMultipartUpload_ErrorButObjectExists863=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure864=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure865=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart866=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart867=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts868=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts869=== CONT TestRedundantMultipartUpload870--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.44s)871=== CONT TestReadProxy4048722026/10/10 19:01:16 INFO Received cleanup request method=DELETE path=/api/pending_closures8732026/10/10 19:01:16 INFO Aborted multipart uploads count=0 kept=08742026/10/10 19:01:16 INFO Received uploads request method=POST path=/api/pending_closures8752026/10/10 19:01:16 INFO Received cleanup request method=DELETE path=/api/pending_closures8762026/10/10 19:01:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8772026/10/10 19:01:16 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst878--- PASS: TestCompleteMultipartUnregistered (0.48s)879=== CONT TestPush_SignsNarinfosOfItsPendingObjects8802026/10/10 19:01:16 INFO Aborted multipart uploads count=1 kept=08812026/10/10 19:01:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8822026-10-10 19:01:16.144 UTC [649] ERROR: Closure does not exist: id=18832026-10-10 19:01:16.144 UTC [649] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE8842026-10-10 19:01:16.144 UTC [649] STATEMENT: -- name: CommitPendingClosure :one885 SELECT commit_pending_closure($1::bigint)::bigint886 887--- PASS: TestService_cleanupPendingClosuresHandler (0.48s)888=== CONT TestReadProxyNarStreaming8892026/10/10 19:01:16 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"890--- PASS: TestService_AuthMiddleware (0.50s)891=== CONT TestPush_RejectsBadRequests8922026/10/10 19:01:16 INFO Received uploads request method=POST path=/api/pending_closures893--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.55s)894=== CONT TestReadProxyContentNegotiation895--- PASS: TestReadProxyRangeRequest (0.57s)896=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit8972026/10/10 19:01:16 INFO Received push request method=POST path=/api/pushes898--- PASS: TestReadProxyDisabled (0.63s)899=== CONT TestPush_RootsAreLockedInByteOrder900--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.63s)901=== CONT TestReadProxyNarinfoAlreadyDecompressed9022026/10/10 19:01:16 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>903--- PASS: TestReadProxyNarinfo (0.66s)904=== CONT TestPush_CompleteWaitsForCleanupOfThePush905--- PASS: TestReadRedirectNar (0.67s)906=== CONT TestPush_CompleteCommitsEveryRoot907--- PASS: TestReadRedirectUsesPublicS3URL (0.72s)908=== CONT TestPush_RepeatedRootCommitsOnce9092026/10/10 19:01:16 INFO Received uploads request method=POST path=/api/pending_closures9102026/10/10 19:01:16 INFO Received uploads request method=POST path=/api/pending_closures9112026/10/10 19:01:16 INFO Received uploads request method=POST path=/api/pending_closures912--- PASS: TestReadRedirectKeepsNarinfoProxied (0.77s)913=== CONT TestGetExistingObjectsLocksRows914--- PASS: TestReadProxyConditionalGet (0.79s)915=== CONT TestIsValidCachePath916=== RUN TestIsValidCachePath/narinfo917=== PAUSE TestIsValidCachePath/narinfo918=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars919=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars920=== RUN TestIsValidCachePath/nar_zst921=== PAUSE TestIsValidCachePath/nar_zst922=== RUN TestIsValidCachePath/nar_xz923=== PAUSE TestIsValidCachePath/nar_xz924=== RUN TestIsValidCachePath/nar_bz2925=== PAUSE TestIsValidCachePath/nar_bz2926=== RUN TestIsValidCachePath/nar_uncompressed927=== PAUSE TestIsValidCachePath/nar_uncompressed928=== RUN TestIsValidCachePath/ls929=== PAUSE TestIsValidCachePath/ls930=== RUN TestIsValidCachePath/log931=== PAUSE TestIsValidCachePath/log932=== RUN TestIsValidCachePath/realisation933=== PAUSE TestIsValidCachePath/realisation934=== RUN TestIsValidCachePath/nix-cache-info935=== PAUSE TestIsValidCachePath/nix-cache-info936=== RUN TestIsValidCachePath/index.html937=== PAUSE TestIsValidCachePath/index.html938=== RUN TestIsValidCachePath/traversal_parent939=== PAUSE TestIsValidCachePath/traversal_parent940=== RUN TestIsValidCachePath/traversal_in_middle941=== PAUSE TestIsValidCachePath/traversal_in_middle942=== RUN TestIsValidCachePath/invalid_char_e943=== PAUSE TestIsValidCachePath/invalid_char_e944=== RUN TestIsValidCachePath/invalid_char_u945=== PAUSE TestIsValidCachePath/invalid_char_u946=== RUN TestIsValidCachePath/random_path947=== PAUSE TestIsValidCachePath/random_path948=== RUN TestIsValidCachePath/empty949=== PAUSE TestIsValidCachePath/empty950=== RUN TestIsValidCachePath/leading_slash951=== PAUSE TestIsValidCachePath/leading_slash952=== RUN TestIsValidCachePath/wrong_extension953=== PAUSE TestIsValidCachePath/wrong_extension954=== RUN TestIsValidCachePath/short_hash955=== PAUSE TestIsValidCachePath/short_hash956=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock957--- PASS: TestService_Rustfstest (0.81s)958=== CONT TestParseSingleRange959=== RUN TestParseSingleRange/none960=== PAUSE TestParseSingleRange/none961=== RUN TestParseSingleRange/unknown_unit962=== PAUSE TestParseSingleRange/unknown_unit963=== RUN TestParseSingleRange/multi-range_ignored964=== PAUSE TestParseSingleRange/multi-range_ignored965=== RUN TestParseSingleRange/malformed_no_dash966=== PAUSE TestParseSingleRange/malformed_no_dash967=== RUN TestParseSingleRange/malformed_both_empty968=== PAUSE TestParseSingleRange/malformed_both_empty969=== RUN TestParseSingleRange/malformed_end_before_start970=== PAUSE TestParseSingleRange/malformed_end_before_start971=== RUN TestParseSingleRange/closed972=== PAUSE TestParseSingleRange/closed973=== RUN TestParseSingleRange/open-ended974=== PAUSE TestParseSingleRange/open-ended975=== RUN TestParseSingleRange/end_clamped_to_size976=== PAUSE TestParseSingleRange/end_clamped_to_size977=== RUN TestParseSingleRange/suffix978=== PAUSE TestParseSingleRange/suffix979=== RUN TestParseSingleRange/suffix_exceeds_size980=== PAUSE TestParseSingleRange/suffix_exceeds_size981=== RUN TestParseSingleRange/single_byte982=== PAUSE TestParseSingleRange/single_byte983=== RUN TestParseSingleRange/start_past_EOF984=== PAUSE TestParseSingleRange/start_past_EOF985=== RUN TestParseSingleRange/start_far_past_EOF986=== PAUSE TestParseSingleRange/start_far_past_EOF987=== CONT TestRegisterCompletedObjectNeedsPendingRow9882026/10/10 19:01:16 INFO Received uploads request method=POST path=/api/pending_closures989--- PASS: TestReadProxyInvalidPath (0.78s)990=== CONT TestPresentNotReportedWhileGCDeletesClosure991=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale992=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale993=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh994=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh995=== CONT TestPresentRefreshesOnlyStaleClosures9962026/10/10 19:01:16 INFO Received uploads request method=POST path=/api/pending_closures9972026/10/10 19:01:16 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9982026/10/10 19:01:16 INFO Received uploads request method=POST path=/api/pending_closures9992026/10/10 19:01:16 INFO Received uploads request method=POST path=/api/pending_closures1000--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.92s)1001=== CONT TestSweepSkipsRowsLockedByPush10022026/10/10 19:01:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10032026/10/10 19:01:16 INFO Received uploads request method=POST path=/api/pending_closures1004--- PASS: TestReadProxyHead (0.96s)1005=== CONT TestPresentReportsOnlyClosureRoots10062026/10/10 19:01:16 INFO Received uploads request method=POST path=/api/pending_closures10072026/10/10 19:01:16 INFO Received uploads request method=POST path=/api/pending_closures10082026/10/10 19:01:16 INFO Received uploads request method=POST path=/api/pending_closures10092026/10/10 19:01:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10102026/10/10 19:01:16 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MWY2ZDE0ZjQtZjc0OC00YmM2LWI2ZDAtNTM0MjBmZWUzNzM2LmJlNTc3Y2ZiLTlkNzUtNDBlZC1iNzdkLWIwM2JmNDEzM2QwM3gxNzkxNjU4ODc2Njk5MDk0Njc410112026/10/10 19:01:16 INFO Received push request method=POST path=/api/pushes10122026/10/10 19:01:16 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MWY2ZDE0ZjQtZjc0OC00YmM2LWI2ZDAtNTM0MjBmZWUzNzM2LmJlNTc3Y2ZiLTlkNzUtNDBlZC1iNzdkLWIwM2JmNDEzM2QwM3gxNzkxNjU4ODc2Njk5MDk0Njc4 parts=11013--- PASS: TestReadProxy404 (0.65s)1014=== CONT TestCreatePin_ReservedPins1015--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.99s)1016=== CONT TestFailedS3DeleteKeepsTombstone10172026/10/10 19:01:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10182026/10/10 19:01:16 INFO Signed narinfos id=1 count=110192026/10/10 19:01:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10202026/10/10 19:01:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10212026/10/10 19:01:16 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"10222026/10/10 19:01:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10232026/10/10 19:01:16 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"10242026/10/10 19:01:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10252026/10/10 19:01:16 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=110262026/10/10 19:01:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10272026/10/10 19:01:16 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1028--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.62s)1029=== CONT TestOrphanedObjectsGCStressTest1030=== RUN TestPush_RejectsBadRequests/no_roots1031=== PAUSE TestPush_RejectsBadRequests/no_roots1032=== RUN TestPush_RejectsBadRequests/no_objects1033=== PAUSE TestPush_RejectsBadRequests/no_objects1034=== RUN TestPush_RejectsBadRequests/bad_root1035=== PAUSE TestPush_RejectsBadRequests/bad_root1036=== RUN TestPush_RejectsBadRequests/root_not_in_objects1037=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1038=== CONT TestForceGCDuringPushOffersSweptObject1039=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1040=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1041=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1042=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1043=== CONT TestOrphanedObjectsGC1044--- PASS: TestReadProxyNarStreaming (0.65s)1045=== CONT TestObjectStatsLargeCommit10462026/10/10 19:01:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10472026/10/10 19:01:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46293/oidc10482026/10/10 19:01:16 INFO Received push request method=POST path=/api/pushes10492026/10/10 19:01:16 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MWY2ZDE0ZjQtZjc0OC00YmM2LWI2ZDAtNTM0MjBmZWUzNzM2LmEwOTVkOTRiLTQyOTMtNDczOS1iZGNhLTQxM2RmYTY3MmMzMXgxNzkxNjU4ODc2NDA3NjQzNTI4 parts=1010502026/10/10 19:01:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10512026/10/10 19:01:16 INFO Completed upload id=1 objects=2 duration=6.704087ms10522026/10/10 19:01:16 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010532026/10/10 19:01:16 INFO Received uploads request method=POST path=/api/pending_closures10542026/10/10 19:01:16 INFO Starting cleanup of old closures method=DELETE path=/api/closures10552026/10/10 19:01:16 INFO Received push request method=POST path=/api/pushes10562026/10/10 19:01:16 INFO Received complete push request method=POST path=/api/pushes/1/complete1057--- PASS: TestReadProxyContentNegotiation (0.68s)1058=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10592026/10/10 19:01:16 INFO Aborted multipart uploads count=0 kept=010602026/10/10 19:01:16 INFO Completed push id=1 objects=4 duration=10.723079ms10612026/10/10 19:01:16 INFO Received push request method=POST path=/api/pushes10622026/10/10 19:01:16 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=010632026/10/10 19:01:16 INFO Vacuumed table table=pending_closures10642026/10/10 19:01:16 INFO Vacuumed table table=pending_objects1065--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.62s)1066=== CONT TestObjectStatsTrigger10672026/10/10 19:01:16 INFO Vacuumed table table=multipart_uploads10682026/10/10 19:01:16 INFO Vacuumed table table=closures10692026/10/10 19:01:16 INFO Vacuumed table table=objects10702026/10/10 19:01:16 INFO Received push request method=POST path=/api/pushes10712026-10-10 19:01:16.950 UTC [767] ERROR: could not obtain lock on row in relation "closures"10722026-10-10 19:01:16.950 UTC [767] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10732026-10-10 19:01:16.950 UTC [767] ERROR: could not obtain lock on row in relation "closures"10742026-10-10 19:01:16.950 UTC [767] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10752026-10-10 19:01:16.951 UTC [767] ERROR: could not obtain lock on row in relation "closures"10762026-10-10 19:01:16.951 UTC [767] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10772026-10-10 19:01:16.951 UTC [767] ERROR: could not obtain lock on row in relation "closures"10782026-10-10 19:01:16.951 UTC [767] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10792026-10-10 19:01:16.952 UTC [767] ERROR: could not obtain lock on row in relation "closures"10802026-10-10 19:01:16.952 UTC [767] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1081--- PASS: TestPush_RootsAreLockedInByteOrder (0.66s)1082=== CONT TestPendingCleanupUsesOneCutoff10832026/10/10 19:01:16 INFO Aborted multipart uploads count=0 kept=010842026/10/10 19:01:16 WARN Force mode enabled - objects will be deleted immediately without grace period10852026/10/10 19:01:16 INFO Received complete push request method=POST path=/api/pushes/1/complete10862026/10/10 19:01:16 INFO Received push request method=POST path=/api/pushes10872026/10/10 19:01:16 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001088--- PASS: TestService_createPendingClosureHandler (1.32s)1089=== CONT TestGCSweepDeliversEachKeyOnce10902026/10/10 19:01:16 INFO Completed push id=1 objects=6 duration=10.30124ms1091--- PASS: TestPush_CompleteCommitsEveryRoot (0.65s)1092=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded10932026/10/10 19:01:16 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=010942026/10/10 19:01:16 INFO Vacuumed table table=pending_closures10952026/10/10 19:01:16 INFO Vacuumed table table=pending_objects10962026/10/10 19:01:16 INFO Vacuumed table table=multipart_uploads10972026/10/10 19:01:17 INFO Vacuumed table table=closures10982026/10/10 19:01:17 INFO Vacuumed table table=objects10992026/10/10 19:01:17 INFO Received complete push request method=POST path=/api/pushes/2/complete11002026/10/10 19:01:17 INFO Received push request method=POST path=/api/pushes11012026/10/10 19:01:17 INFO Completed push id=2 objects=4 duration=5.26305ms1102--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.78s)1103=== CONT TestTombstonedObjectOfferedWithoutWaiting11042026/10/10 19:01:17 INFO Received complete push request method=POST path=/api/pushes/1/complete11052026/10/10 19:01:17 INFO Completed push id=1 objects=4 duration=27.246426ms1106--- PASS: TestPush_RepeatedRootCommitsOnce (0.67s)1107=== CONT TestMultipartCleanup1108--- PASS: TestGetExistingObjectsLocksRows (0.64s)1109=== CONT TestServerTLSConfig1110=== RUN TestServerTLSConfig/no_client_CA1111=== PAUSE TestServerTLSConfig/no_client_CA1112=== RUN TestServerTLSConfig/missing_CA_file1113=== PAUSE TestServerTLSConfig/missing_CA_file1114=== RUN TestServerTLSConfig/not_a_PEM_file1115=== PAUSE TestServerTLSConfig/not_a_PEM_file1116=== CONT TestGCSweepSkipsPendingObjects11172026/10/10 19:01:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1118--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.63s)1119=== CONT TestService_NativeMTLS11202026/10/10 19:01:17 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MWY2ZDE0ZjQtZjc0OC00YmM2LWI2ZDAtNTM0MjBmZWUzNzM2LjI2NWZhZjc3LWE4ODctNDE5ZS1hNzM2LWYwOGRiOWYxOTYxZXgxNzkxNjU4ODc2NjQ1MzQyNTA1 parts=1011212026/10/10 19:01:17 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11222026/10/10 19:01:17 INFO Completed upload id=1 objects=2 duration=7.512765ms1123--- PASS: TestPresentRefreshesOnlyStaleClosures (0.61s)1124=== CONT TestDeduplicatedObjectsRecordedAsPending11252026/10/10 19:01:17 INFO Received uploads request method=POST path=/api/pending_closures11262026/10/10 19:01:17 INFO Received uploads request method=POST path=/api/pending_closures11272026/10/10 19:01:17 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo11282026/10/10 19:01:17 WARN Found objects in DB but missing from S3, will re-upload count=11129--- PASS: TestService_verifyS3Integrity (1.50s)1130=== CONT TestMetricsCommit11312026/10/10 19:01:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11322026/10/10 19:01:17 INFO Aborted multipart uploads count=0 kept=011332026/10/10 19:01:17 WARN Force mode enabled - objects will be deleted immediately without grace period11342026/10/10 19:01:17 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=011352026/10/10 19:01:17 INFO Vacuumed table table=pending_closures11362026/10/10 19:01:17 INFO Vacuumed table table=pending_objects11372026/10/10 19:01:17 INFO Vacuumed table table=multipart_uploads11382026/10/10 19:01:17 INFO Vacuumed table table=closures11392026/10/10 19:01:17 INFO Received uploads request method=POST path=/api/pending_closures11402026/10/10 19:01:17 INFO Vacuumed table table=objects11412026/10/10 19:01:17 INFO Aborted multipart uploads count=0 kept=011422026/10/10 19:01:17 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MWY2ZDE0ZjQtZjc0OC00YmM2LWI2ZDAtNTM0MjBmZWUzNzM2LmVjZDI3N2ViLTQyYzctNGY5Ny05YjM1LTc2Yzc4NDJmZjZjYXgxNzkxNjU4ODc2NjA3NTc0Mzcw parts=1211432026/10/10 19:01:17 INFO Received uploads request method=POST path=/api/pending_closures11442026/10/10 19:01:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1145--- PASS: TestPresentReportsOnlyClosureRoots (0.60s)1146=== CONT TestPushDedupSurvivesConcurrentGC11472026/10/10 19:01:17 WARN Force mode enabled - objects will be deleted immediately without grace period11482026/10/10 19:01:17 INFO Received uploads request method=POST path=/api/pending_closures11492026/10/10 19:01:17 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=011502026/10/10 19:01:17 INFO Vacuumed table table=pending_closures11512026/10/10 19:01:17 INFO Vacuumed table table=pending_objects11522026/10/10 19:01:17 INFO Vacuumed table table=multipart_uploads11532026/10/10 19:01:17 INFO Vacuumed table table=closures11542026/10/10 19:01:17 INFO Vacuumed table table=objects1155--- PASS: TestSweepSkipsRowsLockedByPush (0.67s)1156=== CONT TestMetricsInventory11572026/10/10 19:01:17 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MWY2ZDE0ZjQtZjc0OC00YmM2LWI2ZDAtNTM0MjBmZWUzNzM2LjUwZDNlZTJhLWVjNzYtNDM1NC05MjAzLWRhZmIxM2MxZWI1NngxNzkxNjU4ODc2NjcxMTI0Mjkz parts=1211582026/10/10 19:01:17 INFO Received uploads request method=POST path=/api/pending_closures1159--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.53s)1160=== CONT TestNARDeduplicationMetadataUploadBug1161--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.83s)1162=== CONT TestCreatePendingClosureRejectsOversizedNAR11632026/10/10 19:01:17 INFO Received uploads request method=POST path=/api/pending_closures1164--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1165=== CONT TestGCMetrics11662026-10-10 19:01:17.298 UTC [782] ERROR: Push does not exist: id=111672026-10-10 19:01:17.298 UTC [782] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE11682026-10-10 19:01:17.298 UTC [782] STATEMENT: SELECT commit_push($1)1169--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.98s)1170=== CONT TestCacheConfigHandlerMaxNarSize1171--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1172=== CONT TestGCBugBareHashReferences11732026/10/10 19:01:17 INFO Aborted multipart uploads count=0 kept=011742026/10/10 19:01:17 WARN Force mode enabled - objects will be deleted immediately without grace period11752026/10/10 19:01:17 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."11762026/10/10 19:01:17 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1177--- PASS: TestFailedS3DeleteKeepsTombstone (0.60s)1178=== CONT TestGenerateLandingPage1179--- PASS: TestGenerateLandingPage (0.00s)1180=== CONT TestGCAdvisoryLockBlocksConcurrentRun11812026/10/10 19:01:17 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11822026/10/10 19:01:17 WARN Refused reserved pin name=worker-x86_64-linux11832026/10/10 19:01:17 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11842026/10/10 19:01:17 INFO Received create pin request method=POST path=/api/pins/my-app11852026/10/10 19:01:17 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1186--- PASS: TestCreatePin_ReservedPins (0.61s)1187=== CONT TestService_readinessHandler11882026/10/10 19:01:17 INFO Received uploads request method=POST path=/api/pending_closures1189--- PASS: TestObjectStatsTrigger (0.51s)1190=== CONT TestService_healthCheckHandler11912026/10/10 19:01:17 INFO Received uploads request method=POST path=/api/pending_closures11922026/10/10 19:01:17 INFO Received uploads request method=POST path=/api/pending_closures11932026/10/10 19:01:17 INFO Received cleanup request method=DELETE path=/api/pending_closures11942026/10/10 19:01:17 INFO Received uploads request method=POST path=/api/pending_closures1195--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.53s)1196=== CONT TestLeadEndsOnShutdown11972026/10/10 19:01:17 INFO Aborted multipart uploads count=0 kept=011982026/10/10 19:01:17 WARN Force mode enabled - objects will be deleted immediately without grace period11992026/10/10 19:01:17 INFO Received uploads request method=POST path=/api/pending_closures1200--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.52s)1201=== CONT TestGracefulShutdownDrainsInflight12022026/10/10 19:01:17 INFO Starting HTTP server address=127.0.0.1:3772112032026/10/10 19:01:17 INFO Shutdown signal received, draining in-flight requests timeout=10s12042026/10/10 19:01:17 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=012052026/10/10 19:01:17 INFO Vacuumed table table=pending_closures12062026/10/10 19:01:17 INFO Vacuumed table table=pending_objects12072026/10/10 19:01:17 INFO Vacuumed table table=multipart_uploads12082026/10/10 19:01:17 INFO Vacuumed table table=closures12092026/10/10 19:01:17 INFO Received uploads request method=POST path=/api/pending_closures12102026/10/10 19:01:17 INFO Vacuumed table table=objects1211--- PASS: TestGCSweepDeliversEachKeyOnce (0.56s)1212=== CONT TestLeadIncumbentAnnouncesAtOnce12132026/10/10 19:01:17 INFO Received uploads request method=POST path=/api/pending_closures12142026/10/10 19:01:17 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12152026/10/10 19:01:17 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1216--- PASS: TestService_NativeMTLS (0.49s)1217=== CONT TestGCTaskStore_Fail1218--- PASS: TestGCTaskStore_Fail (0.00s)1219=== CONT TestLeadElectsOneAndHandsOver1220--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1221=== CONT TestGCTaskStore_PhaseUpdates1222--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1223=== CONT TestConnectWaitsForAPeerMigration1224=== NAME TestOrphanedObjectsGC1225 orphaned_objects_gc_test.go:287: GC Test Summary:1226 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1227 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1228 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1229 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1230 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1231--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.73s)1232--- PASS: TestOrphanedObjectsGC (0.85s)1233=== CONT TestGCTaskStore_CompletedAllowsNewTask1234--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1235=== CONT TestResolveDBConnectionString1236=== CONT TestGCTaskStore_GetReturnsLatest1237--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1238=== CONT TestGCTaskStore_GetEmpty1239--- PASS: TestGCTaskStore_GetEmpty (0.00s)1240=== RUN TestResolveDBConnectionString/flag_wins1241=== PAUSE TestResolveDBConnectionString/flag_wins1242=== CONT TestGCEndsOnShutdown1243=== RUN TestGCEndsOnShutdown/before_the_run1244=== PAUSE TestGCEndsOnShutdown/before_the_run1245=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1246=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1247=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1248=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1249=== RUN TestResolveDBConnectionString/file_when_flag_empty1250=== CONT TestCommitRacingPendingCleanupKeepsObjects1251=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1252=== RUN TestResolveDBConnectionString/missing_file_is_an_error1253=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1254=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1255=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1256=== RUN TestResolveDBConnectionString/nothing_configured1257=== PAUSE TestResolveDBConnectionString/nothing_configured1258=== CONT TestPushWaitsForSweepHoldingRow12592026/10/10 19:01:17 INFO Aborted multipart uploads count=0 kept=012602026/10/10 19:01:17 INFO Received uploads request method=POST path=/api/pending_closures12612026/10/10 19:01:17 WARN Force mode enabled - objects will be deleted immediately without grace period12622026/10/10 19:01:17 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=01263--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.49s)1264=== CONT TestGCTaskStore_ConflictDifferentParams1265--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1266=== CONT TestSweepRechecksPendingAfterLocking12672026/10/10 19:01:17 INFO Vacuumed table table=pending_closures12682026/10/10 19:01:17 INFO Vacuumed table table=pending_objects12692026/10/10 19:01:17 INFO Vacuumed table table=multipart_uploads12702026/10/10 19:01:17 INFO Vacuumed table table=closures12712026/10/10 19:01:17 INFO Vacuumed table table=objects12722026/10/10 19:01:17 INFO Received push request method=POST path=/api/pushes12732026/10/10 19:01:17 INFO Received cleanup request method=DELETE path=/api/pending_closures12742026/10/10 19:01:17 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket56/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""12752026/10/10 19:01:17 INFO Aborted multipart uploads count=0 kept=11276--- PASS: TestGCSweepSkipsPendingObjects (0.59s)1277=== CONT TestGCTaskStore_DeduplicateSameParams1278--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1279=== CONT TestGCTaskStore_StartNew1280--- PASS: TestGCTaskStore_StartNew (0.00s)1281=== CONT TestPinProtectsFromGC12822026/10/10 19:01:17 INFO Received cleanup request method=DELETE path=/api/pending_closures12832026/10/10 19:01:17 INFO Aborted multipart uploads count=1 kept=012842026/10/10 19:01:17 INFO Received complete push request method=POST path=/api/pushes/1/complete1285--- PASS: TestMultipartCleanup (0.63s)1286=== CONT TestClientErrorHandling1287=== RUN TestClientErrorHandling/InvalidStorePath1288=== PAUSE TestClientErrorHandling/InvalidStorePath1289=== RUN TestClientErrorHandling/InvalidAuthToken1290=== PAUSE TestClientErrorHandling/InvalidAuthToken1291=== RUN TestClientErrorHandling/ServerNotAvailable1292=== PAUSE TestClientErrorHandling/ServerNotAvailable1293=== CONT TestDeleteClosuresRacingPins12942026/10/10 19:01:17 INFO Completed push id=1 objects=4 duration=13.092104ms12952026/10/10 19:01:17 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12962026/10/10 19:01:17 INFO Completed upload id=2 objects=2 duration=2.196116ms12972026/10/10 19:01:17 INFO Received uploads request method=POST path=/api/pending_closures1298--- PASS: TestMetricsCommit (0.56s)1299=== CONT TestClientSharedPathCommittedMidPush1300--- PASS: TestMetricsInventory (0.51s)1301=== CONT TestClientFallsBackToClosures13022026/10/10 19:01:17 INFO Aborted multipart uploads count=0 kept=013032026/10/10 19:01:17 WARN Force mode enabled - objects will be deleted immediately without grace period13042026/10/10 19:01:17 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=01305=== NAME TestNARDeduplicationMetadataUploadBug1306 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2828017574/001/store/57k45agihk6ni8nxkwiplgcwl6fmnx9r-file1.txt13072026/10/10 19:01:17 INFO Vacuumed table table=pending_closures13082026/10/10 19:01:17 INFO Vacuumed table table=pending_objects13092026/10/10 19:01:17 INFO Vacuumed table table=multipart_uploads13102026/10/10 19:01:17 INFO Vacuumed table table=closures13112026/10/10 19:01:17 INFO Vacuumed table table=objects13122026/10/10 19:01:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13132026/10/10 19:01:17 INFO Aborted multipart uploads count=0 kept=01314--- PASS: TestGCMetrics (0.51s)1315=== CONT TestClientPushesUseOnePush13162026/10/10 19:01:17 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=013172026/10/10 19:01:17 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MWY2ZDE0ZjQtZjc0OC00YmM2LWI2ZDAtNTM0MjBmZWUzNzM2LmQ2MDFmYzEwLTI4N2YtNGJiYS1hMGQ3LWVjNDRkNThhNzFiZHgxNzkxNjU4ODc3MjQwNDk0MTk5 error="Get \"http://127.0.0.1:1/bucket23/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"13182026/10/10 19:01:17 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MWY2ZDE0ZjQtZjc0OC00YmM2LWI2ZDAtNTM0MjBmZWUzNzM2Ljk2NWZiYjkxLWYyYzQtNDNjZS04YTRiLTU5ZTY3MTExYzU3ZXgxNzkxNjU4ODc3MjMzNDQyMjMz parts=1213192026/10/10 19:01:17 INFO Received cleanup request method=DELETE path=/api/pending_closures13202026/10/10 19:01:17 INFO Vacuumed table table=pending_closures13212026/10/10 19:01:17 INFO Vacuumed table table=pending_objects13222026/10/10 19:01:17 INFO Vacuumed table table=multipart_uploads13232026/10/10 19:01:17 INFO Aborted multipart uploads count=1 kept=013242026/10/10 19:01:17 INFO Vacuumed table table=closures13252026/10/10 19:01:17 INFO Vacuumed table table=objects1326--- PASS: TestRedundantMultipartUpload (1.97s)1327=== CONT TestClientWithDependencies13282026/10/10 19:01:17 INFO Aborted multipart uploads count=0 kept=013292026/10/10 19:01:17 WARN Force mode enabled - objects will be deleted immediately without grace period13302026/10/10 19:01:17 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=013312026/10/10 19:01:17 INFO Vacuumed table table=pending_closures13322026/10/10 19:01:17 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"1333--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.48s)1334=== CONT TestClientMultipleUploads13352026/10/10 19:01:17 INFO Vacuumed table table=pending_objects13362026/10/10 19:01:17 INFO Vacuumed table table=multipart_uploads13372026/10/10 19:01:17 INFO Vacuumed table table=closures13382026/10/10 19:01:17 WARN readiness check failed error="closed pool"1339--- PASS: TestService_readinessHandler (0.49s)1340=== CONT TestService_RequireScope_OIDC13412026/10/10 19:01:17 INFO Vacuumed table table=objects1342--- PASS: TestPushDedupSurvivesConcurrentGC (0.62s)1343=== CONT TestClientIntegration1344--- PASS: TestService_healthCheckHandler (0.43s)1345=== CONT TestClientCADerivations13462026/10/10 19:01:17 INFO Received push request method=POST path=/api/pushes13472026/10/10 19:01:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43809/oidc13482026/10/10 19:01:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13492026/10/10 19:01:17 INFO Uploading 57k45agihk6ni8nxkwiplgcwl6fmnx9r-file1.txt (160B)13502026/10/10 19:01:17 INFO lead: acquired remote=192.0.2.1:123413512026/10/10 19:01:17 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"13522026/10/10 19:01:17 WARN Failed to register uploaded object key=57k45agihk6ni8nxkwiplgcwl6fmnx9r.ls error="server returned 404: 404 page not found\n"13532026/10/10 19:01:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13542026/10/10 19:01:17 INFO Signed narinfos id=1 count=113552026/10/10 19:01:17 INFO Uploading 1 narinfos13562026/10/10 19:01:17 INFO Received complete push request method=POST path=/api/pushes/1/complete13572026/10/10 19:01:17 WARN Failed to register uploaded object key=57k45agihk6ni8nxkwiplgcwl6fmnx9r.narinfo error="server returned 404: 404 page not found\n"13582026/10/10 19:01:17 INFO Completed push id=1 objects=3 duration=11.644967ms13592026/10/10 19:01:17 INFO Upload complete. (79ms)1360=== NAME TestNARDeduplicationMetadataUploadBug1361 metadata_upload_test.go:54: Retrieved narinfo from S3:1362 StorePath: /build/TestNARDeduplicationMetadataUploadBug2828017574/001/store/57k45agihk6ni8nxkwiplgcwl6fmnx9r-file1.txt1363 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1364 Compression: zstd1365 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1366 NarSize: 1601367 References: 1368 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1369 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1370 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1371 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}13722026/10/10 19:01:17 INFO lead: acquired remote=192.0.2.1:123413732026/10/10 19:01:17 INFO lead: released remote=192.0.2.1:12341374--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.38s)1375=== CONT TestCacheConfigHandler1376=== RUN TestCacheConfigHandler/full_config,_no_issuer1377=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1378=== RUN TestCacheConfigHandler/no_cache_url_configured1379=== PAUSE TestCacheConfigHandler/no_cache_url_configured1380=== RUN TestCacheConfigHandler/no_signing_keys1381=== PAUSE TestCacheConfigHandler/no_signing_keys1382=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1383=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1384=== CONT TestService_ReadScope_PublicByDefault13852026/10/10 19:01:17 INFO lead: acquired remote=192.0.2.1:12341386=== NAME TestNARDeduplicationMetadataUploadBug1387 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2828017574/001/store/375z6w6af6bcxp8ncmxhv2yh3v44pam4-file2.txt13882026/10/10 19:01:18 INFO Received uploads request method=POST path=/api/pending_closures13892026/10/10 19:01:18 INFO Aborted multipart uploads count=0 kept=01390--- PASS: TestGCBugBareHashReferences (0.75s)1391=== CONT TestCacheStatsHandler13922026/10/10 19:01:18 INFO Received push request method=POST path=/api/pushes13932026/10/10 19:01:18 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13942026/10/10 19:01:18 WARN Force mode enabled - objects will be deleted immediately without grace period13952026/10/10 19:01:18 INFO Aborted multipart uploads count=0 kept=013962026/10/10 19:01:18 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13972026/10/10 19:01:18 INFO Signed narinfos id=2 count=113982026/10/10 19:01:18 WARN Failed to register uploaded object key=375z6w6af6bcxp8ncmxhv2yh3v44pam4.ls error="server returned 404: 404 page not found\n"13992026/10/10 19:01:18 INFO Uploading 1 narinfos14002026/10/10 19:01:18 WARN Force mode enabled - objects will be deleted immediately without grace period14012026/10/10 19:01:18 INFO Received complete push request method=POST path=/api/pushes/2/complete14022026/10/10 19:01:18 WARN Failed to register uploaded object key=375z6w6af6bcxp8ncmxhv2yh3v44pam4.narinfo error="server returned 404: 404 page not found\n"14032026/10/10 19:01:18 INFO Completed push id=2 objects=3 duration=1.477887ms14042026/10/10 19:01:18 INFO Upload complete. (63ms)1405=== NAME TestNARDeduplicationMetadataUploadBug1406 metadata_upload_test.go:76: Retrieved narinfo from S3:1407 StorePath: /build/TestNARDeduplicationMetadataUploadBug2828017574/001/store/375z6w6af6bcxp8ncmxhv2yh3v44pam4-file2.txt1408 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1409 Compression: zstd1410 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1411 NarSize: 1601412 References: 1413 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf14142026/10/10 19:01:18 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=01415 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1416 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1417 {"version":1,"root":{"type":"regular","size":44}}14182026/10/10 19:01:18 INFO Vacuumed table table=pending_closures1419--- PASS: TestNARDeduplicationMetadataUploadBug (0.78s)1420=== CONT TestService_ReadAuthMiddleware14212026/10/10 19:01:18 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=014222026/10/10 19:01:18 INFO Vacuumed table table=pending_objects14232026/10/10 19:01:18 INFO Vacuumed table table=multipart_uploads14242026/10/10 19:01:18 INFO Vacuumed table table=pending_closures14252026/10/10 19:01:18 INFO Vacuumed table table=closures14262026/10/10 19:01:18 INFO Vacuumed table table=objects14272026/10/10 19:01:18 INFO Vacuumed table table=pending_objects14282026/10/10 19:01:18 INFO Vacuumed table table=multipart_uploads14292026/10/10 19:01:18 INFO Vacuumed table table=closures14302026/10/10 19:01:18 INFO Vacuumed table table=objects1431--- PASS: TestSweepRechecksPendingAfterLocking (0.45s)1432=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1433--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.47s)1434=== CONT TestService_AuthMiddleware_OIDC14352026/10/10 19:01:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38843/oidc1436=== NAME TestPinProtectsFromGC1437 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC967749407/001/store/p9nxabzsfxidd7cly5bw5v90325ciszx-pinned-file.txt1438 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC967749407/001/store/z5ggrd9sg6h72aw0g85s8mbj70fqzf7a-unpinned-file.txt14392026/10/10 19:01:18 INFO Received push request method=POST path=/api/pushes14402026/10/10 19:01:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14412026/10/10 19:01:18 INFO Uploading p9nxabzsfxidd7cly5bw5v90325ciszx-pinned-file.txt (128B)1442=== NAME TestClientMultipleUploads1443 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads1056175384/001/store/8qq7r57ppfwdbfia29l76sm8fcfqxdf6-test-file-0.txt14442026/10/10 19:01:18 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14452026/10/10 19:01:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14462026/10/10 19:01:18 WARN Failed to register uploaded object key=p9nxabzsfxidd7cly5bw5v90325ciszx.ls error="server returned 404: 404 page not found\n"14472026/10/10 19:01:18 INFO Signed narinfos id=1 count=114482026/10/10 19:01:18 INFO Uploading 1 narinfos14492026/10/10 19:01:18 INFO Received complete push request method=POST path=/api/pushes/1/complete14502026/10/10 19:01:18 WARN Failed to register uploaded object key=p9nxabzsfxidd7cly5bw5v90325ciszx.narinfo error="server returned 404: 404 page not found\n"1451=== NAME TestClientIntegration1452 client_integration_test.go:286: Created store path: /build/TestClientIntegration4090721781/002/store/614pbjqvg4rk7vsg2r8qig7x0ha447kv-test-file.txt14532026/10/10 19:01:18 INFO Completed push id=1 objects=3 duration=8.502703ms14542026/10/10 19:01:18 INFO Upload complete. (82ms)1455=== NAME TestClientWithDependencies1456 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies3776465529/001/store/nmb9znv9arm4nfy3xc4igrhah185h0ms-test-script1457=== RUN TestService_RequireScope_OIDC/builder_may_write1458=== PAUSE TestService_RequireScope_OIDC/builder_may_write1459=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1460=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1461=== RUN TestService_RequireScope_OIDC/ops_may_admin1462=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1463=== RUN TestService_RequireScope_OIDC/ops_may_not_write1464=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1465=== RUN TestService_RequireScope_OIDC/reader_may_not_write1466=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1467=== RUN TestService_RequireScope_OIDC/static_token_may_admin1468=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1469=== RUN TestService_RequireScope_OIDC/static_token_may_write1470=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1471=== RUN TestService_RequireScope_OIDC/reader_may_read1472=== PAUSE TestService_RequireScope_OIDC/reader_may_read1473=== RUN TestService_RequireScope_OIDC/writer_implies_read1474=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1475=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1476=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1477=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1478=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1479=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1480=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1481=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1482=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1483=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1484=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1485=== CONT TestService_AuthMiddleware_MTLSProxyHeader14862026/10/10 19:01:18 INFO Received push request method=POST path=/api/pushes1487--- PASS: TestService_ReadScope_PublicByDefault (0.37s)1488=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info14892026/10/10 19:01:18 INFO Received uploads request method=POST path=/1490=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key14912026/10/10 19:01:18 INFO Received complete multipart upload request method=POST path=/1492=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key14932026/10/10 19:01:18 INFO Received request for more parts method=POST path=/1494=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal14952026/10/10 19:01:18 INFO Received uploads request method=POST path=/1496--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1497 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1498 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1499 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1500 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1501=== CONT TestPendingClosureWriteTimeout/empty1502=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline15032026/10/10 19:01:18 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)15042026/10/10 19:01:18 INFO Uploading dm0132p5hlml1423cqznaxdkx8x22x20-shared-dep (136B)15052026/10/10 19:01:18 INFO Uploading sy6a3v12z120nicwkhy3340hgn53fza6-top (224B)1506=== NAME TestClientMultipleUploads1507 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads1056175384/001/store/rgh5m35jpzwgs3vm3hf8dqksszaq2xfg-test-file-1.txt15082026/10/10 19:01:18 WARN Failed to register uploaded object key=nar/0l86jhphmqmz5g2mq8v135g902flbahv3njr14hlgnhg2skgnl6v.nar.zst error="server returned 404: 404 page not found\n"15092026/10/10 19:01:18 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15102026/10/10 19:01:18 WARN Failed to register uploaded object key=sy6a3v12z120nicwkhy3340hgn53fza6.ls error="server returned 404: 404 page not found\n"15112026/10/10 19:01:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15122026/10/10 19:01:18 INFO Signed narinfos id=1 count=215132026/10/10 19:01:18 INFO Uploading 2 narinfos15142026/10/10 19:01:18 WARN Failed to register uploaded object key=dm0132p5hlml1423cqznaxdkx8x22x20.ls error="server returned 404: 404 page not found\n"15152026/10/10 19:01:18 WARN Failed to register uploaded object key=dm0132p5hlml1423cqznaxdkx8x22x20.narinfo error="server returned 404: 404 page not found\n"1516=== NAME TestClientWithDependencies1517 client_integration_test.go:615: Found 1 dependencies (including self)15182026/10/10 19:01:18 INFO Received complete push request method=POST path=/api/pushes/1/complete15192026/10/10 19:01:18 WARN Failed to register uploaded object key=sy6a3v12z120nicwkhy3340hgn53fza6.narinfo error="server returned 404: 404 page not found\n"1520--- PASS: TestObjectStatsLargeCommit (1.51s)1521=== CONT TestPendingClosureWriteTimeout/400_objects1522=== CONT TestPendingClosureWriteTimeout/670k_objects1523=== CONT TestProxyWriteTimeout/narinfo1524=== CONT TestProxyWriteTimeout/unknown_size15252026/10/10 19:01:18 INFO Completed push id=1 objects=6 duration=6.287728ms1526=== CONT TestProxyWriteTimeout/10_GiB_nar1527=== CONT TestProxyWriteTimeout/1_GiB_nar15282026/10/10 19:01:18 INFO Upload complete. (67ms)1529--- PASS: TestProxyWriteTimeout (0.09s)1530 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1531 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1532 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1533 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1534=== CONT TestIsValidUploadKey/narinfo1535=== CONT TestIsValidUploadKey/realisation_plus_in_output1536=== CONT TestIsValidUploadKey/realisation1537=== CONT TestIsValidUploadKey/build_log_equals1538=== CONT TestIsValidUploadKey/build_log_question_mark1539=== CONT TestIsValidUploadKey/build_log_plus_in_name1540=== CONT TestIsValidUploadKey/build_log_home-manager_file1541=== CONT TestIsValidUploadKey/build_log1542=== CONT TestIsValidUploadKey/listing1543=== CONT TestIsValidUploadKey/nar_plain1544=== CONT TestIsValidUploadKey/nar_xz1545=== CONT TestIsValidUploadKey/nar_zst1546=== CONT TestIsValidUploadKey/traversal_nar1547=== CONT TestIsValidUploadKey/nix-cache-info1548=== CONT TestIsValidUploadKey/traversal1549=== CONT TestIsValidUploadKey/empty_key1550=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1551=== CONT TestIsValidUploadKey/unknown_type1552=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1553=== CONT TestIsValidUploadKey/absolute1554=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1555=== CONT TestIsValidUploadKey/index.html1556--- PASS: TestIsValidUploadKey (0.09s)1557 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1558 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1559 --- PASS: TestIsValidUploadKey/realisation (0.00s)1560 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1561 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1562 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1563 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1564 --- PASS: TestIsValidUploadKey/build_log (0.00s)1565 --- PASS: TestIsValidUploadKey/listing (0.00s)1566 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1567 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1568 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1569 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1570 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1571 --- PASS: TestIsValidUploadKey/traversal (0.00s)1572 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1573 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1574 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1575 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1576 --- PASS: TestIsValidUploadKey/absolute (0.00s)1577 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1578 --- PASS: TestIsValidUploadKey/index.html (0.00s)1579=== NAME TestClientSharedPathCommittedMidPush1580 client_integration_test.go:680: Retrieved narinfo from S3:1581 StorePath: /build/TestClientSharedPathCommittedMidPush2359150248/001/store/dm0132p5hlml1423cqznaxdkx8x22x20-shared-dep1582 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1583 Compression: zstd1584 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821585 NarSize: 1361586 References: 1587 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1588=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure15892026/10/10 19:01:18 INFO Received uploads request method=POST path=/1590=== NAME TestClientSharedPathCommittedMidPush1591 client_integration_test.go:680: Retrieved narinfo from S3:1592 StorePath: /build/TestClientSharedPathCommittedMidPush2359150248/001/store/sy6a3v12z120nicwkhy3340hgn53fza6-top1593 URL: nar/0l86jhphmqmz5g2mq8v135g902flbahv3njr14hlgnhg2skgnl6v.nar.zst1594 Compression: zstd1595 NarHash: sha256:0l86jhphmqmz5g2mq8v135g902flbahv3njr14hlgnhg2skgnl6v1596 NarSize: 2241597 References: /build/TestClientSharedPathCommittedMidPush2359150248/001/store/dm0132p5hlml1423cqznaxdkx8x22x20-shared-dep1598 CA: text:sha256:0sbcm4hsq9hjdxf37lz251b97rnqy6pl14bsi48hvxjcsc4xgx7h1599--- PASS: TestCacheStatsHandler (0.28s)1600=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16012026/10/10 19:01:18 INFO Received request for more parts method=POST path=/1602--- PASS: TestClientSharedPathCommittedMidPush (0.61s)1603=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16042026/10/10 19:01:18 INFO Received complete multipart upload request method=POST path=/16052026/10/10 19:01:18 INFO Received uploads request method=POST path=/api/pending_closures1606--- PASS: TestService_ReadAuthMiddleware (0.26s)1607=== CONT TestIsValidCachePath/narinfo1608=== CONT TestIsValidCachePath/index.html1609=== CONT TestIsValidCachePath/short_hash1610=== CONT TestIsValidCachePath/wrong_extension1611=== CONT TestIsValidCachePath/leading_slash1612=== CONT TestIsValidCachePath/nar_uncompressed1613=== CONT TestIsValidCachePath/nix-cache-info1614=== CONT TestIsValidCachePath/empty1615=== CONT TestIsValidCachePath/realisation1616=== CONT TestIsValidCachePath/random_path1617=== CONT TestIsValidCachePath/log1618=== CONT TestIsValidCachePath/invalid_char_u1619=== NAME TestClientCADerivations1620 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations698599980/001/store/xdvi3y6kf73lllaldz5ls2nd93hdvzgm-ca-test1621=== CONT TestIsValidCachePath/ls1622=== CONT TestIsValidCachePath/invalid_char_e1623=== CONT TestIsValidCachePath/traversal_in_middle1624=== CONT TestIsValidCachePath/nar_xz1625=== CONT TestIsValidCachePath/traversal_parent1626=== CONT TestIsValidCachePath/nar_bz21627=== CONT TestIsValidCachePath/nar_zst1628=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1629--- PASS: TestIsValidCachePath (0.00s)1630 --- PASS: TestIsValidCachePath/narinfo (0.00s)1631 --- PASS: TestIsValidCachePath/index.html (0.00s)1632 --- PASS: TestIsValidCachePath/short_hash (0.00s)1633 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1634 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1635 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1636 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1637 --- PASS: TestIsValidCachePath/empty (0.00s)1638 --- PASS: TestIsValidCachePath/realisation (0.00s)1639 --- PASS: TestIsValidCachePath/random_path (0.00s)1640 --- PASS: TestIsValidCachePath/log (0.00s)1641 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1642 --- PASS: TestIsValidCachePath/ls (0.00s)1643 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1644 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1645 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1646 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1647 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1648 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1649 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1650=== CONT TestParseSingleRange/none1651=== CONT TestParseSingleRange/open-ended1652=== CONT TestParseSingleRange/start_far_past_EOF1653=== CONT TestParseSingleRange/start_past_EOF1654=== CONT TestParseSingleRange/single_byte1655=== CONT TestParseSingleRange/suffix_exceeds_size1656=== NAME TestClientMultipleUploads1657 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads1056175384/001/store/mz4khlh6c3ix4hda70bf1q4q3pj2ids8-test-file-2.txt1658=== CONT TestParseSingleRange/suffix1659=== CONT TestParseSingleRange/end_clamped_to_size1660=== CONT TestParseSingleRange/malformed_both_empty1661=== CONT TestParseSingleRange/closed1662=== CONT TestParseSingleRange/malformed_end_before_start1663=== CONT TestParseSingleRange/multi-range_ignored1664=== CONT TestParseSingleRange/malformed_no_dash1665=== CONT TestParseSingleRange/unknown_unit1666=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1667--- PASS: TestParseSingleRange (0.00s)1668 --- PASS: TestParseSingleRange/none (0.00s)1669 --- PASS: TestParseSingleRange/open-ended (0.00s)1670 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1671 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1672 --- PASS: TestParseSingleRange/single_byte (0.00s)1673 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1674 --- PASS: TestParseSingleRange/suffix (0.00s)1675 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1676 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1677 --- PASS: TestParseSingleRange/closed (0.00s)1678 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1679 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1680 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1681 --- PASS: TestParseSingleRange/unknown_unit (0.00s)16822026/10/10 19:01:18 INFO Received push request method=POST path=/api/pushes16832026/10/10 19:01:18 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16842026/10/10 19:01:18 WARN mTLS auth: bound subjects configured but subject DN unavailable16852026/10/10 19:01:18 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"16862026/10/10 19:01:18 INFO Received push request method=POST path=/api/pushes1687--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.27s)1688=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh16892026/10/10 19:01:18 INFO Received uploads request method=POST path=/api/pending_closures16902026/10/10 19:01:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16912026/10/10 19:01:18 INFO Uploading z5ggrd9sg6h72aw0g85s8mbj70fqzf7a-unpinned-file.txt (128B)16922026/10/10 19:01:18 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16932026/10/10 19:01:18 INFO Uploading ifn1zs360nbwhls7gfc2c61if25mkr5q-shared-dep (136B)16942026/10/10 19:01:18 INFO Uploading r0k68193xdzvb36zwhpbpwa0ahir01k2-a (216B)16952026/10/10 19:01:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16962026/10/10 19:01:18 INFO Uploading 614pbjqvg4rk7vsg2r8qig7x0ha447kv-test-file.txt (152B)16972026/10/10 19:01:18 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"16982026/10/10 19:01:18 WARN Failed to register uploaded object key=z5ggrd9sg6h72aw0g85s8mbj70fqzf7a.ls error="server returned 404: 404 page not found\n"16992026/10/10 19:01:18 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17002026/10/10 19:01:18 INFO Signed narinfos id=2 count=117012026/10/10 19:01:18 INFO Uploading 1 narinfos17022026/10/10 19:01:18 WARN Failed to register uploaded object key=0818k9qik7yg17zib0myqziphvqq4bkf.ls error="server returned 404: 404 page not found\n"17032026/10/10 19:01:18 WARN Failed to register uploaded object key=r0k68193xdzvb36zwhpbpwa0ahir01k2.ls error="server returned 404: 404 page not found\n"17042026/10/10 19:01:18 WARN Failed to register uploaded object key=nar/0q8hy5wfkhln98sa2k98sc4id7fj3r8h79fxhg8x2i7nhdrz7cky.nar.zst error="server returned 404: 404 page not found\n"17052026/10/10 19:01:18 INFO Received push request method=POST path=/api/pushes17062026/10/10 19:01:18 WARN Failed to register uploaded object key=ifn1zs360nbwhls7gfc2c61if25mkr5q.ls error="server returned 404: 404 page not found\n"17072026/10/10 19:01:18 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17082026/10/10 19:01:18 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17092026/10/10 19:01:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17102026/10/10 19:01:18 INFO Signed narinfos id=2 count=217112026/10/10 19:01:18 INFO Received complete push request method=POST path=/api/pushes/2/complete17122026/10/10 19:01:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17132026/10/10 19:01:18 WARN Failed to register uploaded object key=614pbjqvg4rk7vsg2r8qig7x0ha447kv.ls error="server returned 404: 404 page not found\n"17142026/10/10 19:01:18 WARN Failed to register uploaded object key=z5ggrd9sg6h72aw0g85s8mbj70fqzf7a.narinfo error="server returned 404: 404 page not found\n"17152026/10/10 19:01:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17162026/10/10 19:01:18 INFO Signed narinfos id=1 count=117172026/10/10 19:01:18 INFO Signed narinfos id=1 count=217182026/10/10 19:01:18 INFO Uploading 1 narinfos17192026/10/10 19:01:18 INFO Uploading 4 narinfos1720=== CONT TestPush_RejectsBadRequests/no_roots17212026/10/10 19:01:18 INFO Received push request method=POST path=/api/pushes1722=== CONT TestPush_RejectsBadRequests/bad_root17232026/10/10 19:01:18 INFO Received push request method=POST path=/api/pushes1724=== CONT TestPush_RejectsBadRequests/no_objects17252026/10/10 19:01:18 INFO Received push request method=POST path=/api/pushes1726=== CONT TestPush_RejectsBadRequests/root_not_in_objects17272026/10/10 19:01:18 INFO Received push request method=POST path=/api/pushes1728=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1729--- PASS: TestPush_RejectsBadRequests (0.61s)1730 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1731 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1732 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1733 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)17342026/10/10 19:01:18 INFO Completed push id=2 objects=3 duration=3.899892ms17352026/10/10 19:01:18 INFO Upload complete. (59ms)17362026/10/10 19:01:18 WARN Failed to register uploaded object key=ifn1zs360nbwhls7gfc2c61if25mkr5q.narinfo error="server returned 404: 404 page not found\n"17372026/10/10 19:01:18 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17382026/10/10 19:01:18 INFO Uploading f7ij1vbb2m27k6jp7mx2g1wz7mng7qz0-shared-dep (136B)17392026/10/10 19:01:18 WARN Failed to register uploaded object key=r0k68193xdzvb36zwhpbpwa0ahir01k2.narinfo error="server returned 404: 404 page not found\n"17402026/10/10 19:01:18 INFO Uploading shmc7bvbihwfh3rdgmkcwpgw58s44rfi-b (216B)1741=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token17422026/10/10 19:01:18 INFO Received complete push request method=POST path=/api/pushes/1/complete1743=== NAME TestClientCADerivations17442026/10/10 19:01:18 WARN Failed to register uploaded object key=614pbjqvg4rk7vsg2r8qig7x0ha447kv.narinfo error="server returned 404: 404 page not found\n"1745 client_ca_test.go:139: Found 1 dependencies (including self)17462026/10/10 19:01:18 WARN Failed to register uploaded object key=0818k9qik7yg17zib0myqziphvqq4bkf.narinfo error="server returned 404: 404 page not found\n"1747=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1748=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1749=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1750=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1751=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1752=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1753=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1754=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check17552026/10/10 19:01:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17562026/10/10 19:01:18 WARN Failed to register uploaded object key=ifn1zs360nbwhls7gfc2c61if25mkr5q.narinfo error="server returned 404: 404 page not found\n"17572026/10/10 19:01:18 WARN Failed to register uploaded object key=f7ij1vbb2m27k6jp7mx2g1wz7mng7qz0.ls error="server returned 404: 404 page not found\n"17582026/10/10 19:01:18 WARN Failed to register uploaded object key=nar/1rq50xqz1lrb1626b70nvg4anarvs5nvyds3vslbvc73j2ymk1cp.nar.zst error="server returned 404: 404 page not found\n"17592026/10/10 19:01:18 WARN Failed to register uploaded object key=shmc7bvbihwfh3rdgmkcwpgw58s44rfi.ls error="server returned 404: 404 page not found\n"17602026/10/10 19:01:18 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17612026/10/10 19:01:18 WARN Failed to register uploaded object key=phgbkadggrarjckpgqb6yj02f7h14lc3.ls error="server returned 404: 404 page not found\n"17622026/10/10 19:01:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17632026/10/10 19:01:18 INFO Signed narinfos id=1 count=317642026/10/10 19:01:18 INFO Uploading 3 narinfos17652026/10/10 19:01:18 INFO Completed push id=1 objects=3 duration=5.336729ms17662026/10/10 19:01:18 INFO Upload complete. (70ms)17672026/10/10 19:01:18 WARN Failed to register uploaded object key=phgbkadggrarjckpgqb6yj02f7h14lc3.narinfo error="server returned 404: 404 page not found\n"17682026/10/10 19:01:18 WARN Failed to register uploaded object key=shmc7bvbihwfh3rdgmkcwpgw58s44rfi.narinfo error="server returned 404: 404 page not found\n"17692026/10/10 19:01:18 INFO Received complete push request method=POST path=/api/pushes/1/complete17702026/10/10 19:01:18 WARN Failed to register uploaded object key=f7ij1vbb2m27k6jp7mx2g1wz7mng7qz0.narinfo error="server returned 404: 404 page not found\n"17712026/10/10 19:01:18 INFO Completed upload id=1 objects=6 duration=14.112412ms17722026/10/10 19:01:18 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17732026/10/10 19:01:18 INFO Completed upload id=2 objects=6 duration=2.263926ms17742026/10/10 19:01:18 INFO Received push request method=POST path=/api/pushes17752026/10/10 19:01:18 INFO Upload complete. (103ms)1776=== NAME TestClientFallsBackToClosures1777 client_pushes_test.go:112: Retrieved narinfo from S3:1778 StorePath: /build/TestClientFallsBackToClosures317408057/001/store/ifn1zs360nbwhls7gfc2c61if25mkr5q-shared-dep1779 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1780 Compression: zstd1781 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821782 NarSize: 1361783 References: 1784 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1785=== CONT TestServerTLSConfig/no_client_CA1786=== CONT TestServerTLSConfig/not_a_PEM_file17872026/10/10 19:01:18 INFO Completed push id=1 objects=8 duration=9.944301ms17882026/10/10 19:01:18 INFO Upload complete. (70ms)1789=== CONT TestServerTLSConfig/missing_CA_file1790--- PASS: TestServerTLSConfig (0.00s)1791 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1792 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1793 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1794=== CONT TestGCEndsOnShutdown/before_the_run1795=== NAME TestClientPushesUseOnePush1796 client_pushes_test.go:97: Retrieved narinfo from S3:1797 StorePath: /build/TestClientPushesUseOnePush4016016766/001/store/f7ij1vbb2m27k6jp7mx2g1wz7mng7qz0-shared-dep1798 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1799 Compression: zstd1800 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821801 NarSize: 1361802 References: 1803 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1804=== NAME TestClientFallsBackToClosures1805 client_pushes_test.go:112: Retrieved narinfo from S3:1806 StorePath: /build/TestClientFallsBackToClosures317408057/001/store/r0k68193xdzvb36zwhpbpwa0ahir01k2-a1807 URL: nar/0q8hy5wfkhln98sa2k98sc4id7fj3r8h79fxhg8x2i7nhdrz7cky.nar.zst1808 Compression: zstd1809 NarHash: sha256:0q8hy5wfkhln98sa2k98sc4id7fj3r8h79fxhg8x2i7nhdrz7cky18102026/10/10 19:01:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1811 NarSize: 2161812 References: /build/TestClientFallsBackToClosures317408057/001/store/ifn1zs360nbwhls7gfc2c61if25mkr5q-shared-dep18132026/10/10 19:01:18 INFO Uploading nmb9znv9arm4nfy3xc4igrhah185h0ms-test-script (136B)1814 CA: text:sha256:0fbv2ikqig8yi2gdjpwdd0k2vvr52lsdall6pq43zb2ix1sachab1815=== NAME TestClientPushesUseOnePush1816 client_pushes_test.go:97: Retrieved narinfo from S3:1817 StorePath: /build/TestClientPushesUseOnePush4016016766/001/store/phgbkadggrarjckpgqb6yj02f7h14lc3-a1818 URL: nar/1rq50xqz1lrb1626b70nvg4anarvs5nvyds3vslbvc73j2ymk1cp.nar.zst1819 Compression: zstd1820 NarHash: sha256:1rq50xqz1lrb1626b70nvg4anarvs5nvyds3vslbvc73j2ymk1cp1821 NarSize: 2161822 References: /build/TestClientPushesUseOnePush4016016766/001/store/f7ij1vbb2m27k6jp7mx2g1wz7mng7qz0-shared-dep1823 CA: text:sha256:114h5iahhzzpvgd1b01r3lfnprnlg3b5h4sbi689ypqx3s2i5pxz1824=== NAME TestClientFallsBackToClosures1825 client_pushes_test.go:112: Retrieved narinfo from S3:1826 StorePath: /build/TestClientFallsBackToClosures317408057/001/store/0818k9qik7yg17zib0myqziphvqq4bkf-b1827 URL: nar/0q8hy5wfkhln98sa2k98sc4id7fj3r8h79fxhg8x2i7nhdrz7cky.nar.zst1828 Compression: zstd1829 NarHash: sha256:0q8hy5wfkhln98sa2k98sc4id7fj3r8h79fxhg8x2i7nhdrz7cky1830 NarSize: 2161831 References: /build/TestClientFallsBackToClosures317408057/001/store/ifn1zs360nbwhls7gfc2c61if25mkr5q-shared-dep1832 CA: text:sha256:0fbv2ikqig8yi2gdjpwdd0k2vvr52lsdall6pq43zb2ix1sachab1833=== NAME TestClientPushesUseOnePush1834 client_pushes_test.go:97: Retrieved narinfo from S3:1835 StorePath: /build/TestClientPushesUseOnePush4016016766/001/store/shmc7bvbihwfh3rdgmkcwpgw58s44rfi-b1836 URL: nar/1rq50xqz1lrb1626b70nvg4anarvs5nvyds3vslbvc73j2ymk1cp.nar.zst1837 Compression: zstd18382026/10/10 19:01:18 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"1839 NarHash: sha256:1rq50xqz1lrb1626b70nvg4anarvs5nvyds3vslbvc73j2ymk1cp18402026/10/10 19:01:18 WARN Failed to register uploaded object key=log/wjb4n1zaa268m53x2wvjnxkhnz5g18fa-test-script.drv error="server returned 404: 404 page not found\n"1841 NarSize: 2161842 References: /build/TestClientPushesUseOnePush4016016766/001/store/f7ij1vbb2m27k6jp7mx2g1wz7mng7qz0-shared-dep1843 CA: text:sha256:114h5iahhzzpvgd1b01r3lfnprnlg3b5h4sbi689ypqx3s2i5pxz18442026/10/10 19:01:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18452026/10/10 19:01:18 WARN Failed to register uploaded object key=nmb9znv9arm4nfy3xc4igrhah185h0ms.ls error="server returned 404: 404 page not found\n"18462026/10/10 19:01:18 INFO Signed narinfos id=1 count=118472026/10/10 19:01:18 INFO Uploading 1 narinfos1848--- PASS: TestClientFallsBackToClosures (0.64s)1849=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark18502026/10/10 19:01:18 INFO Received complete push request method=POST path=/api/pushes/1/complete1851--- PASS: TestClientPushesUseOnePush (0.60s)18522026/10/10 19:01:18 WARN Failed to register uploaded object key=nmb9znv9arm4nfy3xc4igrhah185h0ms.narinfo error="server returned 404: 404 page not found\n"1853=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete18542026/10/10 19:01:18 INFO Completed push id=1 objects=4 duration=6.874676ms18552026/10/10 19:01:18 INFO Upload complete. (65ms)1856=== NAME TestClientWithDependencies1857 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3776465529/001/store) requires matching store prefix1858--- PASS: TestClientWithDependencies (0.60s)1859=== CONT TestResolveDBConnectionString/flag_wins1860=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1861=== CONT TestResolveDBConnectionString/nothing_configured1862=== CONT TestResolveDBConnectionString/missing_file_is_an_error1863=== CONT TestResolveDBConnectionString/file_when_flag_empty1864=== CONT TestClientErrorHandling/InvalidStorePath1865--- PASS: TestResolveDBConnectionString (0.00s)1866 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1867 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1868 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1869 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1870 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)18712026/10/10 19:01:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures18722026/10/10 19:01:18 INFO Garbage collection started18732026/10/10 19:01:18 INFO Received push request method=POST path=/api/pushes18742026/10/10 19:01:18 INFO All 1 paths already cached1875=== NAME TestClientIntegration1876 client_integration_test.go:312: Retrieved narinfo from S3:1877 StorePath: /build/TestClientIntegration4090721781/002/store/614pbjqvg4rk7vsg2r8qig7x0ha447kv-test-file.txt1878 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1879 Compression: zstd1880 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11881 NarSize: 1521882 References: 1883 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11884 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1885 client_integration_test.go:313: Decompressed .ls content (64 bytes):1886 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1887 client_integration_test.go:316: Testing garbage collection...18882026/10/10 19:01:18 INFO Aborted multipart uploads count=0 kept=018892026/10/10 19:01:18 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)18902026/10/10 19:01:18 INFO Uploading rgh5m35jpzwgs3vm3hf8dqksszaq2xfg-test-file-1.txt (160B)18912026/10/10 19:01:18 INFO Uploading 8qq7r57ppfwdbfia29l76sm8fcfqxdf6-test-file-0.txt (160B)18922026/10/10 19:01:18 INFO Uploading mz4khlh6c3ix4hda70bf1q4q3pj2ids8-test-file-2.txt (160B)18932026/10/10 19:01:18 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"18942026/10/10 19:01:18 WARN Failed to register uploaded object key=rgh5m35jpzwgs3vm3hf8dqksszaq2xfg.ls error="server returned 404: 404 page not found\n"18952026/10/10 19:01:18 WARN Failed to register uploaded object key=8qq7r57ppfwdbfia29l76sm8fcfqxdf6.ls error="server returned 404: 404 page not found\n"18962026/10/10 19:01:18 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"18972026/10/10 19:01:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18982026/10/10 19:01:18 WARN Failed to register uploaded object key=mz4khlh6c3ix4hda70bf1q4q3pj2ids8.ls error="server returned 404: 404 page not found\n"18992026/10/10 19:01:18 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"19002026/10/10 19:01:18 INFO Signed narinfos id=1 count=319012026/10/10 19:01:18 INFO Uploading 3 narinfos19022026/10/10 19:01:18 WARN Force mode enabled - objects will be deleted immediately without grace period19032026/10/10 19:01:18 WARN Failed to register uploaded object key=8qq7r57ppfwdbfia29l76sm8fcfqxdf6.narinfo error="server returned 404: 404 page not found\n"19042026/10/10 19:01:18 WARN Failed to register uploaded object key=mz4khlh6c3ix4hda70bf1q4q3pj2ids8.narinfo error="server returned 404: 404 page not found\n"19052026/10/10 19:01:18 INFO Received complete push request method=POST path=/api/pushes/1/complete19062026/10/10 19:01:18 WARN Failed to register uploaded object key=rgh5m35jpzwgs3vm3hf8dqksszaq2xfg.narinfo error="server returned 404: 404 page not found\n"19072026/10/10 19:01:18 INFO Completed push id=1 objects=9 duration=13.972972ms19082026/10/10 19:01:18 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=019092026/10/10 19:01:18 INFO Upload complete. (87ms)1910=== NAME TestClientMultipleUploads1911 client_integration_test.go:369: Uploaded 3 paths in 145.48228ms19122026/10/10 19:01:18 INFO Vacuumed table table=pending_closures1913--- PASS: TestClientMultipleUploads (0.66s)1914=== CONT TestClientErrorHandling/ServerNotAvailable1915--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.22s)1916=== CONT TestClientErrorHandling/InvalidAuthToken19172026/10/10 19:01:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures19182026/10/10 19:01:18 INFO Garbage collection started19192026/10/10 19:01:18 INFO Received push request method=POST path=/api/pushes19202026/10/10 19:01:18 INFO Vacuumed table table=pending_objects19212026/10/10 19:01:18 INFO Vacuumed table table=multipart_uploads1922--- PASS: TestPushWaitsForSweepHoldingRow (0.91s)1923=== CONT TestCacheConfigHandler/full_config,_no_issuer1924=== CONT TestCacheConfigHandler/no_signing_keys1925=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1926=== CONT TestCacheConfigHandler/no_cache_url_configured1927--- PASS: TestCacheConfigHandler (0.00s)1928 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1929 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1930 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1931 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1932=== CONT TestService_RequireScope_OIDC/builder_may_write19332026/10/10 19:01:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19342026/10/10 19:01:18 INFO Uploading xdvi3y6kf73lllaldz5ls2nd93hdvzgm-ca-test (144B)1935=== CONT TestService_RequireScope_OIDC/reader_may_read1936=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1937=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19382026/10/10 19:01:18 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]1939=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1940=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1941=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read19422026/10/10 19:01:18 INFO Aborted multipart uploads count=0 kept=01943=== CONT TestService_RequireScope_OIDC/writer_implies_read19442026/10/10 19:01:18 INFO Vacuumed table table=closures1945=== CONT TestService_RequireScope_OIDC/reader_may_not_write1946=== CONT TestService_RequireScope_OIDC/static_token_may_write1947=== CONT TestService_RequireScope_OIDC/static_token_may_admin1948=== CONT TestService_RequireScope_OIDC/ops_may_admin1949=== CONT TestService_RequireScope_OIDC/ops_may_not_write1950=== CONT TestService_RequireScope_OIDC/builder_may_not_admin19512026/10/10 19:01:18 WARN Failed to register uploaded object key=log/xps4lkm38kyfx4dfyr7r42fdrr6jc09r-ca-test.drv error="server returned 404: 404 page not found\n"1952=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token19532026/10/10 19:01:18 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"1954--- PASS: TestService_RequireScope_OIDC (0.44s)1955 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1956 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1957 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1958 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1959 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1960 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1961 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1962 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1963 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1964 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1965 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1966 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1967 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1968 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)19692026/10/10 19:01:18 WARN Failed to register uploaded object key=xdvi3y6kf73lllaldz5ls2nd93hdvzgm.ls error="server returned 404: 404 page not found\n"19702026/10/10 19:01:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19712026/10/10 19:01:18 INFO Vacuumed table table=objects1972=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19732026/10/10 19:01:18 INFO Signed narinfos id=1 count=119742026/10/10 19:01:18 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]19752026/10/10 19:01:18 INFO Uploading 1 narinfos1976=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1977=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19782026/10/10 19:01:18 INFO Received uploads request method=POST path=/api/pending_closures19792026/10/10 19:01:18 WARN Authentication failed token_preview=eyJhbGciOi...xrnPS8rZPg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1980--- PASS: TestService_AuthMiddleware_OIDC (0.29s)1981 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1982 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1983 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1984 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)19852026/10/10 19:01:18 WARN Force mode enabled - objects will be deleted immediately without grace period19862026/10/10 19:01:18 INFO Received complete push request method=POST path=/api/pushes/1/complete19872026/10/10 19:01:18 WARN Failed to register uploaded object key=xdvi3y6kf73lllaldz5ls2nd93hdvzgm.narinfo error="server returned 404: 404 page not found\n"19882026/10/10 19:01:18 INFO Completed push id=1 objects=4 duration=12.073566ms19892026/10/10 19:01:18 INFO Upload complete. (129ms)19902026/10/10 19:01:18 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=01991=== NAME TestClientCADerivations1992 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations698599980/001/store/xdvi3y6kf73lllaldz5ls2nd93hdvzgm-ca-test1993 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1994 Compression: zstd1995 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1996 NarSize: 1441997 References: 1998 Deriver: /build/TestClientCADerivations698599980/001/store/xps4lkm38kyfx4dfyr7r42fdrr6jc09r-ca-test.drv1999 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2000 client_ca_test.go:185: Checking for realisation files in S3...2001 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2002 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache20032026/10/10 19:01:18 INFO Vacuumed table table=pending_closures20042026/10/10 19:01:18 INFO Vacuumed table table=pending_objects20052026/10/10 19:01:18 INFO Vacuumed table table=multipart_uploads20062026/10/10 19:01:18 INFO Vacuumed table table=closures20072026/10/10 19:01:18 INFO Vacuumed table table=objects20082026/10/10 19:01:18 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/present20092026/10/10 19:01:18 INFO Received uploads request method=POST path=/api/pending_closures20102026/10/10 19:01:18 INFO Aborted multipart uploads count=0 kept=020112026/10/10 19:01:18 WARN Force mode enabled - objects will be deleted immediately without grace period20122026/10/10 19:01:18 INFO Received uploads request method=POST path=/api/pending_closures20132026/10/10 19:01:18 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=020142026/10/10 19:01:18 INFO Vacuumed table table=pending_closures20152026/10/10 19:01:18 INFO Vacuumed table table=pending_objects20162026/10/10 19:01:18 INFO Vacuumed table table=multipart_uploads20172026/10/10 19:01:18 INFO Vacuumed table table=closures20182026/10/10 19:01:18 INFO Vacuumed table table=objects20192026/10/10 19:01:18 INFO Aborted multipart uploads count=0 kept=020202026/10/10 19:01:18 WARN Force mode enabled - objects will be deleted immediately without grace period20212026/10/10 19:01:18 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=020222026/10/10 19:01:18 INFO Vacuumed table table=pending_closures20232026/10/10 19:01:18 INFO Vacuumed table table=pending_objects20242026/10/10 19:01:18 INFO Vacuumed table table=multipart_uploads20252026/10/10 19:01:18 INFO Vacuumed table table=closures20262026/10/10 19:01:18 INFO Vacuumed table table=objects2027--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2028 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.30s)2029 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.32s)20302026/10/10 19:01:18 WARN Request failed, retrying attempt=2 backoff=181.553116ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20312026/10/10 19:01:18 INFO Aborted multipart uploads count=0 kept=020322026/10/10 19:01:18 WARN Force mode enabled - objects will be deleted immediately without grace period20332026/10/10 19:01:18 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:38607/bucket97/?delete=\": context canceled"2034=== NAME TestClientCADerivations2035 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2036 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2037 error: binary cache 's3://bucket83?endpoint=http://localhost:38607®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations698599980/001/store'2038 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 120392026/10/10 19:01:18 INFO Aborted multipart uploads count=0 kept=020402026/10/10 19:01:18 WARN Force mode enabled - objects will be deleted immediately without grace period2041--- PASS: TestClientCADerivations (0.85s)2042--- PASS: TestGCEndsOnShutdown (0.00s)2043 --- PASS: TestGCEndsOnShutdown/before_the_run (0.28s)2044 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.30s)2045 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.33s)20462026/10/10 19:01:18 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2047=== NAME TestOrphanedObjectsGCStressTest2048 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains20492026/10/10 19:01:18 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20502026/10/10 19:01:18 WARN Request failed, retrying attempt=3 backoff=418.810558ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2051 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion20522026/10/10 19:01:18 INFO lead: released remote=192.0.2.1:12342053--- PASS: TestLeadEndsOnShutdown (1.43s)2054--- PASS: TestUploadHandlersRejectOversizedBody (0.19s)2055 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)2056 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)2057 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.81s)2058--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2059 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.77s)2060 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.79s)2061--- PASS: TestDeleteClosuresRacingPins (1.44s)20622026/10/10 19:01:19 INFO lead: released remote=192.0.2.1:12342063=== NAME TestOrphanedObjectsGCStressTest2064 orphaned_objects_gc_test.go:503: Stress test completed successfully:2065 orphaned_objects_gc_test.go:504: - Active objects preserved: 202066 orphaned_objects_gc_test.go:505: - Objects deleted: 2102067 orphaned_objects_gc_test.go:506: - Total GC'd: 2102068--- PASS: TestOrphanedObjectsGCStressTest (2.46s)20692026/10/10 19:01:19 INFO lead: acquired remote=192.0.2.1:123420702026/10/10 19:01:19 WARN Request failed, retrying attempt=4 backoff=802.241049ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2071--- PASS: TestPendingClosureWriteTimeout (0.09s)2072 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2073 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2074 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2075 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.05s)20762026/10/10 19:01:20 WARN Request failed, retrying attempt=5 backoff=1.493433895s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20772026/10/10 19:01:20 INFO lead: released remote=192.0.2.1:12342078--- PASS: TestLeadElectsOneAndHandsOver (2.72s)20792026/10/10 19:01:20 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020802026/10/10 19:01:20 INFO Received create pin request method=POST path=/api/pins/myapp20812026/10/10 19:01:20 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC967749407/001/store/p9nxabzsfxidd7cly5bw5v90325ciszx-pinned-file.txt narinfo_key=p9nxabzsfxidd7cly5bw5v90325ciszx.narinfo20822026/10/10 19:01:20 INFO Starting cleanup of old closures method=DELETE path=/api/closures20832026/10/10 19:01:20 INFO Garbage collection started20842026/10/10 19:01:20 INFO Aborted multipart uploads count=0 kept=020852026/10/10 19:01:20 WARN Force mode enabled - objects will be deleted immediately without grace period20862026/10/10 19:01:20 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=020872026/10/10 19:01:20 INFO Vacuumed table table=pending_closures20882026/10/10 19:01:20 INFO Vacuumed table table=pending_objects20892026/10/10 19:01:20 INFO Vacuumed table table=multipart_uploads20902026/10/10 19:01:20 INFO Vacuumed table table=closures20912026/10/10 19:01:20 INFO Vacuumed table table=objects20922026/10/10 19:01:20 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02093=== NAME TestClientIntegration2094 client_integration_test.go:323: Objects in database after GC:2095 client_integration_test.go:323: Successfully deleted all objects with GC --force2096--- PASS: TestClientIntegration (2.67s)2097--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.90s)20982026/10/10 19:01:21 WARN Rate limiter enabled after throttle name=s3-test rate=520992026/10/10 19:01:21 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2100=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2101 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102102 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002103--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.57s)21042026/10/10 19:01:21 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-config21052026/10/10 19:01:21 WARN Request failed, retrying attempt=2 backoff=186.488689ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21062026/10/10 19:01:21 WARN Request failed, retrying attempt=3 backoff=380.256304ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21072026/10/10 19:01:22 WARN Request failed, retrying attempt=4 backoff=877.856557ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2108=== NAME TestPinProtectsFromGC2109 client_integration_test.go:840: Pin successfully protected closure from garbage collection2110--- PASS: TestPinProtectsFromGC (4.79s)2111--- PASS: TestConnectWaitsForAPeerMigration (5.20s)21122026/10/10 19:01:23 WARN Request failed, retrying attempt=5 backoff=1.566215043s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21132026/10/10 19:01:23 INFO Aborted multipart uploads count=1 kept=021142026/10/10 19:01:23 INFO Received cleanup request method=DELETE path=/api/pending_closures21152026/10/10 19:01:23 INFO Aborted multipart uploads count=1 kept=02116--- PASS: TestPendingCleanupUsesOneCutoff (6.53s)21172026/10/10 19:01:24 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"21182026/10/10 19:01:24 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-config21192026/10/10 19:01:24 WARN Request failed, retrying attempt=2 backoff=197.664327ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21202026/10/10 19:01:25 WARN Request failed, retrying attempt=3 backoff=437.835475ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21212026/10/10 19:01:25 WARN Request failed, retrying attempt=4 backoff=855.095315ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21222026/10/10 19:01:26 WARN Request failed, retrying attempt=5 backoff=1.724792765s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21232026/10/10 19:01:28 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_closures21242026/10/10 19:01:28 WARN Request failed, retrying attempt=2 backoff=201.353177ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21252026/10/10 19:01:28 WARN Request failed, retrying attempt=3 backoff=378.088634ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21262026/10/10 19:01:28 WARN Request failed, retrying attempt=4 backoff=750.098631ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21272026/10/10 19:01:29 WARN Request failed, retrying attempt=5 backoff=1.70857854s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2128--- PASS: TestClientErrorHandling (0.00s)2129 --- PASS: TestClientErrorHandling/InvalidStorePath (0.33s)2130 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.37s)2131 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.74s)2132PASS21332026-10-10 19:01:31.698 UTC [129] LOG: received smart shutdown request21342026-10-10 19:01:31.703 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 121352026-10-10 19:01:31.716 UTC [134] LOG: shutting down21362026-10-10 19:01:31.718 UTC [134] LOG: checkpoint starting: shutdown immediate21372026-10-10 19:01:32.940 UTC [134] LOG: checkpoint complete: wrote 11058 buffers (67.5%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.273 s, sync=0.891 s, total=1.223 s; sync files=34045, longest=0.008 s, average=0.001 s; distance=531552 kB, estimate=531552 kB; lsn=0/21E7E0A8, redo lsn=0/21E7E0A821382026-10-10 19:01:33.002 UTC [129] LOG: database system is shut down2139Running OIDC tests...2140=== RUN TestAudienceForIssuer2141=== PAUSE TestAudienceForIssuer2142=== RUN TestGlobMatch2143=== PAUSE TestGlobMatch2144=== RUN TestValidateToken_ValidToken2145=== PAUSE TestValidateToken_ValidToken2146=== RUN TestValidateToken_WrongAudience2147=== PAUSE TestValidateToken_WrongAudience2148=== RUN TestValidateToken_Expired2149=== PAUSE TestValidateToken_Expired2150=== RUN TestValidateToken_BoundClaimsMismatch2151=== PAUSE TestValidateToken_BoundClaimsMismatch2152=== RUN TestValidateToken_BoundSubjectMismatch2153=== PAUSE TestValidateToken_BoundSubjectMismatch2154=== RUN TestValidateToken_MultipleProviders2155=== PAUSE TestValidateToken_MultipleProviders2156=== RUN TestValidateToken_NoMatchingProvider2157=== PAUSE TestValidateToken_NoMatchingProvider2158=== RUN TestValidateToken_KubernetesServiceAccount2159=== PAUSE TestValidateToken_KubernetesServiceAccount2160=== RUN TestNewValidator_KubernetesRequiresCA2161=== PAUSE TestNewValidator_KubernetesRequiresCA2162=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2163=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2164=== RUN TestPins_ReservedForMatchingRule2165=== PAUSE TestPins_ReservedForMatchingRule2166=== RUN TestPins_TopLevelShorthand2167=== PAUSE TestPins_TopLevelShorthand2168=== RUN TestPins_ConfigValidation2169=== PAUSE TestPins_ConfigValidation2170=== RUN TestScopes_LegacyProviderDefaultsToWrite2171=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2172=== RUN TestScopes_Rules2173=== PAUSE TestScopes_Rules2174=== RUN TestScopes_ConfigValidation2175=== PAUSE TestScopes_ConfigValidation2176=== CONT TestAudienceForIssuer2177=== CONT TestValidateToken_KubernetesServiceAccount2178--- PASS: TestAudienceForIssuer (0.00s)2179=== CONT TestValidateToken_NoMatchingProvider2180=== CONT TestValidateToken_MultipleProviders2181=== CONT TestValidateToken_BoundSubjectMismatch2182=== CONT TestValidateToken_BoundClaimsMismatch2183=== CONT TestValidateToken_Expired2184=== CONT TestValidateToken_WrongAudience2185=== CONT TestValidateToken_ValidToken2186=== CONT TestGlobMatch2187=== RUN TestGlobMatch/foo_foo2188=== PAUSE TestGlobMatch/foo_foo2189=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2190=== CONT TestPins_TopLevelShorthand2191=== CONT TestNewValidator_KubernetesRequiresCA2192=== CONT TestScopes_Rules2193=== CONT TestScopes_ConfigValidation2194=== CONT TestScopes_LegacyProviderDefaultsToWrite2195=== CONT TestPins_ConfigValidation2196=== CONT TestPins_ReservedForMatchingRule2197=== RUN TestGlobMatch/foo_bar2198=== PAUSE TestGlobMatch/foo_bar2199=== RUN TestGlobMatch/*_2200=== PAUSE TestGlobMatch/*_2201=== RUN TestGlobMatch/*_anything2202=== PAUSE TestGlobMatch/*_anything2203=== RUN TestGlobMatch/foo*_foo2204=== PAUSE TestGlobMatch/foo*_foo2205=== RUN TestGlobMatch/foo*_foobar2206=== PAUSE TestGlobMatch/foo*_foobar2207=== RUN TestGlobMatch/foo*_bar2208=== PAUSE TestGlobMatch/foo*_bar2209=== RUN TestGlobMatch/*bar_bar2210=== PAUSE TestGlobMatch/*bar_bar2211=== RUN TestGlobMatch/*bar_foobar2212=== PAUSE TestGlobMatch/*bar_foobar2213=== RUN TestGlobMatch/*bar_foo2214=== PAUSE TestGlobMatch/*bar_foo2215=== RUN TestGlobMatch/foo*bar_foobar2216=== PAUSE TestGlobMatch/foo*bar_foobar2217=== RUN TestGlobMatch/foo*bar_foo123bar2218=== PAUSE TestGlobMatch/foo*bar_foo123bar2219=== RUN TestGlobMatch/foo*bar_foobarbaz2220=== PAUSE TestGlobMatch/foo*bar_foobarbaz2221=== RUN TestGlobMatch/*/*_foo/bar2222=== PAUSE TestGlobMatch/*/*_foo/bar2223=== RUN TestGlobMatch/*/*_foo2224=== PAUSE TestGlobMatch/*/*_foo2225=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2226=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2227=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02228=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02229=== RUN TestGlobMatch/refs/*/main_refs/heads/main2230=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2231=== RUN TestGlobMatch/fo?_foo2232=== PAUSE TestGlobMatch/fo?_foo2233=== RUN TestGlobMatch/fo?_fo2234=== PAUSE TestGlobMatch/fo?_fo2235=== RUN TestGlobMatch/fo?_fooo2236=== PAUSE TestGlobMatch/fo?_fooo2237=== RUN TestGlobMatch/?oo_foo2238=== PAUSE TestGlobMatch/?oo_foo2239=== RUN TestGlobMatch/?oo_boo2240=== PAUSE TestGlobMatch/?oo_boo2241=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2242=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2243=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2244=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2245=== CONT TestGlobMatch/foo_foo2246=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2247=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2248=== CONT TestGlobMatch/?oo_boo2249=== CONT TestGlobMatch/?oo_foo2250=== CONT TestGlobMatch/fo?_fooo2251=== CONT TestGlobMatch/fo?_fo2252=== CONT TestGlobMatch/fo?_foo2253=== CONT TestGlobMatch/refs/*/main_refs/heads/main2254=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02255=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2256=== CONT TestGlobMatch/*/*_foo2257=== CONT TestGlobMatch/*/*_foo/bar2258=== CONT TestGlobMatch/foo*_bar2259=== CONT TestGlobMatch/foo*_foobar2260=== CONT TestGlobMatch/foo*_foo2261=== CONT TestGlobMatch/*_anything2262=== CONT TestGlobMatch/*_2263=== CONT TestGlobMatch/foo_bar2264=== CONT TestGlobMatch/foo*bar_foobar2265=== CONT TestGlobMatch/foo*bar_foobarbaz2266=== CONT TestGlobMatch/foo*bar_foo123bar2267=== CONT TestGlobMatch/*bar_bar2268=== CONT TestGlobMatch/*bar_foobar2269=== CONT TestGlobMatch/*bar_foo2270--- PASS: TestGlobMatch (0.00s)2271 --- PASS: TestGlobMatch/foo_foo (0.00s)2272 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2273 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2274 --- PASS: TestGlobMatch/?oo_boo (0.00s)2275 --- PASS: TestGlobMatch/?oo_foo (0.00s)2276 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2277 --- PASS: TestGlobMatch/fo?_fo (0.00s)2278 --- PASS: TestGlobMatch/fo?_foo (0.00s)2279 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2280 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2281 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2282 --- PASS: TestGlobMatch/*/*_foo (0.00s)2283 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2284 --- PASS: TestGlobMatch/foo*_bar (0.00s)2285 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2286 --- PASS: TestGlobMatch/foo*_foo (0.00s)2287 --- PASS: TestGlobMatch/*_anything (0.00s)2288 --- PASS: TestGlobMatch/*_ (0.00s)2289 --- PASS: TestGlobMatch/foo_bar (0.00s)2290 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2291 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2292 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2293 --- PASS: TestGlobMatch/*bar_bar (0.00s)2294 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2295 --- PASS: TestGlobMatch/*bar_foo (0.00s)2296--- PASS: TestScopes_ConfigValidation (0.00s)2297--- PASS: TestPins_ConfigValidation (0.00s)22982026/10/10 19:01:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35223/oidc22992026/10/10 19:01:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43277/oidc23002026/10/10 19:01:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42921/oidc2301--- PASS: TestValidateToken_BoundSubjectMismatch (0.04s)2302--- PASS: TestValidateToken_ValidToken (0.04s)2303--- PASS: TestPins_ReservedForMatchingRule (0.03s)23042026/10/10 19:01:36 http: TLS handshake error from 127.0.0.1:35972: remote error: tls: bad certificate2305--- PASS: TestNewValidator_KubernetesRequiresCA (0.04s)23062026/10/10 19:01:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43623/oidc23072026/10/10 19:01:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45373/oidc2308--- PASS: TestValidateToken_WrongAudience (0.04s)23092026/10/10 19:01:36 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:46411/oidc2310--- PASS: TestValidateToken_NoMatchingProvider (0.05s)2311--- PASS: TestScopes_Rules (0.05s)23122026/10/10 19:01:36 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:342112313--- PASS: TestValidateToken_KubernetesServiceAccount (0.06s)23142026/10/10 19:01:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34439/oidc2315--- PASS: TestValidateToken_BoundClaimsMismatch (0.06s)23162026/10/10 19:01:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46053/oidc2317--- PASS: TestPins_TopLevelShorthand (0.06s)23182026/10/10 19:01:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40181/oidc2319--- PASS: TestValidateToken_Expired (0.07s)23202026/10/10 19:01:36 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:37287/oidc23212026/10/10 19:01:36 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:42255/oidc2322--- PASS: TestValidateToken_MultipleProviders (0.09s)23232026/10/10 19:01:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38735/oidc2324--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.09s)23252026/10/10 19:01:36 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232326--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.12s)2327PASS2328Running hook tests...2329=== RUN TestSendPathsEmpty2330=== PAUSE TestSendPathsEmpty2331=== RUN TestQueueEnqueueAndFetch2332=== PAUSE TestQueueEnqueueAndFetch2333=== RUN TestQueueDeduplication2334=== PAUSE TestQueueDeduplication2335=== RUN TestQueueRemove2336=== PAUSE TestQueueRemove2337=== RUN TestQueueFetchBatchLimit2338=== PAUSE TestQueueFetchBatchLimit2339=== RUN TestQueueRetryMovesToBack2340=== PAUSE TestQueueRetryMovesToBack2341=== RUN TestQueueFetchRemoveLifecycle2342=== PAUSE TestQueueFetchRemoveLifecycle2343=== RUN TestQueueConcurrentWriters2344=== PAUSE TestQueueConcurrentWriters2345=== RUN TestQueueRemoveLargeClosure2346=== PAUSE TestQueueRemoveLargeClosure2347=== RUN TestServerClientIntegration2348--- PASS: TestServerClientIntegration (0.00s)2349=== RUN TestServerQueueError23502026/10/10 19:01:36 ERROR Failed to queue paths error="permission denied" count=12351--- PASS: TestServerQueueError (0.00s)2352=== RUN TestGetListenerSocketActivation2353 server_test.go:219: === RUN TestGetListenerSocketActivation2354 --- PASS: TestGetListenerSocketActivation (0.00s)2355 PASS2356 2357--- PASS: TestGetListenerSocketActivation (0.01s)2358=== RUN TestDrainIsolatesPoisonPath2359=== PAUSE TestDrainIsolatesPoisonPath2360=== RUN TestRunNotBlockedByPoisonHead2361=== PAUSE TestRunNotBlockedByPoisonHead2362=== RUN TestDrainGivesUpWhenServerDown2363=== PAUSE TestDrainGivesUpWhenServerDown2364=== RUN TestFailedPathPrunedByLaterClosure2365=== PAUSE TestFailedPathPrunedByLaterClosure2366=== RUN TestWorkerUploadsAndRemoves2367=== PAUSE TestWorkerUploadsAndRemoves2368=== RUN TestWorkerSkipsGCdPaths2369=== PAUSE TestWorkerSkipsGCdPaths2370=== RUN TestWorkerPrunesClosureDeps2371=== PAUSE TestWorkerPrunesClosureDeps2372=== RUN TestDrainTimeout2373=== PAUSE TestDrainTimeout2374=== CONT TestSendPathsEmpty2375=== CONT TestWorkerUploadsAndRemoves2376--- PASS: TestSendPathsEmpty (0.00s)2377=== CONT TestDrainTimeout2378=== CONT TestWorkerPrunesClosureDeps2379=== CONT TestWorkerSkipsGCdPaths2380=== CONT TestDrainIsolatesPoisonPath2381=== CONT TestQueueFetchBatchLimit2382=== CONT TestQueueRemove2383=== CONT TestQueueDeduplication2384=== CONT TestQueueRetryMovesToBack2385=== CONT TestQueueEnqueueAndFetch2386=== CONT TestQueueRemoveLargeClosure2387=== CONT TestQueueConcurrentWriters2388=== CONT TestQueueFetchRemoveLifecycle2389=== CONT TestDrainGivesUpWhenServerDown2390=== CONT TestFailedPathPrunedByLaterClosure2391=== CONT TestRunNotBlockedByPoisonHead23922026/10/10 19:01:36 INFO Uploading batch count=423932026/10/10 19:01:36 ERROR Upload failed error="upload failed" count=423942026/10/10 19:01:36 INFO Upload queue status pending=223952026/10/10 19:01:36 INFO Upload queue status pending=223962026/10/10 19:01:36 INFO Upload queue status pending=22397--- PASS: TestQueueEnqueueAndFetch (0.02s)2398--- PASS: TestQueueFetchBatchLimit (0.02s)23992026/10/10 19:01:36 INFO Uploading batch count=124002026/10/10 19:01:36 ERROR Upload failed error="upload failed" count=124012026/10/10 19:01:36 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2071578480/002/nonexistent24022026/10/10 19:01:36 INFO Uploading batch count=124032026/10/10 19:01:36 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2117998906/002/bbb24042026/10/10 19:01:36 INFO Uploading batch count=22405--- PASS: TestQueueDeduplication (0.02s)24062026/10/10 19:01:36 INFO Uploading batch count=22407--- PASS: TestQueueRetryMovesToBack (0.02s)24082026/10/10 19:01:36 INFO Uploading batch count=224092026/10/10 19:01:36 ERROR Upload failed error="upload failed" count=224102026/10/10 19:01:36 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown79011406/002/a24112026/10/10 19:01:36 INFO Uploading batch count=124122026/10/10 19:01:36 INFO Upload queue status pending=324132026/10/10 19:01:36 INFO Uploading batch count=124142026/10/10 19:01:36 INFO Uploading batch count=12415--- PASS: TestQueueRemove (0.02s)24162026/10/10 19:01:36 ERROR Upload failed error="upload failed" count=124172026/10/10 19:01:36 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown79011406/002/b24182026/10/10 19:01:36 INFO Uploading batch count=124192026/10/10 19:01:36 INFO Uploading batch count=12420--- PASS: TestQueueFetchRemoveLifecycle (0.01s)24212026/10/10 19:01:36 ERROR Upload failed error="upload failed" count=124222026/10/10 19:01:36 INFO Uploading batch count=224232026/10/10 19:01:36 ERROR Upload failed error="upload failed" count=224242026/10/10 19:01:36 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown79011406/002/c24252026/10/10 19:01:36 INFO Uploading batch count=124262026/10/10 19:01:36 ERROR Upload failed error="upload failed" count=124272026/10/10 19:01:36 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown79011406/002/d2428--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)24292026/10/10 19:01:36 INFO Uploading batch count=124302026/10/10 19:01:36 ERROR Upload failed error="upload failed" count=124312026/10/10 19:01:36 INFO Uploading batch count=224322026/10/10 19:01:36 ERROR Upload failed error="upload failed" count=224332026/10/10 19:01:36 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown79011406/002/e24342026/10/10 19:01:36 ERROR Drain finished with paths left in queue remaining=124352026/10/10 19:01:36 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown79011406/002/f24362026/10/10 19:01:36 ERROR Drain finished with paths left in queue remaining=102437--- PASS: TestDrainIsolatesPoisonPath (0.03s)2438--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2439--- PASS: TestWorkerPrunesClosureDeps (0.04s)2440--- PASS: TestWorkerSkipsGCdPaths (0.04s)2441--- PASS: TestWorkerUploadsAndRemoves (0.04s)2442--- PASS: TestQueueRemoveLargeClosure (0.05s)24432026/10/10 19:01:36 ERROR Upload failed error="context deadline exceeded" count=224442026/10/10 19:01:36 ERROR Drain finished with paths left in queue remaining=42445--- PASS: TestDrainTimeout (0.22s)2446--- PASS: TestQueueConcurrentWriters (0.38s)24472026/10/10 19:01:37 INFO Uploading batch count=124482026/10/10 19:01:37 INFO Uploading batch count=124492026/10/10 19:01:37 INFO Uploading batch count=124502026/10/10 19:01:37 ERROR Upload failed error="upload failed" count=124512026/10/10 19:01:37 INFO Uploading batch count=124522026/10/10 19:01:37 ERROR Upload failed error="upload failed" count=124532026/10/10 19:01:37 INFO Uploading batch count=124542026/10/10 19:01:37 ERROR Upload failed error="upload failed" count=124552026/10/10 19:01:37 INFO Uploading batch count=124562026/10/10 19:01:37 ERROR Upload failed error="upload failed" count=124572026/10/10 19:01:37 ERROR Drain finished with paths left in queue remaining=12458--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2459PASS2460Running signing tests...2461=== RUN TestExternalSigner2462=== PAUSE TestExternalSigner2463=== RUN TestExternalSignerWrongPublicKey2464=== PAUSE TestExternalSignerWrongPublicKey2465=== RUN TestExternalSignerErrors2466=== PAUSE TestExternalSignerErrors2467=== RUN TestExternalSignerRestartsAfterCrash2468=== PAUSE TestExternalSignerRestartsAfterCrash2469=== RUN TestExternalSignerProgramErrorKeepsProcess2470=== PAUSE TestExternalSignerProgramErrorKeepsProcess2471=== RUN TestExternalSignerClose2472=== PAUSE TestExternalSignerClose2473=== RUN TestExternalSignerRejectsInvalidPublicKey2474=== PAUSE TestExternalSignerRejectsInvalidPublicKey2475=== RUN TestExternalSignerCancellation2476=== PAUSE TestExternalSignerCancellation2477=== RUN TestGenerateFingerprint2478=== PAUSE TestGenerateFingerprint2479=== RUN TestParseSigningKey2480=== PAUSE TestParseSigningKey2481=== RUN TestSign2482=== PAUSE TestSign2483=== RUN TestSignBatch2484=== PAUSE TestSignBatch2485=== RUN TestNilKeyPublicKey2486=== PAUSE TestNilKeyPublicKey2487=== RUN TestSignErrors2488=== PAUSE TestSignErrors2489=== CONT TestExternalSigner2490=== CONT TestSignBatch2491=== CONT TestExternalSignerCancellation2492=== CONT TestSign2493=== CONT TestParseSigningKey2494=== CONT TestGenerateFingerprint2495=== RUN TestGenerateFingerprint/basic_with_references2496=== CONT TestNilKeyPublicKey2497=== CONT TestExternalSignerProgramErrorKeepsProcess2498=== CONT TestExternalSignerRejectsInvalidPublicKey2499=== CONT TestExternalSignerClose2500=== CONT TestExternalSignerErrors2501=== CONT TestExternalSignerRestartsAfterCrash2502=== CONT TestExternalSignerWrongPublicKey2503=== CONT TestSignErrors2504=== RUN TestParseSigningKey/valid_32-byte_key2505=== RUN TestSignErrors/nil_key2506=== PAUSE TestGenerateFingerprint/basic_with_references2507=== RUN TestExternalSignerRejectsInvalidPublicKey/#002508=== RUN TestGenerateFingerprint/no_references2509=== PAUSE TestGenerateFingerprint/no_references2510=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2511=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2512--- PASS: TestSignBatch (0.00s)2513=== RUN TestExternalSignerErrors/null_signatures2514=== PAUSE TestExternalSignerErrors/null_signatures2515=== PAUSE TestSignErrors/nil_key2516=== RUN TestSignErrors/nil_narinfo2517=== PAUSE TestParseSigningKey/valid_32-byte_key2518=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002519=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2520=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2521=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2522--- PASS: TestNilKeyPublicKey (0.00s)2523--- PASS: TestSign (0.00s)2524=== RUN TestExternalSignerErrors/wrong_signatures_shape2525=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2526=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2527=== PAUSE TestSignErrors/nil_narinfo2528=== RUN TestSignErrors/invalid_narinfo2529=== PAUSE TestSignErrors/invalid_narinfo2530=== RUN TestSignErrors/canceled2531=== PAUSE TestSignErrors/canceled2532=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2533=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2534=== RUN TestParseSigningKey/no_colon2535=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2536=== RUN TestExternalSignerErrors/too_few_signatures2537=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2538=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2539=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2540=== CONT TestSignErrors/nil_key2541=== CONT TestSignErrors/canceled2542=== CONT TestSignErrors/invalid_narinfo2543=== CONT TestSignErrors/nil_narinfo2544--- PASS: TestSignErrors (0.00s)2545 --- PASS: TestSignErrors/nil_key (0.00s)2546 --- PASS: TestSignErrors/canceled (0.00s)2547 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2548 --- PASS: TestSignErrors/nil_narinfo (0.00s)2549=== PAUSE TestParseSigningKey/no_colon2550=== RUN TestParseSigningKey/empty_name2551=== PAUSE TestParseSigningKey/empty_name2552=== RUN TestParseSigningKey/invalid_base642553=== PAUSE TestParseSigningKey/invalid_base642554=== RUN TestParseSigningKey/wrong_length2555=== PAUSE TestParseSigningKey/wrong_length2556=== CONT TestParseSigningKey/valid_32-byte_key2557=== PAUSE TestExternalSignerErrors/too_few_signatures2558=== RUN TestExternalSignerErrors/wrong_signature_length2559=== PAUSE TestExternalSignerErrors/wrong_signature_length2560=== RUN TestExternalSignerErrors/exit_at_startup2561=== CONT TestParseSigningKey/invalid_base642562=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2563=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2564=== RUN TestGenerateFingerprint/invalid_nar_hash_length2565=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2566=== CONT TestParseSigningKey/wrong_length2567=== CONT TestParseSigningKey/no_colon2568=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2569=== CONT TestParseSigningKey/empty_name2570--- PASS: TestParseSigningKey (0.00s)2571 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2572 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2573 --- PASS: TestParseSigningKey/wrong_length (0.00s)2574 --- PASS: TestParseSigningKey/no_colon (0.00s)2575 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2576 --- PASS: TestParseSigningKey/empty_name (0.00s)2577=== PAUSE TestExternalSignerErrors/exit_at_startup2578=== RUN TestExternalSignerErrors/exit_on_request2579=== PAUSE TestExternalSignerErrors/exit_on_request2580=== CONT TestExternalSignerRejectsInvalidPublicKey/#002581=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2582=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2583=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2584=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2585=== RUN TestGenerateFingerprint/invalid_store_path_prefix2586=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2587=== RUN TestExternalSignerErrors/null2588=== PAUSE TestExternalSignerErrors/null2589--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2590 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2591 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2592 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2593 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2594 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2595--- PASS: TestExternalSignerClose (0.00s)2596=== RUN TestGenerateFingerprint/invalid_reference_prefix2597=== RUN TestExternalSignerErrors/missing_signature_name2598=== PAUSE TestExternalSignerErrors/missing_signature_name2599=== RUN TestExternalSignerErrors/wrong_signature_name2600=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2601=== CONT TestGenerateFingerprint/basic_with_references2602=== CONT TestGenerateFingerprint/no_references2603--- PASS: TestExternalSignerWrongPublicKey (0.00s)2604=== PAUSE TestExternalSignerErrors/wrong_signature_name2605=== RUN TestExternalSignerErrors/invalid_signature_base642606=== PAUSE TestExternalSignerErrors/invalid_signature_base642607=== RUN TestExternalSignerErrors/invalid_JSON2608=== PAUSE TestExternalSignerErrors/invalid_JSON2609=== CONT TestGenerateFingerprint/invalid_nar_hash_length2610=== CONT TestGenerateFingerprint/invalid_reference_prefix2611=== CONT TestGenerateFingerprint/invalid_store_path_prefix2612=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2613=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2614--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2615=== RUN TestExternalSignerErrors/unrequested_key2616=== PAUSE TestExternalSignerErrors/unrequested_key2617--- PASS: TestGenerateFingerprint (0.01s)2618 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2619 --- PASS: TestGenerateFingerprint/no_references (0.00s)2620 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2621 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2622 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2623 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2624 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2625=== RUN TestExternalSignerErrors/program_error2626=== PAUSE TestExternalSignerErrors/program_error2627=== RUN TestExternalSignerErrors/wrong_shape2628=== PAUSE TestExternalSignerErrors/wrong_shape2629=== RUN TestExternalSignerErrors/wrong_id2630=== PAUSE TestExternalSignerErrors/wrong_id2631=== RUN TestExternalSignerErrors/missing_signatures2632=== PAUSE TestExternalSignerErrors/missing_signatures2633=== CONT TestExternalSignerErrors/null_signatures2634=== CONT TestExternalSignerErrors/unrequested_key2635=== CONT TestExternalSignerErrors/wrong_signature_name2636--- PASS: TestExternalSigner (0.01s)2637=== CONT TestExternalSignerErrors/missing_signatures2638=== CONT TestExternalSignerErrors/wrong_id2639=== CONT TestExternalSignerErrors/wrong_shape2640=== CONT TestExternalSignerErrors/invalid_signature_base642641=== CONT TestExternalSignerErrors/null2642=== CONT TestExternalSignerErrors/missing_signature_name2643=== CONT TestExternalSignerErrors/wrong_signature_length2644=== CONT TestExternalSignerErrors/exit_on_request2645=== CONT TestExternalSignerErrors/exit_at_startup2646=== CONT TestExternalSignerErrors/too_few_signatures2647=== CONT TestExternalSignerErrors/wrong_signatures_shape2648=== CONT TestExternalSignerErrors/invalid_JSON2649=== CONT TestExternalSignerErrors/program_error2650--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2651--- PASS: TestExternalSignerErrors (0.01s)2652 --- PASS: TestExternalSignerErrors/null_signatures (0.00s)2653 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2654 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)2655 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2656 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2657 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2658 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2659 --- PASS: TestExternalSignerErrors/null (0.01s)2660 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2661 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2662 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2663 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2664 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2665 --- PASS: TestExternalSignerErrors/program_error (0.01s)2666 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2667 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2668--- PASS: TestExternalSignerCancellation (0.02s)2669PASS2670Running OpenBao signer tests...2671=== RUN TestSign2672=== PAUSE TestSign2673=== RUN TestSignErrors2674=== PAUSE TestSignErrors2675=== RUN TestServe2676=== PAUSE TestServe2677=== RUN TestServeRejectsGarbage2678=== PAUSE TestServeRejectsGarbage2679=== CONT TestSign2680=== CONT TestSignErrors2681=== CONT TestServeRejectsGarbage2682=== RUN TestSignErrors/http_error2683=== PAUSE TestSignErrors/http_error2684=== CONT TestServe2685--- PASS: TestServeRejectsGarbage (0.00s)2686=== RUN TestSignErrors/invalid_json2687=== PAUSE TestSignErrors/invalid_json2688=== RUN TestSignErrors/no_prefix2689=== PAUSE TestSignErrors/no_prefix2690=== RUN TestSignErrors/invalid_base642691=== PAUSE TestSignErrors/invalid_base642692=== CONT TestSignErrors/http_error2693=== CONT TestSignErrors/no_prefix2694=== CONT TestSignErrors/invalid_base642695--- PASS: TestServe (0.00s)2696=== CONT TestSignErrors/invalid_json2697--- PASS: TestSign (0.00s)2698--- PASS: TestSignErrors (0.00s)2699 --- PASS: TestSignErrors/invalid_json (0.00s)2700 --- PASS: TestSignErrors/no_prefix (0.00s)2701 --- PASS: TestSignErrors/http_error (0.00s)2702 --- PASS: TestSignErrors/invalid_base64 (0.00s)2703PASS