niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #416
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestUploadMultipart_PartsInParallel18=== PAUSE TestUploadMultipart_PartsInParallel19=== RUN TestPartSizeForNAR20=== PAUSE TestPartSizeForNAR21=== RUN TestUploadMultipart_SupersededByPeer22=== PAUSE TestUploadMultipart_SupersededByPeer23=== RUN TestDumpPathCaseHackMatchesNix24--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)25=== RUN TestDumpPathCaseHackCollision26--- PASS: TestDumpPathCaseHackCollision (0.00s)27=== RUN TestSupersededNARStillUploadsListing28=== PAUSE TestSupersededNARStillUploadsListing29=== RUN TestDumpPathMatchesNix30=== PAUSE TestDumpPathMatchesNix31=== RUN TestDumpPathSingleFile32=== PAUSE TestDumpPathSingleFile33=== RUN TestDumpPathWriterError34=== PAUSE TestDumpPathWriterError35=== RUN TestEncodeNixBase3236=== PAUSE TestEncodeNixBase3237=== RUN TestEncodeNixBase32WithRealHash38=== PAUSE TestEncodeNixBase32WithRealHash39=== RUN TestConvertHashToNix3240=== PAUSE TestConvertHashToNix3241=== RUN TestGetStorePathHash42=== PAUSE TestGetStorePathHash43=== RUN TestPathInfoHashCompatibility44=== PAUSE TestPathInfoHashCompatibility45=== RUN TestParsePathInfoJSON46=== PAUSE TestParsePathInfoJSON47=== RUN TestParsePathInfoJSONMultiplePaths48=== PAUSE TestParsePathInfoJSONMultiplePaths49=== RUN TestPathInfoCACompatibility50=== PAUSE TestPathInfoCACompatibility51=== RUN TestRateLimiterFeedback52=== PAUSE TestRateLimiterFeedback53=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess54=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess55=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer56=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer57=== RUN TestResolveStorePath58=== PAUSE TestResolveStorePath59=== RUN TestDoWithRetry_BodyReplayedViaGetBody60=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody61=== RUN TestRetryTimeoutOutlastsMaxRetries62=== PAUSE TestRetryTimeoutOutlastsMaxRetries63=== RUN TestDoWithRetry_FinalResponseBodyReadable64=== PAUSE TestDoWithRetry_FinalResponseBodyReadable65=== RUN TestShellSplit66=== PAUSE TestShellSplit67=== RUN TestShellSplitErrors68=== PAUSE TestShellSplitErrors69=== RUN TestStreamPushReportsEveryPath70=== PAUSE TestStreamPushReportsEveryPath71=== RUN TestStreamPushBatchesUnderLoad72=== PAUSE TestStreamPushBatchesUnderLoad73=== RUN TestStreamPushIsolatesFailures74=== PAUSE TestStreamPushIsolatesFailures75=== RUN TestStreamPushGivesUpOnDeadServer76=== PAUSE TestStreamPushGivesUpOnDeadServer77=== RUN TestStreamPushRequestLine78=== PAUSE TestStreamPushRequestLine79=== RUN TestStreamPushReportsSignatures80=== PAUSE TestStreamPushReportsSignatures81=== RUN TestStreamPushReportsSkippedPaths82=== PAUSE TestStreamPushReportsSkippedPaths83=== RUN TestClientSignaturesByStorePath84=== PAUSE TestClientSignaturesByStorePath85=== RUN TestStreamPushStopsWhenCanceled86=== PAUSE TestStreamPushStopsWhenCanceled87=== RUN TestSetClientTLS88=== PAUSE TestSetClientTLS89=== RUN TestSetClientTLSDoesNotMutateDefaultTransport90=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport91=== RUN TestSetClientTLSErrors92=== PAUSE TestSetClientTLSErrors93=== RUN TestStaticToken94=== PAUSE TestStaticToken95=== RUN TestFileTokenReadsAndCaches96=== PAUSE TestFileTokenReadsAndCaches97=== RUN TestFileTokenMissing98=== PAUSE TestFileTokenMissing99=== RUN TestFileTokenEmpty100=== PAUSE TestFileTokenEmpty101=== RUN TestScriptTokenNoExpiryRerunsEveryCall102=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall103=== RUN TestScriptTokenCachesUntilRefresh104=== PAUSE TestScriptTokenCachesUntilRefresh105=== RUN TestScriptTokenEmptyToken106=== PAUSE TestScriptTokenEmptyToken107=== RUN TestScriptTokenBadJSON108=== PAUSE TestScriptTokenBadJSON109=== RUN TestScriptTokenScriptFails110=== PAUSE TestScriptTokenScriptFails111=== RUN TestScriptTokenEmptyCommand112=== PAUSE TestScriptTokenEmptyCommand113=== CONT TestDoServerRequestAttachesToken114=== CONT TestFileTokenEmpty115=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess116=== CONT TestFileTokenMissing117=== CONT TestFileTokenReadsAndCaches118=== CONT TestStaticToken1192026/10/14 16:46:32 WARN Rate limiter enabled after throttle name=server-test rate=5120--- PASS: TestStaticToken (0.00s)121=== CONT TestRetryTimeoutOutlastsMaxRetries122--- PASS: TestFileTokenMissing (0.00s)123=== CONT TestDoWithRetry_BodyReplayedViaGetBody124=== CONT TestSetClientTLSErrors125--- PASS: TestFileTokenEmpty (0.00s)126=== CONT TestStreamPushBatchesUnderLoad127=== CONT TestSetClientTLSDoesNotMutateDefaultTransport128=== CONT TestSetClientTLS129=== CONT TestDumpPathSingleFile130=== CONT TestStreamPushStopsWhenCanceled131=== CONT TestGetStorePathHash132=== CONT TestClientSignaturesByStorePath133=== CONT TestConvertHashToNix32134=== CONT TestStreamPushReportsSkippedPaths135=== CONT TestEncodeNixBase32WithRealHash136=== CONT TestStreamPushReportsSignatures137=== CONT TestEncodeNixBase32138=== CONT TestStreamPushRequestLine139=== CONT TestDumpPathWriterError140=== CONT TestStreamPushGivesUpOnDeadServer141=== CONT TestShellSplit142=== CONT TestDoWithRetry_FinalResponseBodyReadable143=== CONT TestShellSplitErrors144=== CONT TestFilterOversizedClosures1452026/10/14 16:46:32 ERROR Upload failed error="connection refused" count=201462026/10/14 16:46:32 ERROR Server seems unavailable, giving up on batch untried=17147=== CONT TestStreamPushIsolatesFailures148=== RUN TestGetStorePathHash/valid_store_path149=== PAUSE TestGetStorePathHash/valid_store_path150--- PASS: TestStreamPushStopsWhenCanceled (0.00s)151=== CONT TestResolveStorePath152=== CONT TestStreamPushReportsEveryPath153=== RUN TestConvertHashToNix32/SRI_format_to_Nix32154=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer155=== CONT TestDumpPathMatchesNix1562026/10/14 16:46:32 ERROR Upload failed error="bad path" count=3157--- PASS: TestClientSignaturesByStorePath (0.00s)158--- PASS: TestFileTokenReadsAndCaches (0.00s)159--- PASS: TestShellSplit (0.00s)160--- PASS: TestShellSplitErrors (0.00s)161--- PASS: TestDoServerRequestAttachesToken (0.00s)162=== CONT TestPathInfoCACompatibility163=== RUN TestPathInfoCACompatibility/null_ca_field164=== PAUSE TestPathInfoCACompatibility/null_ca_field165=== RUN TestPathInfoCACompatibility/old_string_format_-_text166=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text167--- PASS: TestStreamPushReportsSkippedPaths (0.00s)168--- PASS: TestEncodeNixBase32WithRealHash (0.00s)169=== RUN TestGetStorePathHash/basename_without_hyphen_should_error1702026/10/14 16:46:32 ERROR Upload failed error=boom count=11712026/10/14 16:46:32 WARN Rate limiter enabled after throttle name=server-test rate=51722026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:37963173=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32174=== RUN TestConvertHashToNix32/already_Nix32_format175=== RUN TestEncodeNixBase32/test_string_hash1762026/10/14 16:46:32 ERROR Upload failed error=boom count=1177=== PAUSE TestEncodeNixBase32/test_string_hash178=== PAUSE TestConvertHashToNix32/already_Nix32_format179=== RUN TestConvertHashToNix32/invalid_format180=== CONT TestRateLimiterFeedback181=== RUN TestRateLimiterFeedback/429_enables_limiter182=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive1832026/10/14 16:46:32 WARN Rate limiter enabled after throttle name=server-test rate=5184=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive185--- PASS: TestStreamPushIsolatesFailures (0.00s)186=== CONT TestSupersededNARStillUploadsListing1872026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:37023188=== CONT TestPartSizeForNAR189=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error190=== RUN TestSetClientTLSErrors/missing_cert_file191=== RUN TestFilterOversizedClosures/no_limit_keeps_everything192=== CONT TestUploadMultipart_PartsInParallel193=== RUN TestPartSizeForNAR/zero_stays_at_minimum194=== RUN TestSupersededNARStillUploadsListing/small_NAR1952026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:32957196=== RUN TestEncodeNixBase32/empty_input197=== CONT TestParsePathInfoJSONMultiplePaths198=== PAUSE TestConvertHashToNix32/invalid_format199=== PAUSE TestRateLimiterFeedback/429_enables_limiter200--- PASS: TestStreamPushReportsSignatures (0.00s)201--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)202--- PASS: TestStreamPushReportsEveryPath (0.00s)203--- PASS: TestResolveStorePath (0.00s)204--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)205=== RUN TestPathInfoCACompatibility/new_structured_format_-_text206=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum207=== PAUSE TestSupersededNARStillUploadsListing/small_NAR208=== CONT TestUploadMultipart_SupersededByPeer209=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything2102026/10/14 16:46:32 WARN Rate limiter backed off name=server-test rate=5211=== CONT TestParsePathInfoJSON212=== RUN TestParsePathInfoJSON/Nix_format213=== PAUSE TestEncodeNixBase32/empty_input214=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error215=== CONT TestCaseHackSuffix216=== RUN TestSetClientTLS/rejects_connection_without_client_cert2172026/10/14 16:46:32 WARN Rate limiter backed off name=server-test rate=5218=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths2192026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:37023220=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert221=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths222=== RUN TestRateLimiterFeedback/503_enables_limiter2232026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:32957224=== PAUSE TestSetClientTLSErrors/missing_cert_file225=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text226=== RUN TestPartSizeForNAR/small_stays_at_minimum227=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry228=== PAUSE TestPartSizeForNAR/small_stays_at_minimum229=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica230=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum231=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum232=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts233=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts234=== RUN TestPartSizeForNAR/1_TiB235=== RUN TestSupersededNARStillUploadsListing/dump_cut_short236=== RUN TestUploadMultipart_SupersededByPeer/exists237=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped238--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.01s)239=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error2402026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:32957241=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun242=== PAUSE TestParsePathInfoJSON/Nix_format243=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA244=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths245=== PAUSE TestRateLimiterFeedback/503_enables_limiter246=== RUN TestSetClientTLSErrors/missing_key_file247=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA248=== PAUSE TestSetClientTLSErrors/missing_key_file249=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method250=== PAUSE TestPartSizeForNAR/1_TiB251=== PAUSE TestUploadMultipart_SupersededByPeer/exists252=== RUN TestPartSizeForNAR/5_TiB_S3_max_object253=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object254=== RUN TestPartSizeForNAR/capped_at_5_GiB255=== RUN TestUploadMultipart_SupersededByPeer/missing256=== PAUSE TestUploadMultipart_SupersededByPeer/missing257=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped258=== RUN TestFilterOversizedClosures/all_closures_skipped259=== PAUSE TestFilterOversizedClosures/all_closures_skipped260=== CONT TestScriptTokenBadJSON261--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)262--- PASS: TestDumpPathSingleFile (0.03s)263=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error2642026/10/14 16:46:32 INFO Garbage collection started265=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error2662026/10/14 16:46:32 INFO Garbage collection started267=== CONT TestRegisterUploadedObjectReusesConnections268=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths269=== RUN TestParsePathInfoJSON/Lix_format270=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter271=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter272=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter273=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter274=== RUN TestSetClientTLS/preserves_debug_logging_transport275=== PAUSE TestSetClientTLS/preserves_debug_logging_transport276=== RUN TestSetClientTLSErrors/missing_ca_file277=== PAUSE TestSetClientTLSErrors/missing_ca_file278=== RUN TestSetClientTLSErrors/invalid_ca_file279=== PAUSE TestSetClientTLSErrors/invalid_ca_file280=== CONT TestScriptTokenEmptyToken2812026/10/14 16:46:32 WARN Rate limiter enabled after throttle name=s3-test rate=52822026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:426732832026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:32957284=== CONT TestPathInfoHashCompatibility2852026/10/14 16:46:32 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=0286=== CONT TestConvertHashToNix32/invalid_format287=== CONT TestConvertHashToNix32/already_Nix32_format288=== CONT TestEncodeNixBase32/test_string_hash289=== CONT TestEncodeNixBase32/empty_input290=== CONT TestUploadMultipart_SupersededByPeer/exists291--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)292--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.00s)293=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)294=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)295=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon296=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon297=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI298--- PASS: TestScriptTokenBadJSON (0.00s)299=== CONT TestUploadMultipart_SupersededByPeer/missing3002026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:32957301=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI302=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512303=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512304=== PAUSE TestPartSizeForNAR/capped_at_5_GiB305=== CONT TestFilterOversizedClosures/no_limit_keeps_everything306=== CONT TestScriptTokenEmptyCommand307--- PASS: TestScriptTokenEmptyCommand (0.00s)308=== CONT TestGetStorePathHash/valid_store_path309=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3102026/10/14 16:46:32 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=2000311=== CONT TestFilterOversizedClosures/all_closures_skipped3122026/10/14 16:46:32 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50313--- PASS: TestEncodeNixBase32 (0.00s)314 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)315 --- PASS: TestEncodeNixBase32/empty_input (0.00s)316--- PASS: TestFilterOversizedClosures (0.04s)317 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)318 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)319 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)320=== CONT TestGetStorePathHash/basename_without_hyphen_should_error321=== CONT TestScriptTokenCachesUntilRefresh322--- PASS: TestScriptTokenEmptyToken (0.00s)323=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths324=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths325=== CONT TestRateLimiterFeedback/429_enables_limiter326--- PASS: TestParsePathInfoJSONMultiplePaths (0.03s)327 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)328 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)329=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter3302026/10/14 16:46:32 WARN Garbage collection finished on another replica. Its statistics are not available here331=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter332--- PASS: TestUploadMultipart_SupersededByPeer (0.03s)333 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)334 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)335--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)336=== CONT TestSetClientTLS/rejects_connection_without_client_cert337=== CONT TestScriptTokenNoExpiryRerunsEveryCall338=== CONT TestConvertHashToNix32/SRI_format_to_Nix323392026/10/14 16:46:32 WARN Rate limiter enabled after throttle name=server-test rate=5340--- PASS: TestConvertHashToNix32 (0.00s)341 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)342 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)343 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)344=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short3452026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:36259346=== CONT TestScriptTokenScriptFails347=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error348=== CONT TestSetClientTLS/preserves_debug_logging_transport349=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails350=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails3512026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:32957352=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA3532026/10/14 16:46:32 WARN Rate limiter backed off name=server-test rate=5354=== CONT TestSetClientTLSErrors/missing_ca_file355=== PAUSE TestParsePathInfoJSON/Lix_format356=== RUN TestParsePathInfoJSON/empty_input357=== PAUSE TestParsePathInfoJSON/empty_input358=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error359=== CONT TestSetClientTLSErrors/missing_cert_file360=== CONT TestRateLimiterFeedback/503_enables_limiter361=== CONT TestSetClientTLSErrors/invalid_ca_file362=== CONT TestSetClientTLSErrors/missing_key_file363=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)364=== CONT TestPartSizeForNAR/zero_stays_at_minimum365=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512366=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum367=== CONT TestPartSizeForNAR/5_TiB_S3_max_object368=== CONT TestPartSizeForNAR/1_TiB369=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts370=== CONT TestPartSizeForNAR/small_stays_at_minimum371=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails372=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method3732026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:32957374=== CONT TestSupersededNARStillUploadsListing/small_NAR3752026/10/14 16:46:32 WARN Rate limiter enabled after throttle name=server-test rate=53762026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:41463377=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon378=== CONT TestPathInfoCACompatibility/null_ca_field3792026/10/14 16:46:32 INFO Uploading abc-hello (1.0GB)3802026/10/14 16:46:32 WARN Rate limiter backed off name=server-test rate=5381=== CONT TestPathInfoCACompatibility/new_structured_format_-_text382=== CONT TestSupersededNARStillUploadsListing/dump_cut_short383=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method384=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive385=== CONT TestPathInfoCACompatibility/old_string_format_-_text386=== RUN TestParsePathInfoJSON/whitespace_only3872026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:32957388=== PAUSE TestParsePathInfoJSON/whitespace_only389=== RUN TestParsePathInfoJSON/invalid_JSON390=== PAUSE TestParsePathInfoJSON/invalid_JSON391=== CONT TestParsePathInfoJSON/Nix_format392=== CONT TestPartSizeForNAR/capped_at_5_GiB393--- PASS: TestGetStorePathHash (0.04s)394 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)395 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)396 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)397 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)398=== CONT TestParsePathInfoJSON/Lix_format399=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI400=== CONT TestParsePathInfoJSON/whitespace_only401=== CONT TestParsePathInfoJSON/invalid_JSON402--- PASS: TestRateLimiterFeedback (0.03s)403 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)404 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)405 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)406 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)407--- PASS: TestScriptTokenScriptFails (0.01s)408=== CONT TestParsePathInfoJSON/empty_input409--- PASS: TestParsePathInfoJSON (0.04s)410 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)411 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)412 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)413 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)414 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)415--- PASS: TestPathInfoCACompatibility (0.04s)416 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)417 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)418 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)419 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)420 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)421--- PASS: TestPartSizeForNAR (0.03s)422 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)423 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)424 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)425 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)426 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)427 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)428 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)4292026/10/14 16:46:32 INFO Uploading abc-hello (1.0GB)430--- PASS: TestPathInfoHashCompatibility (0.00s)431 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)432 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)433 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)434 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)435--- PASS: TestSetClientTLSErrors (0.04s)436 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)437 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)438 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)439 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)440--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.27s)441--- PASS: TestScriptTokenCachesUntilRefresh (0.27s)442--- PASS: TestCaseHackSuffix (0.30s)4432026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:329574442026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:329574452026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:329574462026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:329574472026/10/14 16:46:32 http: TLS handshake error from 127.0.0.1:51374: remote error: tls: bad certificate4482026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:32957449--- PASS: TestSetClientTLS (0.04s)450 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.27s)451 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.27s)452 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.27s)4532026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:329574542026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:329574552026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:329574562026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:32957457--- PASS: TestRegisterUploadedObjectReusesConnections (0.28s)4582026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:32957459--- PASS: TestStreamPushRequestLine (0.32s)4602026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:32957461--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.32s)462--- PASS: TestDumpPathWriterError (0.33s)4632026/10/14 16:46:32 INFO Uploading abc-hello (1.0GB)464--- PASS: TestStreamPushBatchesUnderLoad (0.36s)4652026/10/14 16:46:32 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:39183/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:39183/part/24662026/10/14 16:46:32 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"467--- PASS: TestDumpPathMatchesNix (0.37s)468--- PASS: TestSupersededNARStillUploadsListing (0.04s)469 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.27s)470 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.27s)471 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.81s)472--- PASS: TestUploadMultipart_PartsInParallel (0.88s)473--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)4742026/10/14 16:46:33 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:35151/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:35151/api/uploads/complete4752026/10/14 16:46:33 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:35151/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:35151/api/uploads/complete4762026/10/14 16:46:33 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4772026/10/14 16:46:33 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:35151/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:35151/api/uploads/complete4782026/10/14 16:46:33 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4792026/10/14 16:46:33 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"480--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)481PASS482Running server tests...483The files belonging to this database system will be owned by user "nixbld".484This user must also own the server process.485486The database cluster will be initialized with locale "C".487The default database encoding has accordingly been set to "SQL_ASCII".488The default text search configuration will be set to "english".489490Data page checksums are enabled.491492creating directory /build/postgres186354898/data ... ok493creating subdirectories ... ok494selecting dynamic shared memory implementation ... posix495selecting default "max_connections" ... 100496selecting default "shared_buffers" ... 128MB497selecting default time zone ... UTC498creating configuration files ... ok499running bootstrap script ... ok500performing post-bootstrap initialization ... ok501syncing data to disk ... ok502503initdb: warning: enabling "trust" authentication for local connections504initdb: 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.505506Success. You can now start the database server using:507508 pg_ctl -D /build/postgres186354898/data -l logfile start509510/build/postgres186354898:5432 - no response5112026-10-14 16:46:34.203 UTC [128] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit5122026-10-14 16:46:34.204 UTC [128] LOG: listening on Unix socket "/build/postgres186354898/.s.PGSQL.5432"5132026-10-14 16:46:34.207 UTC [135] LOG: database system was shut down at 2026-10-14 16:46:34 UTC5142026-10-14 16:46:34.211 UTC [128] LOG: database system is ready to accept connections515/build/postgres186354898:5432 - accepting connections516=== RUN TestService_AuthMiddleware517=== PAUSE TestService_AuthMiddleware518=== RUN TestService_AuthMiddleware_MTLSProxyHeader519=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader520=== RUN TestService_AuthMiddleware_MTLSBoundSubjects521=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects522=== RUN TestService_ReadAuthMiddleware523=== PAUSE TestService_ReadAuthMiddleware524=== RUN TestService_AuthMiddleware_OIDC525=== PAUSE TestService_AuthMiddleware_OIDC526=== RUN TestService_RequireScope_OIDC527=== PAUSE TestService_RequireScope_OIDC528=== RUN TestService_ReadScope_PublicByDefault529=== PAUSE TestService_ReadScope_PublicByDefault530=== RUN TestCacheConfigHandler531=== PAUSE TestCacheConfigHandler532=== RUN TestCacheStatsHandler533=== PAUSE TestCacheStatsHandler534=== RUN TestClientCADerivations535=== PAUSE TestClientCADerivations536=== RUN TestClientErrorHandling537=== PAUSE TestClientErrorHandling538=== RUN TestClientIntegration539=== PAUSE TestClientIntegration540=== RUN TestClientMultipleUploads541=== PAUSE TestClientMultipleUploads542=== RUN TestClientWithDependencies543=== PAUSE TestClientWithDependencies544=== RUN TestClientSharedPathCommittedMidPush545=== PAUSE TestClientSharedPathCommittedMidPush546=== RUN TestPinProtectsFromGC547=== PAUSE TestPinProtectsFromGC548=== RUN TestClientPushesUseOnePush549=== PAUSE TestClientPushesUseOnePush550=== RUN TestClientFallsBackToClosures551=== PAUSE TestClientFallsBackToClosures552=== RUN TestDeleteClosuresRacingPins553=== PAUSE TestDeleteClosuresRacingPins554=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock555=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock556=== RUN TestResolveDBConnectionString557=== PAUSE TestResolveDBConnectionString558=== RUN TestConnectWaitsForAPeerMigration559=== PAUSE TestConnectWaitsForAPeerMigration560=== RUN TestLeadElectsOneAndHandsOver561=== PAUSE TestLeadElectsOneAndHandsOver562=== RUN TestLeadIncumbentWinsAfterRestart5632026/10/14 16:46:34 INFO lead: acquired remote=192.0.2.1:12345642026/10/14 16:46:35 INFO lead: released remote=192.0.2.1:12345652026/10/14 16:46:35 INFO lead: acquired remote=192.0.2.1:12345662026/10/14 16:46:36 INFO lead: released remote=192.0.2.1:1234567--- PASS: TestLeadIncumbentWinsAfterRestart (1.82s)568=== RUN TestLeadIncumbentAnnouncesAtOnce569=== PAUSE TestLeadIncumbentAnnouncesAtOnce570=== RUN TestLeadEndsOnShutdown571=== PAUSE TestLeadEndsOnShutdown572=== RUN TestLeadEndsWhenItsConnectionHangs5732026/10/14 16:46:36 INFO lead: acquired remote=192.0.2.1:12345742026-10-14 16:46:37.735 UTC [380] FATAL: terminating connection due to administrator command5752026/10/14 16:46:37 INFO lead: acquired remote=192.0.2.1:12345762026/10/14 16:46:38 WARN lead: lock connection lost error="timeout: context deadline exceeded"5772026/10/14 16:46:38 INFO lead: released remote=192.0.2.1:12345782026/10/14 16:46:39 INFO lead: released remote=192.0.2.1:1234579--- PASS: TestLeadEndsWhenItsConnectionHangs (3.11s)580=== RUN TestGCAdvisoryLockBlocksConcurrentRun581=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun582=== RUN TestGCBugBareHashReferences583=== PAUSE TestGCBugBareHashReferences584=== RUN TestGCMetrics585=== PAUSE TestGCMetrics586=== RUN TestPushDedupSurvivesConcurrentGC587=== PAUSE TestPushDedupSurvivesConcurrentGC588=== RUN TestDeduplicatedObjectsRecordedAsPending589=== PAUSE TestDeduplicatedObjectsRecordedAsPending590=== RUN TestGCSweepSkipsPendingObjects591=== PAUSE TestGCSweepSkipsPendingObjects592=== RUN TestTombstonedObjectOfferedWithoutWaiting593=== PAUSE TestTombstonedObjectOfferedWithoutWaiting594=== RUN TestGCSweepDeliversEachKeyOnce595=== PAUSE TestGCSweepDeliversEachKeyOnce596=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection597=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection598=== RUN TestForceGCDuringPushOffersSweptObject599=== PAUSE TestForceGCDuringPushOffersSweptObject600=== RUN TestFailedS3DeleteKeepsTombstone601=== PAUSE TestFailedS3DeleteKeepsTombstone602=== RUN TestSweepSkipsRowsLockedByPush603=== PAUSE TestSweepSkipsRowsLockedByPush604=== RUN TestRegisterCompletedObjectNeedsPendingRow605=== PAUSE TestRegisterCompletedObjectNeedsPendingRow606=== RUN TestGetExistingObjectsLocksRows607=== PAUSE TestGetExistingObjectsLocksRows608=== RUN TestSweepRechecksPendingAfterLocking609=== PAUSE TestSweepRechecksPendingAfterLocking610=== RUN TestPushWaitsForSweepHoldingRow611=== PAUSE TestPushWaitsForSweepHoldingRow612=== RUN TestCommitRacingPendingCleanupKeepsObjects613=== PAUSE TestCommitRacingPendingCleanupKeepsObjects614=== RUN TestGCEndsOnShutdown615=== PAUSE TestGCEndsOnShutdown616=== RUN TestGCTaskStore_StartNew617=== PAUSE TestGCTaskStore_StartNew618=== RUN TestGCTaskStore_DeduplicateSameParams619=== PAUSE TestGCTaskStore_DeduplicateSameParams620=== RUN TestGCTaskStore_ConflictDifferentParams621=== PAUSE TestGCTaskStore_ConflictDifferentParams622=== RUN TestGCTaskStore_GetEmpty623=== PAUSE TestGCTaskStore_GetEmpty624=== RUN TestGCTaskStore_GetReturnsLatest625=== PAUSE TestGCTaskStore_GetReturnsLatest626=== RUN TestGCTaskStore_CompletedAllowsNewTask627=== PAUSE TestGCTaskStore_CompletedAllowsNewTask628=== RUN TestGCTaskStore_PhaseUpdates629=== PAUSE TestGCTaskStore_PhaseUpdates630=== RUN TestGCTaskStore_Fail631=== PAUSE TestGCTaskStore_Fail632=== RUN TestGracefulShutdownDrainsInflight633=== PAUSE TestGracefulShutdownDrainsInflight634=== RUN TestService_healthCheckHandler635=== PAUSE TestService_healthCheckHandler636=== RUN TestService_readinessHandler637=== PAUSE TestService_readinessHandler638=== RUN TestGenerateLandingPage639=== PAUSE TestGenerateLandingPage640=== RUN TestCacheConfigHandlerMaxNarSize641=== PAUSE TestCacheConfigHandlerMaxNarSize642=== RUN TestCreatePendingClosureRejectsOversizedNAR643=== PAUSE TestCreatePendingClosureRejectsOversizedNAR644=== RUN TestNARDeduplicationMetadataUploadBug645=== PAUSE TestNARDeduplicationMetadataUploadBug646=== RUN TestMetricsInventory647=== PAUSE TestMetricsInventory648=== RUN TestMetricsCommit649=== PAUSE TestMetricsCommit650=== RUN TestService_NativeMTLS651=== PAUSE TestService_NativeMTLS652=== RUN TestServerTLSConfig653=== PAUSE TestServerTLSConfig654=== RUN TestMultipartCleanup655=== PAUSE TestMultipartCleanup656=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded657=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded658=== RUN TestPendingCleanupUsesOneCutoff659=== PAUSE TestPendingCleanupUsesOneCutoff660=== RUN TestObjectStatsTrigger661=== PAUSE TestObjectStatsTrigger662=== RUN TestObjectStatsLargeCommit663=== PAUSE TestObjectStatsLargeCommit664=== RUN TestOrphanedObjectsGC665=== PAUSE TestOrphanedObjectsGC666=== RUN TestOrphanedObjectsGCStressTest667=== PAUSE TestOrphanedObjectsGCStressTest668=== RUN TestCreatePin_ReservedPins669=== PAUSE TestCreatePin_ReservedPins670=== RUN TestPresentReportsOnlyClosureRoots671=== PAUSE TestPresentReportsOnlyClosureRoots672=== RUN TestPresentRefreshesOnlyStaleClosures673=== PAUSE TestPresentRefreshesOnlyStaleClosures674=== RUN TestPresentNotReportedWhileGCDeletesClosure675=== PAUSE TestPresentNotReportedWhileGCDeletesClosure676=== RUN TestParseSingleRange677=== PAUSE TestParseSingleRange678=== RUN TestProxyHeadersOnlyTrustedOnSocket6792026/10/14 16:46:39 INFO Starting HTTP server address=proxy.sock6802026/10/14 16:46:39 INFO Starting HTTP server address=127.0.0.1:444876812026/10/14 16:46:39 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6822026/10/14 16:46:39 INFO Shutdown signal received, draining in-flight requests timeout=10s683--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.10s)684=== RUN TestIsValidCachePath685=== PAUSE TestIsValidCachePath686=== RUN TestReadProxyNarinfo687=== PAUSE TestReadProxyNarinfo688=== RUN TestReadProxyNarinfoAlreadyDecompressed689=== PAUSE TestReadProxyNarinfoAlreadyDecompressed690=== RUN TestReadProxyContentNegotiation691=== PAUSE TestReadProxyContentNegotiation692=== RUN TestReadProxyNarStreaming693=== PAUSE TestReadProxyNarStreaming694=== RUN TestReadProxy404695=== PAUSE TestReadProxy404696=== RUN TestReadProxyInvalidPath697=== PAUSE TestReadProxyInvalidPath698=== RUN TestReadProxyHead699=== PAUSE TestReadProxyHead700=== RUN TestReadProxyOutlastsServerWriteTimeout701=== PAUSE TestReadProxyOutlastsServerWriteTimeout702=== RUN TestReadProxyConditionalGet703=== PAUSE TestReadProxyConditionalGet704=== RUN TestReadProxyRootRedirectsToIndexHTML705=== PAUSE TestReadProxyRootRedirectsToIndexHTML706=== RUN TestReadProxyDisabled707=== PAUSE TestReadProxyDisabled708=== RUN TestReadRedirectNar709=== PAUSE TestReadRedirectNar710=== RUN TestReadRedirectKeepsNarinfoProxied711=== PAUSE TestReadRedirectKeepsNarinfoProxied712=== RUN TestReadProxyRangeRequest713=== PAUSE TestReadProxyRangeRequest714=== RUN TestReadRedirectUsesPublicS3URL715=== PAUSE TestReadRedirectUsesPublicS3URL716=== RUN TestPush_OverlappingRootsStoreOneRowPerKey717=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey718=== RUN TestPush_CompleteCommitsEveryRoot719=== PAUSE TestPush_CompleteCommitsEveryRoot720=== RUN TestPush_RepeatedRootCommitsOnce721=== PAUSE TestPush_RepeatedRootCommitsOnce722=== RUN TestPush_CompleteWaitsForCleanupOfThePush723=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush724=== RUN TestPush_RootsAreLockedInByteOrder725=== PAUSE TestPush_RootsAreLockedInByteOrder726=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit727=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit728=== RUN TestPush_RejectsBadRequests729=== PAUSE TestPush_RejectsBadRequests730=== RUN TestPush_SignsNarinfosOfItsPendingObjects731=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects732=== RUN TestRedundantMultipartUpload733=== PAUSE TestRedundantMultipartUpload734=== RUN TestCompleteMultipartUpload_ErrorButObjectExists735=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists736=== RUN TestCompletedNarNotReofferedAcrossClosures737=== PAUSE TestCompletedNarNotReofferedAcrossClosures738=== RUN TestPresignedUploadRegisteredBeforeCommit739=== PAUSE TestPresignedUploadRegisteredBeforeCommit740=== RUN TestService_Rustfstest741=== PAUSE TestService_Rustfstest742=== RUN TestParseSize743=== PAUSE TestParseSize744=== RUN TestSkippedUploadsHandler745=== PAUSE TestSkippedUploadsHandler746=== RUN TestSystemdListenerNotActivated747--- PASS: TestSystemdListenerNotActivated (0.00s)748=== RUN TestWatchdogBeatsWhenHealthy749--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)750=== RUN TestWatchdogSkipsWhenUnhealthy7512026/10/14 16:46:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7522026/10/14 16:46:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7532026/10/14 16:46:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7542026/10/14 16:46:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7552026/10/14 16:46:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7562026/10/14 16:46:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7572026/10/14 16:46:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7582026/10/14 16:46:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7592026/10/14 16:46:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7602026/10/14 16:46:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"761--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)762=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle763=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle764=== RUN TestProxyWriteTimeout765=== PAUSE TestProxyWriteTimeout766=== RUN TestPendingClosureWriteTimeout767=== PAUSE TestPendingClosureWriteTimeout768=== RUN TestIsValidUploadKey769=== PAUSE TestIsValidUploadKey770=== RUN TestUploadHandlersRejectInvalidKeys771=== PAUSE TestUploadHandlersRejectInvalidKeys772=== RUN TestUploadHandlersRejectOversizedBody773=== PAUSE TestUploadHandlersRejectOversizedBody774=== RUN TestService_cleanupPendingClosuresHandler775=== PAUSE TestService_cleanupPendingClosuresHandler776=== RUN TestService_createPendingClosureHandler777=== PAUSE TestService_createPendingClosureHandler778=== RUN TestService_verifyS3Integrity779=== PAUSE TestService_verifyS3Integrity780=== RUN TestCompleteMultipartUnregistered781=== PAUSE TestCompleteMultipartUnregistered782=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT783=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT784=== CONT TestProxyWriteTimeout785=== CONT TestSkippedUploadsHandler786=== CONT TestParseSize787--- PASS: TestParseSize (0.00s)788=== RUN TestProxyWriteTimeout/narinfo789=== PAUSE TestProxyWriteTimeout/narinfo790=== CONT TestService_cleanupPendingClosuresHandler791=== RUN TestProxyWriteTimeout/1_GiB_nar792=== PAUSE TestProxyWriteTimeout/1_GiB_nar793=== RUN TestProxyWriteTimeout/10_GiB_nar794=== PAUSE TestProxyWriteTimeout/10_GiB_nar795=== RUN TestProxyWriteTimeout/unknown_size796=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle797=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT7982026/10/14 16:46:39 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000799=== CONT TestCompleteMultipartUnregistered800=== CONT TestService_verifyS3Integrity801=== CONT TestService_createPendingClosureHandler802=== CONT TestUploadHandlersRejectInvalidKeys803=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info804=== CONT TestUploadHandlersRejectOversizedBody805=== CONT TestService_healthCheckHandler806=== CONT TestService_AuthMiddleware807=== CONT TestIsValidUploadKey808=== RUN TestIsValidUploadKey/narinfo809=== CONT TestPendingClosureWriteTimeout810=== CONT TestClientWithDependencies811=== CONT TestGCAdvisoryLockBlocksConcurrentRun812=== CONT TestLeadEndsOnShutdown813=== CONT TestLeadIncumbentAnnouncesAtOnce814=== CONT TestGCBugBareHashReferences815=== CONT TestLeadElectsOneAndHandsOver816=== CONT TestGracefulShutdownDrainsInflight817=== CONT TestConnectWaitsForAPeerMigration818=== CONT TestGCTaskStore_Fail819=== CONT TestResolveDBConnectionString820=== PAUSE TestProxyWriteTimeout/unknown_size821=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info822=== PAUSE TestIsValidUploadKey/narinfo823=== RUN TestIsValidUploadKey/nar_zst824=== PAUSE TestIsValidUploadKey/nar_zst825=== RUN TestIsValidUploadKey/nar_xz826=== RUN TestPendingClosureWriteTimeout/empty827=== PAUSE TestPendingClosureWriteTimeout/empty828=== RUN TestPendingClosureWriteTimeout/400_objects829=== PAUSE TestIsValidUploadKey/nar_xz830=== RUN TestIsValidUploadKey/nar_plain831=== PAUSE TestPendingClosureWriteTimeout/400_objects832=== RUN TestPendingClosureWriteTimeout/670k_objects833=== CONT TestGCTaskStore_PhaseUpdates834=== PAUSE TestPendingClosureWriteTimeout/670k_objects835=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal836=== RUN TestResolveDBConnectionString/flag_wins837=== PAUSE TestIsValidUploadKey/nar_plain838--- PASS: TestGCTaskStore_Fail (0.00s)839--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)840=== RUN TestIsValidUploadKey/listing841=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline842=== CONT TestGCTaskStore_CompletedAllowsNewTask843=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock844--- PASS: TestSkippedUploadsHandler (0.06s)845=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal846=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key847=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key848=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key849=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key850=== CONT TestDeleteClosuresRacingPins8512026/10/14 16:46:39 INFO Starting HTTP server address=127.0.0.1:38475852=== CONT TestPinProtectsFromGC8532026/10/14 16:46:39 INFO Shutdown signal received, draining in-flight requests timeout=10s854=== PAUSE TestIsValidUploadKey/listing855=== RUN TestIsValidUploadKey/build_log856--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)857=== CONT TestGCTaskStore_GetReturnsLatest858--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)859=== CONT TestGCTaskStore_GetEmpty860--- PASS: TestGCTaskStore_GetEmpty (0.00s)861=== CONT TestClientSharedPathCommittedMidPush862=== PAUSE TestIsValidUploadKey/build_log863=== RUN TestIsValidUploadKey/build_log_home-manager_file864=== PAUSE TestResolveDBConnectionString/flag_wins865=== RUN TestResolveDBConnectionString/file_when_flag_empty866=== PAUSE TestResolveDBConnectionString/file_when_flag_empty867=== RUN TestResolveDBConnectionString/missing_file_is_an_error868=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error869=== RUN TestResolveDBConnectionString/PGHOST_allows_empty870=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty871=== RUN TestResolveDBConnectionString/nothing_configured872=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline873=== PAUSE TestIsValidUploadKey/build_log_home-manager_file874=== RUN TestIsValidUploadKey/build_log_plus_in_name875=== PAUSE TestIsValidUploadKey/build_log_plus_in_name876=== RUN TestIsValidUploadKey/build_log_question_mark877=== PAUSE TestIsValidUploadKey/build_log_question_mark878=== PAUSE TestResolveDBConnectionString/nothing_configured879=== CONT TestGCTaskStore_ConflictDifferentParams880--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)881=== CONT TestReadProxyNarStreaming882=== RUN TestIsValidUploadKey/build_log_equals883=== PAUSE TestIsValidUploadKey/build_log_equals884=== RUN TestIsValidUploadKey/realisation885=== PAUSE TestIsValidUploadKey/realisation886=== CONT TestGCTaskStore_DeduplicateSameParams887--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)888=== CONT TestGCTaskStore_StartNew889--- PASS: TestGCTaskStore_StartNew (0.00s)890=== CONT TestService_Rustfstest891=== RUN TestIsValidUploadKey/realisation_plus_in_output892=== PAUSE TestIsValidUploadKey/realisation_plus_in_output893=== RUN TestIsValidUploadKey/nix-cache-info894=== PAUSE TestIsValidUploadKey/nix-cache-info895=== RUN TestIsValidUploadKey/index.html896=== PAUSE TestIsValidUploadKey/index.html897=== RUN TestIsValidUploadKey/narinfo_key,_nar_type898=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type899=== RUN TestIsValidUploadKey/nar_key,_narinfo_type900=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type901=== RUN TestIsValidUploadKey/listing_key,_narinfo_type902=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type903=== RUN TestIsValidUploadKey/traversal904=== PAUSE TestIsValidUploadKey/traversal905=== RUN TestIsValidUploadKey/traversal_nar906=== PAUSE TestIsValidUploadKey/traversal_nar907=== RUN TestIsValidUploadKey/absolute908=== PAUSE TestIsValidUploadKey/absolute909=== RUN TestIsValidUploadKey/empty_key910=== PAUSE TestIsValidUploadKey/empty_key911=== RUN TestIsValidUploadKey/unknown_type912=== PAUSE TestIsValidUploadKey/unknown_type913=== CONT TestGCEndsOnShutdown914=== RUN TestGCEndsOnShutdown/before_the_run915=== PAUSE TestGCEndsOnShutdown/before_the_run916=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete917=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete918=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark919=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark920=== CONT TestPresignedUploadRegisteredBeforeCommit921--- PASS: TestGracefulShutdownDrainsInflight (0.11s)922=== CONT TestCommitRacingPendingCleanupKeepsObjects923=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure924=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure925=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart926=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart927=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts928=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts929=== CONT TestCompletedNarNotReofferedAcrossClosures9302026/10/14 16:46:40 INFO Received uploads request method=POST path=/api/pending_closures931--- PASS: TestService_healthCheckHandler (0.40s)932=== CONT TestClientPushesUseOnePush9332026/10/14 16:46:40 INFO lead: acquired remote=192.0.2.1:12349342026/10/14 16:46:40 INFO Received uploads request method=POST path=/api/pending_closures9352026/10/14 16:46:40 INFO lead: acquired remote=192.0.2.1:12349362026/10/14 16:46:40 INFO lead: released remote=192.0.2.1:1234937--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.46s)938=== CONT TestCompleteMultipartUpload_ErrorButObjectExists9392026/10/14 16:46:40 INFO Received uploads request method=POST path=/api/pending_closures9402026/10/14 16:46:40 INFO Received uploads request method=POST path=/api/pending_closures9412026/10/14 16:46:40 INFO Received uploads request method=POST path=/api/pending_closures9422026/10/14 16:46:40 INFO Received cleanup request method=DELETE path=/api/pending_closures9432026/10/14 16:46:40 INFO Aborted multipart uploads count=0 kept=09442026/10/14 16:46:40 INFO Received uploads request method=POST path=/api/pending_closures945=== NAME TestClientWithDependencies946 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies713611392/001/store/b8rhbrkbcqg0zvaqrby078xi8pzdpsd2-test-script9472026/10/14 16:46:40 INFO Received cleanup request method=DELETE path=/api/pending_closures9482026/10/14 16:46:40 INFO Aborted multipart uploads count=1 kept=09492026/10/14 16:46:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9502026/10/14 16:46:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9512026-10-14 16:46:40.183 UTC [460] ERROR: Closure does not exist: id=19522026-10-14 16:46:40.183 UTC [460] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9532026-10-14 16:46:40.183 UTC [460] STATEMENT: -- name: CommitPendingClosure :one954 SELECT commit_pending_closure($1::bigint)::bigint955 956--- PASS: TestService_cleanupPendingClosuresHandler (0.52s)957=== CONT TestClientFallsBackToClosures9582026/10/14 16:46:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9592026/10/14 16:46:40 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst960--- PASS: TestCompleteMultipartUnregistered (0.52s)961=== CONT TestRedundantMultipartUpload9622026/10/14 16:46:40 INFO Received uploads request method=POST path=/api/pending_closures963=== NAME TestClientWithDependencies964 client_integration_test.go:615: Found 1 dependencies (including self)965--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.55s)966=== CONT TestPushWaitsForSweepHoldingRow9672026/10/14 16:46:40 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"968--- PASS: TestService_AuthMiddleware (0.56s)969=== CONT TestPush_SignsNarinfosOfItsPendingObjects9702026/10/14 16:46:40 INFO lead: acquired remote=192.0.2.1:12349712026/10/14 16:46:40 INFO Received push request method=POST path=/api/pushes9722026/10/14 16:46:40 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9732026/10/14 16:46:40 INFO Uploading b8rhbrkbcqg0zvaqrby078xi8pzdpsd2-test-script (136B)9742026/10/14 16:46:40 WARN Failed to register uploaded object key=b8rhbrkbcqg0zvaqrby078xi8pzdpsd2.ls error="server returned 404: 404 page not found\n"9752026/10/14 16:46:40 WARN Failed to register uploaded object key=log/zk9mc0z0fnsqhhdibzphxfn6ia12qmnd-test-script.drv error="server returned 404: 404 page not found\n"9762026/10/14 16:46:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9772026/10/14 16:46:40 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"9782026/10/14 16:46:40 INFO Signed narinfos id=1 count=19792026/10/14 16:46:40 INFO Uploading 1 narinfos9802026/10/14 16:46:40 INFO Received complete push request method=POST path=/api/pushes/1/complete9812026/10/14 16:46:40 WARN Failed to register uploaded object key=b8rhbrkbcqg0zvaqrby078xi8pzdpsd2.narinfo error="server returned 404: 404 page not found\n"9822026/10/14 16:46:40 INFO Completed push id=1 objects=4 duration=5.510709ms9832026/10/14 16:46:40 INFO Upload complete. (58ms)984=== NAME TestClientWithDependencies985 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies713611392/001/store) requires matching store prefix986--- PASS: TestClientWithDependencies (0.64s)987=== CONT TestReadProxyRangeRequest9882026/10/14 16:46:40 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"989--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.59s)990=== CONT TestSweepRechecksPendingAfterLocking991--- PASS: TestService_Rustfstest (0.60s)992=== CONT TestReadRedirectKeepsNarinfoProxied9932026/10/14 16:46:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9942026/10/14 16:46:40 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZTZjODdlZWUtN2ZmMS00MjcwLWI0MmEtOWE2ODYwY2NmZjBjLmNmMTBiMjNmLWUzNjUtNGMxNS1hNWY2LTRkOWYwNTFlMzRmMngxNzkxOTk2NDAwMDU4MjcxNzE1 parts=109952026/10/14 16:46:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9962026/10/14 16:46:40 INFO Completed upload id=1 objects=2 duration=3.677793ms9972026/10/14 16:46:40 INFO Received uploads request method=POST path=/api/pending_closures9982026/10/14 16:46:40 INFO Received uploads request method=POST path=/api/pending_closures9992026/10/14 16:46:40 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10002026/10/14 16:46:40 WARN Found objects in DB but missing from S3, will re-upload count=11001--- PASS: TestService_verifyS3Integrity (0.72s)1002=== CONT TestPush_RejectsBadRequests10032026/10/14 16:46:40 INFO Received uploads request method=POST path=/api/pending_closures1004=== NAME TestPinProtectsFromGC1005 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC455414320/001/store/s1x484pgnxjk7d85vnw5cq0pvsai7384-pinned-file.txt1006 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC455414320/001/store/mnjwqpsybm03dq4h91gsbd57r7py4la5-unpinned-file.txt10072026/10/14 16:46:40 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10082026/10/14 16:46:40 INFO Received uploads request method=POST path=/api/pending_closures1009--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.71s)1010=== CONT TestGetExistingObjectsLocksRows1011--- PASS: TestReadProxyNarStreaming (0.75s)1012=== CONT TestReadRedirectNar10132026/10/14 16:46:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10142026/10/14 16:46:40 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZTZjODdlZWUtN2ZmMS00MjcwLWI0MmEtOWE2ODYwY2NmZjBjLmI4OThkZDUyLWEwZjktNDE2MC04NTc2LWU4YzFiNDVjYTlmY3gxNzkxOTk2NDAwMTUxNzU4Njg4 parts=1010152026/10/14 16:46:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10162026/10/14 16:46:40 INFO Completed upload id=1 objects=2 duration=3.35577ms10172026/10/14 16:46:40 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010182026/10/14 16:46:40 INFO Received uploads request method=POST path=/api/pending_closures10192026/10/14 16:46:40 INFO Received push request method=POST path=/api/pushes10202026/10/14 16:46:40 INFO Starting cleanup of old closures method=DELETE path=/api/closures10212026/10/14 16:46:40 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10222026/10/14 16:46:40 INFO Uploading s1x484pgnxjk7d85vnw5cq0pvsai7384-pinned-file.txt (128B)10232026/10/14 16:46:40 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"10242026/10/14 16:46:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10252026/10/14 16:46:40 INFO Aborted multipart uploads count=0 kept=010262026/10/14 16:46:40 WARN Failed to register uploaded object key=s1x484pgnxjk7d85vnw5cq0pvsai7384.ls error="server returned 404: 404 page not found\n"10272026/10/14 16:46:40 INFO Signed narinfos id=1 count=110282026/10/14 16:46:40 INFO Uploading 1 narinfos10292026/10/14 16:46:40 INFO Received uploads request method=POST path=/api/pending_closures10302026/10/14 16:46:40 INFO Received complete push request method=POST path=/api/pushes/1/complete10312026/10/14 16:46:40 WARN Failed to register uploaded object key=s1x484pgnxjk7d85vnw5cq0pvsai7384.narinfo error="server returned 404: 404 page not found\n"10322026/10/14 16:46:40 INFO Completed push id=1 objects=3 duration=5.453348ms10332026/10/14 16:46:40 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=010342026/10/14 16:46:40 INFO Upload complete. (58ms)10352026/10/14 16:46:40 INFO Vacuumed table table=pending_closures10362026/10/14 16:46:40 INFO Vacuumed table table=pending_objects10372026/10/14 16:46:40 INFO Aborted multipart uploads count=0 kept=010382026/10/14 16:46:40 INFO Vacuumed table table=multipart_uploads10392026/10/14 16:46:40 INFO Vacuumed table table=closures10402026/10/14 16:46:40 WARN Force mode enabled - objects will be deleted immediately without grace period10412026/10/14 16:46:40 INFO Vacuumed table table=objects10422026/10/14 16:46:40 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=01043--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.82s)1044=== CONT TestRegisterCompletedObjectNeedsPendingRow10452026/10/14 16:46:40 INFO Vacuumed table table=pending_closures10462026/10/14 16:46:40 INFO Vacuumed table table=pending_objects10472026/10/14 16:46:40 INFO Vacuumed table table=multipart_uploads10482026/10/14 16:46:40 INFO Vacuumed table table=closures10492026/10/14 16:46:40 INFO Vacuumed table table=objects10502026/10/14 16:46:40 INFO Received push request method=POST path=/api/pushes10512026/10/14 16:46:40 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001052--- PASS: TestService_createPendingClosureHandler (0.88s)1053=== CONT TestReadProxyDisabled10542026/10/14 16:46:40 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)10552026/10/14 16:46:40 INFO Uploading ny2nh6xx32am6cfazck9ivfrb16lr3iz-shared-dep (136B)10562026/10/14 16:46:40 INFO Uploading y3c5m524mbf4iyl37yqfd6xsy71rskd2-top (224B)10572026/10/14 16:46:40 INFO Received uploads request method=POST path=/api/pending_closures10582026/10/14 16:46:40 WARN Failed to register uploaded object key=y3c5m524mbf4iyl37yqfd6xsy71rskd2.ls error="server returned 404: 404 page not found\n"10592026/10/14 16:46:40 WARN Failed to register uploaded object key=nar/1r6zrg8wn47s1bsyrnymnq2rmh789r0n5x0b5zz99ig86f436gb6.nar.zst error="server returned 404: 404 page not found\n"1060--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.77s)10612026/10/14 16:46:40 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1062=== CONT TestSweepSkipsRowsLockedByPush10632026/10/14 16:46:40 WARN Failed to register uploaded object key=ny2nh6xx32am6cfazck9ivfrb16lr3iz.ls error="server returned 404: 404 page not found\n"10642026/10/14 16:46:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10652026/10/14 16:46:40 INFO Signed narinfos id=1 count=210662026/10/14 16:46:40 INFO Uploading 2 narinfos10672026/10/14 16:46:40 WARN Failed to register uploaded object key=y3c5m524mbf4iyl37yqfd6xsy71rskd2.narinfo error="server returned 404: 404 page not found\n"10682026/10/14 16:46:40 INFO Received complete push request method=POST path=/api/pushes/1/complete10692026/10/14 16:46:40 WARN Failed to register uploaded object key=ny2nh6xx32am6cfazck9ivfrb16lr3iz.narinfo error="server returned 404: 404 page not found\n"10702026/10/14 16:46:40 INFO Completed push id=1 objects=6 duration=6.938742ms10712026/10/14 16:46:40 INFO Upload complete. (67ms)1072=== NAME TestClientSharedPathCommittedMidPush1073 client_integration_test.go:680: Retrieved narinfo from S3:1074 StorePath: /build/TestClientSharedPathCommittedMidPush2250131609/001/store/ny2nh6xx32am6cfazck9ivfrb16lr3iz-shared-dep1075 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1076 Compression: zstd1077 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821078 NarSize: 1361079 References: 1080 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1081 client_integration_test.go:680: Retrieved narinfo from S3:1082 StorePath: /build/TestClientSharedPathCommittedMidPush2250131609/001/store/y3c5m524mbf4iyl37yqfd6xsy71rskd2-top1083 URL: nar/1r6zrg8wn47s1bsyrnymnq2rmh789r0n5x0b5zz99ig86f436gb6.nar.zst1084 Compression: zstd1085 NarHash: sha256:1r6zrg8wn47s1bsyrnymnq2rmh789r0n5x0b5zz99ig86f436gb61086 NarSize: 2241087 References: /build/TestClientSharedPathCommittedMidPush2250131609/001/store/ny2nh6xx32am6cfazck9ivfrb16lr3iz-shared-dep1088 CA: text:sha256:0ycknzzzjhjs6hkmxaxjp6h5p8r44jbblbmm2nacgxfpcbf238db1089--- PASS: TestClientSharedPathCommittedMidPush (0.86s)1090=== CONT TestReadProxyRootRedirectsToIndexHTML10912026/10/14 16:46:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10922026/10/14 16:46:40 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZTZjODdlZWUtN2ZmMS00MjcwLWI0MmEtOWE2ODYwY2NmZjBjLjMyZmRiYzE0LWZjZDQtNDcwMS05OGFlLTk3YjlkNGM0ZjUyNHgxNzkxOTk2NDAwNTU3NTEyNTQ010932026/10/14 16:46:40 INFO Received push request method=POST path=/api/pushes10942026/10/14 16:46:40 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10952026/10/14 16:46:40 INFO Uploading mnjwqpsybm03dq4h91gsbd57r7py4la5-unpinned-file.txt (128B)10962026/10/14 16:46:40 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZTZjODdlZWUtN2ZmMS00MjcwLWI0MmEtOWE2ODYwY2NmZjBjLjMyZmRiYzE0LWZjZDQtNDcwMS05OGFlLTk3YjlkNGM0ZjUyNHgxNzkxOTk2NDAwNTU3NTEyNTQ0 parts=11097--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.47s)1098=== CONT TestFailedS3DeleteKeepsTombstone10992026/10/14 16:46:40 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"11002026/10/14 16:46:40 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11012026/10/14 16:46:40 WARN Failed to register uploaded object key=mnjwqpsybm03dq4h91gsbd57r7py4la5.ls error="server returned 404: 404 page not found\n"11022026/10/14 16:46:40 INFO Signed narinfos id=2 count=111032026/10/14 16:46:40 INFO Uploading 1 narinfos11042026/10/14 16:46:40 INFO Received uploads request method=POST path=/api/pending_closures11052026/10/14 16:46:40 INFO Received complete push request method=POST path=/api/pushes/2/complete11062026/10/14 16:46:40 WARN Failed to register uploaded object key=mnjwqpsybm03dq4h91gsbd57r7py4la5.narinfo error="server returned 404: 404 page not found\n"11072026/10/14 16:46:40 INFO Completed push id=2 objects=3 duration=2.729944ms11082026/10/14 16:46:40 INFO Upload complete. (54ms)11092026/10/14 16:46:40 INFO Received uploads request method=POST path=/api/pending_closures11102026/10/14 16:46:40 INFO Received uploads request method=POST path=/api/pending_closures11112026/10/14 16:46:40 INFO Starting cleanup of old closures method=DELETE path=/api/closures11122026/10/14 16:46:40 INFO Received push request method=POST path=/api/pushes11132026/10/14 16:46:40 INFO Garbage collection started11142026/10/14 16:46:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11152026/10/14 16:46:40 INFO Aborted multipart uploads count=0 kept=011162026/10/14 16:46:40 INFO Signed narinfos id=1 count=111172026/10/14 16:46:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11182026/10/14 16:46:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11192026/10/14 16:46:40 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"11202026/10/14 16:46:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11212026/10/14 16:46:40 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"11222026/10/14 16:46:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11232026/10/14 16:46:40 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=111242026/10/14 16:46:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11252026/10/14 16:46:40 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1126--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.43s)1127=== CONT TestReadProxyConditionalGet1128--- PASS: TestGCBugBareHashReferences (0.94s)1129=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit11302026/10/14 16:46:40 WARN Force mode enabled - objects will be deleted immediately without grace period1131--- PASS: TestReadProxyRangeRequest (0.37s)1132=== CONT TestForceGCDuringPushOffersSweptObject1133=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1134=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1135=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1136=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1137=== CONT TestReadProxyOutlastsServerWriteTimeout11382026/10/14 16:46:40 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=011392026/10/14 16:46:40 INFO Vacuumed table table=pending_closures11402026/10/14 16:46:40 INFO Vacuumed table table=pending_objects11412026/10/14 16:46:40 INFO Vacuumed table table=multipart_uploads11422026/10/14 16:46:40 INFO Vacuumed table table=closures11432026/10/14 16:46:40 INFO Vacuumed table table=objects11442026/10/14 16:46:40 INFO Aborted multipart uploads count=0 kept=011452026/10/14 16:46:40 WARN Force mode enabled - objects will be deleted immediately without grace period11462026/10/14 16:46:40 INFO Received push request method=POST path=/api/pushes1147--- PASS: TestReadRedirectKeepsNarinfoProxied (0.41s)1148=== CONT TestPush_RootsAreLockedInByteOrder11492026/10/14 16:46:40 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11502026/10/14 16:46:40 INFO Uploading myrnw6z0kd078r07fdx2xgyw2szlpxv4-b (216B)11512026/10/14 16:46:40 INFO Uploading rlp8gzdrvbb3yi4n10231p867f406bjg-shared-dep (136B)11522026/10/14 16:46:40 WARN Failed to register uploaded object key=v2anwia3kb42n3jws57zrv0wjr19w32l.ls error="server returned 404: 404 page not found\n"11532026/10/14 16:46:40 WARN Failed to register uploaded object key=rlp8gzdrvbb3yi4n10231p867f406bjg.ls error="server returned 404: 404 page not found\n"11542026/10/14 16:46:40 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11552026/10/14 16:46:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11562026/10/14 16:46:40 WARN Failed to register uploaded object key=nar/18hmf2b6n593jc025y2i9b0abmadhw7r9msz04pz7kcq14qbnhqv.nar.zst error="server returned 404: 404 page not found\n"11572026/10/14 16:46:40 WARN Failed to register uploaded object key=myrnw6z0kd078r07fdx2xgyw2szlpxv4.ls error="server returned 404: 404 page not found\n"11582026/10/14 16:46:40 INFO Signed narinfos id=1 count=311592026/10/14 16:46:40 INFO Uploading 3 narinfos11602026/10/14 16:46:40 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=011612026/10/14 16:46:40 INFO Vacuumed table table=pending_closures1162=== RUN TestPush_RejectsBadRequests/no_roots1163=== PAUSE TestPush_RejectsBadRequests/no_roots1164=== RUN TestPush_RejectsBadRequests/no_objects1165=== PAUSE TestPush_RejectsBadRequests/no_objects1166=== RUN TestPush_RejectsBadRequests/bad_root1167=== PAUSE TestPush_RejectsBadRequests/bad_root1168=== RUN TestPush_RejectsBadRequests/root_not_in_objects1169=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1170=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection11712026/10/14 16:46:40 WARN Failed to register uploaded object key=rlp8gzdrvbb3yi4n10231p867f406bjg.narinfo error="server returned 404: 404 page not found\n"11722026/10/14 16:46:40 INFO Vacuumed table table=pending_objects11732026/10/14 16:46:40 WARN Failed to register uploaded object key=v2anwia3kb42n3jws57zrv0wjr19w32l.narinfo error="server returned 404: 404 page not found\n"11742026/10/14 16:46:40 INFO Vacuumed table table=multipart_uploads11752026/10/14 16:46:40 INFO Vacuumed table table=closures11762026/10/14 16:46:40 WARN Failed to register uploaded object key=myrnw6z0kd078r07fdx2xgyw2szlpxv4.narinfo error="server returned 404: 404 page not found\n"11772026/10/14 16:46:40 INFO Received complete push request method=POST path=/api/pushes/1/complete11782026/10/14 16:46:40 INFO Vacuumed table table=objects1179--- PASS: TestSweepRechecksPendingAfterLocking (0.44s)1180=== CONT TestReadProxyHead11812026/10/14 16:46:40 INFO Completed push id=1 objects=8 duration=6.910702ms11822026/10/14 16:46:40 INFO Upload complete. (61ms)1183=== NAME TestClientPushesUseOnePush1184 client_pushes_test.go:97: Retrieved narinfo from S3:1185 StorePath: /build/TestClientPushesUseOnePush1064267751/001/store/rlp8gzdrvbb3yi4n10231p867f406bjg-shared-dep1186 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1187 Compression: zstd1188 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821189 NarSize: 1361190 References: 1191 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1192 client_pushes_test.go:97: Retrieved narinfo from S3:1193 StorePath: /build/TestClientPushesUseOnePush1064267751/001/store/v2anwia3kb42n3jws57zrv0wjr19w32l-a1194 URL: nar/18hmf2b6n593jc025y2i9b0abmadhw7r9msz04pz7kcq14qbnhqv.nar.zst1195 Compression: zstd1196 NarHash: sha256:18hmf2b6n593jc025y2i9b0abmadhw7r9msz04pz7kcq14qbnhqv1197 NarSize: 2161198 References: /build/TestClientPushesUseOnePush1064267751/001/store/rlp8gzdrvbb3yi4n10231p867f406bjg-shared-dep1199 CA: text:sha256:19javjqknb63jhcgsg770xfb38fd6588b7wsc6gq1djn7ayi41pb1200 client_pushes_test.go:97: Retrieved narinfo from S3:1201 StorePath: /build/TestClientPushesUseOnePush1064267751/001/store/myrnw6z0kd078r07fdx2xgyw2szlpxv4-b1202 URL: nar/18hmf2b6n593jc025y2i9b0abmadhw7r9msz04pz7kcq14qbnhqv.nar.zst1203 Compression: zstd1204 NarHash: sha256:18hmf2b6n593jc025y2i9b0abmadhw7r9msz04pz7kcq14qbnhqv1205 NarSize: 2161206 References: /build/TestClientPushesUseOnePush1064267751/001/store/rlp8gzdrvbb3yi4n10231p867f406bjg-shared-dep1207 CA: text:sha256:19javjqknb63jhcgsg770xfb38fd6588b7wsc6gq1djn7ayi41pb1208--- PASS: TestClientPushesUseOnePush (0.70s)1209=== CONT TestPush_OverlappingRootsStoreOneRowPerKey12102026/10/14 16:46:40 INFO Received uploads request method=POST path=/api/pending_closures12112026/10/14 16:46:40 INFO Received uploads request method=POST path=/api/pending_closures12122026/10/14 16:46:40 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12132026/10/14 16:46:40 INFO Uploading 3h7q0vjk915ylb1z2r28pcnvmp44f0b2-a (216B)12142026/10/14 16:46:40 INFO Uploading xidb2awv85hzzals38vvdr3d7zky0w20-shared-dep (136B)12152026/10/14 16:46:40 WARN Failed to register uploaded object key=2409inqn0s7ybrhx8mnsv207ibhwwz8m.ls error="server returned 404: 404 page not found\n"12162026/10/14 16:46:40 WARN Failed to register uploaded object key=3h7q0vjk915ylb1z2r28pcnvmp44f0b2.ls error="server returned 404: 404 page not found\n"12172026/10/14 16:46:40 WARN Failed to register uploaded object key=nar/0zapfyr65psxz8v8xkxbh7axb3yiv66hqpzpdsnyi2j75qp3zvl4.nar.zst error="server returned 404: 404 page not found\n"1218--- PASS: TestGetExistingObjectsLocksRows (0.35s)1219=== CONT TestGCSweepDeliversEachKeyOnce12202026/10/14 16:46:40 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12212026/10/14 16:46:40 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12222026/10/14 16:46:40 WARN Failed to register uploaded object key=xidb2awv85hzzals38vvdr3d7zky0w20.ls error="server returned 404: 404 page not found\n"12232026/10/14 16:46:40 INFO Signed narinfos id=1 count=212242026/10/14 16:46:40 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12252026/10/14 16:46:40 INFO Signed narinfos id=2 count=212262026/10/14 16:46:40 INFO Uploading 4 narinfos12272026/10/14 16:46:40 WARN Failed to register uploaded object key=2409inqn0s7ybrhx8mnsv207ibhwwz8m.narinfo error="server returned 404: 404 page not found\n"12282026/10/14 16:46:40 WARN Failed to register uploaded object key=xidb2awv85hzzals38vvdr3d7zky0w20.narinfo error="server returned 404: 404 page not found\n"12292026/10/14 16:46:40 WARN Failed to register uploaded object key=3h7q0vjk915ylb1z2r28pcnvmp44f0b2.narinfo error="server returned 404: 404 page not found\n"12302026/10/14 16:46:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12312026/10/14 16:46:40 WARN Failed to register uploaded object key=xidb2awv85hzzals38vvdr3d7zky0w20.narinfo error="server returned 404: 404 page not found\n"12322026/10/14 16:46:40 INFO Completed upload id=1 objects=6 duration=5.964313ms12332026/10/14 16:46:40 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12342026/10/14 16:46:40 INFO Completed upload id=2 objects=6 duration=2.2531ms12352026/10/14 16:46:40 INFO Upload complete. (75ms)1236--- PASS: TestReadRedirectNar (0.34s)1237=== CONT TestReadProxyInvalidPath1238=== NAME TestClientFallsBackToClosures1239 client_pushes_test.go:112: Retrieved narinfo from S3:1240 StorePath: /build/TestClientFallsBackToClosures1663730158/001/store/xidb2awv85hzzals38vvdr3d7zky0w20-shared-dep1241 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1242 Compression: zstd1243 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821244 NarSize: 1361245 References: 1246 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1247 client_pushes_test.go:112: Retrieved narinfo from S3:1248 StorePath: /build/TestClientFallsBackToClosures1663730158/001/store/3h7q0vjk915ylb1z2r28pcnvmp44f0b2-a1249 URL: nar/0zapfyr65psxz8v8xkxbh7axb3yiv66hqpzpdsnyi2j75qp3zvl4.nar.zst1250 Compression: zstd1251 NarHash: sha256:0zapfyr65psxz8v8xkxbh7axb3yiv66hqpzpdsnyi2j75qp3zvl41252 NarSize: 2161253 References: /build/TestClientFallsBackToClosures1663730158/001/store/xidb2awv85hzzals38vvdr3d7zky0w20-shared-dep1254 CA: text:sha256:0q2gyy17rnm88pdwp8wlpk5ci50h5x4cbn4h0hjn56hlpfjgzasz1255 client_pushes_test.go:112: Retrieved narinfo from S3:1256 StorePath: /build/TestClientFallsBackToClosures1663730158/001/store/2409inqn0s7ybrhx8mnsv207ibhwwz8m-b1257 URL: nar/0zapfyr65psxz8v8xkxbh7axb3yiv66hqpzpdsnyi2j75qp3zvl4.nar.zst1258 Compression: zstd1259 NarHash: sha256:0zapfyr65psxz8v8xkxbh7axb3yiv66hqpzpdsnyi2j75qp3zvl41260 NarSize: 2161261 References: /build/TestClientFallsBackToClosures1663730158/001/store/xidb2awv85hzzals38vvdr3d7zky0w20-shared-dep1262 CA: text:sha256:0q2gyy17rnm88pdwp8wlpk5ci50h5x4cbn4h0hjn56hlpfjgzasz1263--- PASS: TestClientFallsBackToClosures (0.63s)1264=== CONT TestReadRedirectUsesPublicS3URL1265--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.28s)1266=== CONT TestTombstonedObjectOfferedWithoutWaiting1267--- PASS: TestReadProxyDisabled (0.30s)1268=== CONT TestReadProxy40412692026/10/14 16:46:40 INFO Aborted multipart uploads count=0 kept=01270--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.33s)1271=== CONT TestGCSweepSkipsPendingObjects12722026/10/14 16:46:40 WARN Force mode enabled - objects will be deleted immediately without grace period12732026/10/14 16:46:40 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=012742026/10/14 16:46:40 INFO Vacuumed table table=pending_closures12752026/10/14 16:46:40 INFO Vacuumed table table=pending_objects12762026/10/14 16:46:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12772026/10/14 16:46:40 INFO Vacuumed table table=multipart_uploads12782026/10/14 16:46:40 INFO Vacuumed table table=closures12792026/10/14 16:46:40 INFO Vacuumed table table=objects12802026/10/14 16:46:40 INFO Aborted multipart uploads count=0 kept=012812026/10/14 16:46:40 WARN Force mode enabled - objects will be deleted immediately without grace period12822026/10/14 16:46:40 INFO Received uploads request method=POST path=/api/pending_closures12832026/10/14 16:46:40 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZTZjODdlZWUtN2ZmMS00MjcwLWI0MmEtOWE2ODYwY2NmZjBjLjBjMGVjNWE1LWI4YzMtNDNlNS1iZGQzLTQ3M2E3YzhhYTQ4N3gxNzkxOTk2NDAwNTEwMjc3MDIz parts=1212842026/10/14 16:46:40 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=012852026/10/14 16:46:40 INFO Received uploads request method=POST path=/api/pending_closures12862026/10/14 16:46:40 INFO Vacuumed table table=pending_closures12872026/10/14 16:46:40 INFO Vacuumed table table=pending_objects12882026/10/14 16:46:40 INFO Vacuumed table table=multipart_uploads12892026/10/14 16:46:40 INFO Vacuumed table table=closures1290--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.13s)1291=== CONT TestCacheConfigHandler1292=== RUN TestCacheConfigHandler/full_config,_no_issuer1293=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1294=== RUN TestCacheConfigHandler/no_cache_url_configured1295=== PAUSE TestCacheConfigHandler/no_cache_url_configured1296=== RUN TestCacheConfigHandler/no_signing_keys1297=== PAUSE TestCacheConfigHandler/no_signing_keys1298=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1299=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1300=== CONT TestPushDedupSurvivesConcurrentGC13012026/10/14 16:46:40 INFO Vacuumed table table=objects1302--- PASS: TestSweepSkipsRowsLockedByPush (0.39s)1303=== CONT TestGCMetrics1304--- PASS: TestReadProxyConditionalGet (0.31s)1305=== CONT TestClientMultipleUploads13062026/10/14 16:46:40 INFO Received push request method=POST path=/api/pushes13072026/10/14 16:46:41 INFO Received complete push request method=POST path=/api/pushes/1/complete13082026/10/14 16:46:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13092026/10/14 16:46:41 INFO Completed push id=1 objects=4 duration=10.061269ms13102026/10/14 16:46:41 INFO Received push request method=POST path=/api/pushes13112026/10/14 16:46:41 INFO Aborted multipart uploads count=0 kept=013122026/10/14 16:46:41 WARN Force mode enabled - objects will be deleted immediately without grace period13132026/10/14 16:46:41 INFO Received push request method=POST path=/api/pushes13142026/10/14 16:46:41 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."13152026/10/14 16:46:41 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."13162026/10/14 16:46:41 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZTZjODdlZWUtN2ZmMS00MjcwLWI0MmEtOWE2ODYwY2NmZjBjLjBkYTlkOWRkLTZjZjgtNDMyYS04ZGQ1LTIzZTk4NGNiYzBmYngxNzkxOTk2NDAwNjA2NTc4MTQx parts=121317--- PASS: TestFailedS3DeleteKeepsTombstone (0.44s)1318=== CONT TestDeduplicatedObjectsRecordedAsPending13192026/10/14 16:46:41 INFO Received uploads request method=POST path=/api/pending_closures13202026/10/14 16:46:41 INFO Received uploads request method=POST path=/api/pending_closures13212026/10/14 16:46:41 INFO Received uploads request method=POST path=/api/pending_closures13222026-10-14 16:46:41.062 UTC [1089] ERROR: could not obtain lock on row in relation "closures"13232026-10-14 16:46:41.062 UTC [1089] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT13242026-10-14 16:46:41.062 UTC [1089] ERROR: could not obtain lock on row in relation "closures"13252026-10-14 16:46:41.062 UTC [1089] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT13262026-10-14 16:46:41.063 UTC [1089] ERROR: could not obtain lock on row in relation "closures"13272026-10-14 16:46:41.063 UTC [1089] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT13282026-10-14 16:46:41.063 UTC [1089] ERROR: could not obtain lock on row in relation "closures"13292026-10-14 16:46:41.063 UTC [1089] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT13302026-10-14 16:46:41.063 UTC [1089] ERROR: could not obtain lock on row in relation "closures"13312026-10-14 16:46:41.063 UTC [1089] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1332--- PASS: TestPush_RootsAreLockedInByteOrder (0.34s)1333=== CONT TestClientIntegration13342026/10/14 16:46:41 INFO Aborted multipart uploads count=0 kept=013352026/10/14 16:46:41 WARN Force mode enabled - objects will be deleted immediately without grace period1336--- PASS: TestReadProxyHead (0.33s)1337=== CONT TestObjectStatsTrigger13382026/10/14 16:46:41 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=013392026/10/14 16:46:41 INFO Vacuumed table table=pending_closures13402026/10/14 16:46:41 INFO Vacuumed table table=pending_objects13412026/10/14 16:46:41 INFO Vacuumed table table=multipart_uploads13422026/10/14 16:46:41 INFO Vacuumed table table=closures13432026/10/14 16:46:41 INFO Received push request method=POST path=/api/pushes13442026/10/14 16:46:41 INFO Vacuumed table table=objects13452026/10/14 16:46:41 INFO Received complete push request method=POST path=/api/pushes/2/complete13462026/10/14 16:46:41 INFO Completed push id=2 objects=4 duration=2.923066ms1347--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.44s)1348=== CONT TestPush_CompleteCommitsEveryRoot1349--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.35s)1350=== CONT TestPush_CompleteWaitsForCleanupOfThePush1351--- PASS: TestPushWaitsForSweepHoldingRow (0.91s)1352=== CONT TestReadProxyContentNegotiation13532026/10/14 16:46:41 INFO lead: released remote=192.0.2.1:12341354--- PASS: TestLeadEndsOnShutdown (1.47s)1355=== CONT TestPush_RepeatedRootCommitsOnce1356--- PASS: TestReadProxyInvalidPath (0.34s)1357=== CONT TestClientCADerivations13582026/10/14 16:46:41 INFO Aborted multipart uploads count=0 kept=013592026/10/14 16:46:41 WARN Force mode enabled - objects will be deleted immediately without grace period1360--- PASS: TestReadRedirectUsesPublicS3URL (0.37s)1361=== CONT TestClientErrorHandling1362=== RUN TestClientErrorHandling/InvalidStorePath1363=== PAUSE TestClientErrorHandling/InvalidStorePath1364=== RUN TestClientErrorHandling/InvalidAuthToken1365=== PAUSE TestClientErrorHandling/InvalidAuthToken1366=== RUN TestClientErrorHandling/ServerNotAvailable1367=== PAUSE TestClientErrorHandling/ServerNotAvailable1368=== CONT TestCacheStatsHandler13692026/10/14 16:46:41 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=013702026/10/14 16:46:41 INFO Vacuumed table table=pending_closures13712026/10/14 16:46:41 INFO Vacuumed table table=pending_objects13722026/10/14 16:46:41 INFO Vacuumed table table=multipart_uploads13732026/10/14 16:46:41 INFO Vacuumed table table=closures13742026/10/14 16:46:41 INFO Vacuumed table table=objects1375--- PASS: TestGCSweepDeliversEachKeyOnce (0.40s)1376=== CONT TestReadProxyNarinfoAlreadyDecompressed13772026/10/14 16:46:41 INFO Received uploads request method=POST path=/api/pending_closures1378--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.38s)1379=== CONT TestMetricsCommit1380--- PASS: TestReadProxy404 (0.40s)1381=== CONT TestMultipartCleanup13822026/10/14 16:46:41 INFO Received uploads request method=POST path=/api/pending_closures1383--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.52s)1384=== CONT TestReadProxyNarinfo13852026/10/14 16:46:41 INFO Aborted multipart uploads count=0 kept=013862026/10/14 16:46:41 WARN Force mode enabled - objects will be deleted immediately without grace period13872026/10/14 16:46:41 INFO Aborted multipart uploads count=0 kept=013882026/10/14 16:46:41 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=013892026/10/14 16:46:41 WARN Force mode enabled - objects will be deleted immediately without grace period13902026/10/14 16:46:41 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=013912026/10/14 16:46:41 INFO Vacuumed table table=pending_closures13922026/10/14 16:46:41 INFO Vacuumed table table=pending_closures13932026/10/14 16:46:41 INFO Vacuumed table table=pending_objects13942026/10/14 16:46:41 INFO Vacuumed table table=multipart_uploads13952026/10/14 16:46:41 INFO Vacuumed table table=closures13962026/10/14 16:46:41 INFO Vacuumed table table=objects13972026/10/14 16:46:41 INFO Vacuumed table table=pending_objects13982026/10/14 16:46:41 INFO Vacuumed table table=multipart_uploads13992026/10/14 16:46:41 INFO Vacuumed table table=closures1400--- PASS: TestGCMetrics (0.35s)1401=== CONT TestServerTLSConfig1402=== RUN TestServerTLSConfig/no_client_CA1403=== PAUSE TestServerTLSConfig/no_client_CA1404=== RUN TestServerTLSConfig/missing_CA_file1405=== PAUSE TestServerTLSConfig/missing_CA_file1406=== RUN TestServerTLSConfig/not_a_PEM_file1407=== PAUSE TestServerTLSConfig/not_a_PEM_file1408=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded14092026/10/14 16:46:41 INFO Vacuumed table table=objects1410--- PASS: TestGCSweepSkipsPendingObjects (0.39s)1411=== CONT TestIsValidCachePath1412=== RUN TestIsValidCachePath/narinfo1413=== PAUSE TestIsValidCachePath/narinfo1414=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1415=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1416=== RUN TestIsValidCachePath/nar_zst1417=== PAUSE TestIsValidCachePath/nar_zst1418=== RUN TestIsValidCachePath/nar_xz1419=== PAUSE TestIsValidCachePath/nar_xz1420=== RUN TestIsValidCachePath/nar_bz21421=== PAUSE TestIsValidCachePath/nar_bz21422=== RUN TestIsValidCachePath/nar_uncompressed1423=== PAUSE TestIsValidCachePath/nar_uncompressed1424=== RUN TestIsValidCachePath/ls1425=== PAUSE TestIsValidCachePath/ls1426=== RUN TestIsValidCachePath/log1427=== PAUSE TestIsValidCachePath/log1428=== RUN TestIsValidCachePath/realisation1429=== PAUSE TestIsValidCachePath/realisation1430=== RUN TestIsValidCachePath/nix-cache-info1431=== PAUSE TestIsValidCachePath/nix-cache-info1432=== RUN TestIsValidCachePath/index.html1433=== PAUSE TestIsValidCachePath/index.html1434=== RUN TestIsValidCachePath/traversal_parent1435=== PAUSE TestIsValidCachePath/traversal_parent1436=== RUN TestIsValidCachePath/traversal_in_middle1437=== PAUSE TestIsValidCachePath/traversal_in_middle1438=== RUN TestIsValidCachePath/invalid_char_e1439=== PAUSE TestIsValidCachePath/invalid_char_e1440=== RUN TestIsValidCachePath/invalid_char_u1441=== PAUSE TestIsValidCachePath/invalid_char_u1442=== RUN TestIsValidCachePath/random_path1443=== PAUSE TestIsValidCachePath/random_path1444=== RUN TestIsValidCachePath/empty1445=== PAUSE TestIsValidCachePath/empty1446=== RUN TestIsValidCachePath/leading_slash1447=== PAUSE TestIsValidCachePath/leading_slash1448=== RUN TestIsValidCachePath/wrong_extension1449=== PAUSE TestIsValidCachePath/wrong_extension1450=== RUN TestIsValidCachePath/short_hash1451=== PAUSE TestIsValidCachePath/short_hash1452=== CONT TestService_NativeMTLS14532026/10/14 16:46:41 INFO Received uploads request method=POST path=/api/pending_closures14542026/10/14 16:46:41 INFO Received uploads request method=POST path=/api/pending_closures1455--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.33s)1456=== CONT TestParseSingleRange1457=== RUN TestParseSingleRange/none1458=== PAUSE TestParseSingleRange/none1459=== RUN TestParseSingleRange/unknown_unit1460=== PAUSE TestParseSingleRange/unknown_unit1461=== RUN TestParseSingleRange/multi-range_ignored1462=== PAUSE TestParseSingleRange/multi-range_ignored1463=== RUN TestParseSingleRange/malformed_no_dash1464=== PAUSE TestParseSingleRange/malformed_no_dash1465=== RUN TestParseSingleRange/malformed_both_empty1466=== PAUSE TestParseSingleRange/malformed_both_empty1467=== RUN TestParseSingleRange/malformed_end_before_start1468=== PAUSE TestParseSingleRange/malformed_end_before_start1469=== RUN TestParseSingleRange/closed1470=== PAUSE TestParseSingleRange/closed1471=== RUN TestParseSingleRange/open-ended1472=== PAUSE TestParseSingleRange/open-ended1473=== RUN TestParseSingleRange/end_clamped_to_size1474=== PAUSE TestParseSingleRange/end_clamped_to_size1475=== RUN TestParseSingleRange/suffix1476=== PAUSE TestParseSingleRange/suffix1477=== RUN TestParseSingleRange/suffix_exceeds_size1478=== PAUSE TestParseSingleRange/suffix_exceeds_size1479=== RUN TestParseSingleRange/single_byte1480=== PAUSE TestParseSingleRange/single_byte1481=== RUN TestParseSingleRange/start_past_EOF1482=== PAUSE TestParseSingleRange/start_past_EOF1483=== RUN TestParseSingleRange/start_far_past_EOF1484=== PAUSE TestParseSingleRange/start_far_past_EOF1485=== CONT TestService_AuthMiddleware_OIDC1486=== NAME TestClientMultipleUploads1487 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads4051616010/001/store/v7bnpd4xzsf7n54bd81xjslgmk88jr8k-test-file-0.txt14882026/10/14 16:46:41 INFO Aborted multipart uploads count=0 kept=01489 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads4051616010/001/store/zs0dl17agx7l3z3falhm7pwi161x0d1m-test-file-1.txt14902026/10/14 16:46:41 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=014912026/10/14 16:46:41 INFO Vacuumed table table=pending_closures14922026/10/14 16:46:41 INFO Vacuumed table table=pending_objects14932026/10/14 16:46:41 INFO Vacuumed table table=multipart_uploads14942026/10/14 16:46:41 INFO Vacuumed table table=closures14952026/10/14 16:46:41 INFO Vacuumed table table=objects1496--- PASS: TestObjectStatsTrigger (0.33s)1497=== CONT TestPresentNotReportedWhileGCDeletesClosure1498=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1499=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1500=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1501=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1502=== CONT TestService_ReadScope_PublicByDefault1503=== NAME TestClientIntegration1504 client_integration_test.go:286: Created store path: /build/TestClientIntegration3891012580/002/store/hhqv2hr2hnnwnjjlzyimfmkbli49q5am-test-file.txt15052026/10/14 16:46:41 INFO Aborted multipart uploads count=0 kept=015062026/10/14 16:46:41 WARN Force mode enabled - objects will be deleted immediately without grace period15072026/10/14 16:46:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15082026/10/14 16:46:41 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=015092026/10/14 16:46:41 INFO Received push request method=POST path=/api/pushes15102026/10/14 16:46:41 INFO Vacuumed table table=pending_closures15112026/10/14 16:46:41 INFO Vacuumed table table=pending_objects15122026/10/14 16:46:41 INFO Vacuumed table table=multipart_uploads15132026/10/14 16:46:41 INFO Vacuumed table table=closures15142026/10/14 16:46:41 INFO Vacuumed table table=objects1515--- PASS: TestPushDedupSurvivesConcurrentGC (0.48s)1516=== CONT TestPresentRefreshesOnlyStaleClosures1517=== NAME TestClientMultipleUploads1518 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads4051616010/001/store/bpkswdp8mq428h8nlzbdp92p7hk15ryg-test-file-2.txt15192026/10/14 16:46:41 INFO Received complete push request method=POST path=/api/pushes/1/complete15202026/10/14 16:46:41 INFO Received push request method=POST path=/api/pushes15212026/10/14 16:46:41 INFO Completed push id=1 objects=6 duration=14.160006ms1522--- PASS: TestPush_CompleteCommitsEveryRoot (0.35s)1523=== CONT TestCreatePendingClosureRejectsOversizedNAR15242026/10/14 16:46:41 INFO Received uploads request method=POST path=/api/pending_closures1525--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1526=== CONT TestService_RequireScope_OIDC15272026/10/14 16:46:41 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZTZjODdlZWUtN2ZmMS00MjcwLWI0MmEtOWE2ODYwY2NmZjBjLjcxNTBjYzM1LWE5MzEtNDZlNC04M2RlLTI2YTNmYzMyYWQxM3gxNzkxOTk2NDAxMDQxNzI1Mjk4 error="Get \"http://127.0.0.1:1/bucket30/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"15282026/10/14 16:46:41 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZTZjODdlZWUtN2ZmMS00MjcwLWI0MmEtOWE2ODYwY2NmZjBjLmY3NWVjODM5LWRlZmQtNDg1Yy1iMDNjLThhMTdmNzRlYmM0YngxNzkxOTk2NDAxMDM2MDg3NDQ3 parts=1215292026/10/14 16:46:41 INFO Received cleanup request method=DELETE path=/api/pending_closures15302026/10/14 16:46:41 INFO Aborted multipart uploads count=1 kept=015312026/10/14 16:46:41 INFO Received push request method=POST path=/api/pushes1532--- PASS: TestRedundantMultipartUpload (1.28s)1533=== CONT TestMetricsInventory15342026/10/14 16:46:41 INFO Received complete push request method=POST path=/api/pushes/1/complete15352026/10/14 16:46:41 INFO Received push request method=POST path=/api/pushes15362026/10/14 16:46:41 INFO Completed push id=1 objects=4 duration=8.565616ms1537--- PASS: TestPush_RepeatedRootCommitsOnce (0.36s)1538=== CONT TestPresentReportsOnlyClosureRoots15392026/10/14 16:46:41 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15402026/10/14 16:46:41 INFO Uploading hhqv2hr2hnnwnjjlzyimfmkbli49q5am-test-file.txt (152B)15412026/10/14 16:46:41 WARN Failed to register uploaded object key=hhqv2hr2hnnwnjjlzyimfmkbli49q5am.ls error="server returned 404: 404 page not found\n"15422026/10/14 16:46:41 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15432026/10/14 16:46:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15442026/10/14 16:46:41 INFO Signed narinfos id=1 count=115452026/10/14 16:46:41 INFO Uploading 1 narinfos15462026/10/14 16:46:41 INFO Received push request method=POST path=/api/pushes15472026/10/14 16:46:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38355/oidc15482026/10/14 16:46:41 INFO Received complete push request method=POST path=/api/pushes/1/complete15492026/10/14 16:46:41 WARN Failed to register uploaded object key=hhqv2hr2hnnwnjjlzyimfmkbli49q5am.narinfo error="server returned 404: 404 page not found\n"15502026/10/14 16:46:41 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15512026/10/14 16:46:41 INFO Uploading v7bnpd4xzsf7n54bd81xjslgmk88jr8k-test-file-0.txt (160B)15522026/10/14 16:46:41 INFO Uploading zs0dl17agx7l3z3falhm7pwi161x0d1m-test-file-1.txt (160B)15532026/10/14 16:46:41 INFO Uploading bpkswdp8mq428h8nlzbdp92p7hk15ryg-test-file-2.txt (160B)15542026/10/14 16:46:41 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15552026/10/14 16:46:41 WARN Failed to register uploaded object key=zs0dl17agx7l3z3falhm7pwi161x0d1m.ls error="server returned 404: 404 page not found\n"15562026/10/14 16:46:41 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15572026/10/14 16:46:41 WARN Failed to register uploaded object key=bpkswdp8mq428h8nlzbdp92p7hk15ryg.ls error="server returned 404: 404 page not found\n"15582026/10/14 16:46:41 WARN Failed to register uploaded object key=v7bnpd4xzsf7n54bd81xjslgmk88jr8k.ls error="server returned 404: 404 page not found\n"15592026/10/14 16:46:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15602026/10/14 16:46:41 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15612026/10/14 16:46:41 INFO Signed narinfos id=1 count=315622026/10/14 16:46:41 INFO Uploading 3 narinfos15632026/10/14 16:46:41 INFO Completed push id=1 objects=3 duration=11.854546ms15642026/10/14 16:46:41 INFO Upload complete. (71ms)15652026/10/14 16:46:41 WARN Failed to register uploaded object key=zs0dl17agx7l3z3falhm7pwi161x0d1m.narinfo error="server returned 404: 404 page not found\n"15662026/10/14 16:46:41 WARN Failed to register uploaded object key=bpkswdp8mq428h8nlzbdp92p7hk15ryg.narinfo error="server returned 404: 404 page not found\n"15672026/10/14 16:46:41 INFO Received complete push request method=POST path=/api/pushes/1/complete15682026/10/14 16:46:41 WARN Failed to register uploaded object key=v7bnpd4xzsf7n54bd81xjslgmk88jr8k.narinfo error="server returned 404: 404 page not found\n"15692026/10/14 16:46:41 INFO Completed push id=1 objects=9 duration=6.281536ms15702026/10/14 16:46:41 INFO Upload complete. (60ms)1571=== NAME TestClientMultipleUploads1572 client_integration_test.go:369: Uploaded 3 paths in 93.805356ms15732026/10/14 16:46:41 INFO lead: released remote=192.0.2.1:12341574--- PASS: TestClientMultipleUploads (0.57s)1575=== CONT TestOrphanedObjectsGCStressTest1576--- PASS: TestCacheStatsHandler (0.36s)1577=== CONT TestPendingCleanupUsesOneCutoff1578--- PASS: TestReadProxyContentNegotiation (0.41s)1579=== CONT TestCreatePin_ReservedPins15802026/10/14 16:46:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42083/oidc15812026/10/14 16:46:41 INFO All 1 paths already cached1582=== NAME TestClientIntegration1583 client_integration_test.go:312: Retrieved narinfo from S3:1584 StorePath: /build/TestClientIntegration3891012580/002/store/hhqv2hr2hnnwnjjlzyimfmkbli49q5am-test-file.txt1585 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1586 Compression: zstd1587 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11588 NarSize: 1521589 References: 1590 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11591 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1592 client_integration_test.go:313: Decompressed .ls content (64 bytes):1593 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1594 client_integration_test.go:316: Testing garbage collection...1595--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.37s)1596=== CONT TestOrphanedObjectsGC15972026/10/14 16:46:41 INFO Received push request method=POST path=/api/pushes15982026/10/14 16:46:41 INFO lead: acquired remote=192.0.2.1:123415992026/10/14 16:46:41 INFO Received complete push request method=POST path=/api/pushes/1/complete16002026/10/14 16:46:41 INFO Starting cleanup of old closures method=DELETE path=/api/closures16012026/10/14 16:46:41 INFO Garbage collection started16022026/10/14 16:46:41 INFO Received uploads request method=POST path=/api/pending_closures16032026/10/14 16:46:41 INFO Aborted multipart uploads count=0 kept=016042026/10/14 16:46:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44307/oidc16052026/10/14 16:46:41 INFO Completed push id=1 objects=4 duration=10.595114ms1606=== NAME TestClientCADerivations1607 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2997789975/001/store/ygp8fmsqb4sacbyqalryj79gwg6p3x6s-ca-test16082026/10/14 16:46:41 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16092026/10/14 16:46:41 INFO Completed upload id=2 objects=2 duration=1.499073ms16102026/10/14 16:46:41 WARN Force mode enabled - objects will be deleted immediately without grace period1611--- PASS: TestMetricsCommit (0.41s)1612=== CONT TestNARDeduplicationMetadataUploadBug1613--- PASS: TestDeleteClosuresRacingPins (1.90s)1614=== CONT TestObjectStatsLargeCommit16152026/10/14 16:46:41 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=016162026/10/14 16:46:41 INFO Vacuumed table table=pending_closures16172026/10/14 16:46:41 INFO Vacuumed table table=pending_objects16182026/10/14 16:46:41 INFO Vacuumed table table=multipart_uploads16192026/10/14 16:46:41 INFO Vacuumed table table=closures1620=== NAME TestClientCADerivations1621 client_ca_test.go:139: Found 1 dependencies (including self)16222026/10/14 16:46:41 INFO Vacuumed table table=objects16232026/10/14 16:46:41 INFO Received uploads request method=POST path=/api/pending_closures1624--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.38s)1625=== CONT TestService_ReadAuthMiddleware16262026/10/14 16:46:41 WARN mTLS auth: subject not in bound subjects subject="CN=reader"16272026/10/14 16:46:41 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1628--- PASS: TestService_NativeMTLS (0.38s)1629=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1630--- PASS: TestService_ReadScope_PublicByDefault (0.29s)1631=== CONT TestService_readinessHandler16322026/10/14 16:46:41 INFO Received cleanup request method=DELETE path=/api/pending_closures16332026/10/14 16:46:41 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket71/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""16342026/10/14 16:46:41 INFO Aborted multipart uploads count=0 kept=116352026/10/14 16:46:41 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1636--- PASS: TestReadProxyNarinfo (0.45s)1637=== CONT TestService_AuthMiddleware_MTLSProxyHeader16382026/10/14 16:46:41 INFO Received cleanup request method=DELETE path=/api/pending_closures16392026/10/14 16:46:41 INFO Aborted multipart uploads count=1 kept=01640--- PASS: TestMultipartCleanup (0.48s)1641=== CONT TestCacheConfigHandlerMaxNarSize1642--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1643=== CONT TestGenerateLandingPage1644--- PASS: TestGenerateLandingPage (0.00s)1645=== CONT TestProxyWriteTimeout/narinfo1646=== CONT TestProxyWriteTimeout/unknown_size1647=== CONT TestProxyWriteTimeout/10_GiB_nar1648=== CONT TestProxyWriteTimeout/1_GiB_nar1649=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1650--- PASS: TestProxyWriteTimeout (0.00s)1651 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1652 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1653 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1654 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)16552026/10/14 16:46:41 INFO Received uploads request method=POST path=/1656=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16572026/10/14 16:46:41 INFO Received complete multipart upload request method=POST path=/1658=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16592026/10/14 16:46:41 INFO Received request for more parts method=POST path=/1660=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16612026/10/14 16:46:41 INFO Received uploads request method=POST path=/1662--- PASS: TestUploadHandlersRejectInvalidKeys (0.06s)1663 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1664 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1665 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1666 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1667=== CONT TestPendingClosureWriteTimeout/empty1668=== CONT TestPendingClosureWriteTimeout/400_objects1669=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1670--- PASS: TestPresentRefreshesOnlyStaleClosures (0.32s)1671=== CONT TestPendingClosureWriteTimeout/670k_objects1672=== CONT TestResolveDBConnectionString/flag_wins1673=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1674=== CONT TestResolveDBConnectionString/file_when_flag_empty1675=== CONT TestResolveDBConnectionString/missing_file_is_an_error1676=== CONT TestResolveDBConnectionString/nothing_configured1677=== CONT TestIsValidUploadKey/narinfo1678=== CONT TestIsValidUploadKey/realisation_plus_in_output1679=== CONT TestIsValidUploadKey/unknown_type1680=== CONT TestIsValidUploadKey/empty_key1681=== CONT TestIsValidUploadKey/absolute1682=== CONT TestIsValidUploadKey/traversal_nar1683=== CONT TestIsValidUploadKey/traversal1684=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1685=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1686=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1687=== CONT TestIsValidUploadKey/index.html1688=== CONT TestIsValidUploadKey/nix-cache-info1689=== CONT TestIsValidUploadKey/build_log_home-manager_file1690--- PASS: TestResolveDBConnectionString (0.04s)1691 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1692 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1693 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1694 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1695 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1696=== CONT TestIsValidUploadKey/realisation1697=== CONT TestIsValidUploadKey/build_log_equals1698=== CONT TestIsValidUploadKey/build_log_question_mark1699=== CONT TestIsValidUploadKey/build_log_plus_in_name1700=== CONT TestIsValidUploadKey/nar_plain1701=== CONT TestIsValidUploadKey/build_log1702=== CONT TestIsValidUploadKey/listing1703=== CONT TestIsValidUploadKey/nar_xz1704=== CONT TestIsValidUploadKey/nar_zst1705=== CONT TestGCEndsOnShutdown/before_the_run1706--- PASS: TestIsValidUploadKey (0.06s)1707 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1708 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1709 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1710 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1711 --- PASS: TestIsValidUploadKey/absolute (0.00s)1712 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1713 --- PASS: TestIsValidUploadKey/traversal (0.00s)1714 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1715 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1716 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1717 --- PASS: TestIsValidUploadKey/index.html (0.00s)1718 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1719 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1720 --- PASS: TestIsValidUploadKey/realisation (0.00s)1721 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1722 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1723 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1724 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1725 --- PASS: TestIsValidUploadKey/build_log (0.00s)1726 --- PASS: TestIsValidUploadKey/listing (0.00s)1727 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1728 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)17292026/10/14 16:46:41 INFO Received push request method=POST path=/api/pushes17302026/10/14 16:46:41 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17312026/10/14 16:46:41 INFO Uploading ygp8fmsqb4sacbyqalryj79gwg6p3x6s-ca-test (144B)17322026/10/14 16:46:41 WARN Failed to register uploaded object key=ygp8fmsqb4sacbyqalryj79gwg6p3x6s.ls error="server returned 404: 404 page not found\n"17332026/10/14 16:46:41 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"17342026/10/14 16:46:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17352026/10/14 16:46:41 WARN Failed to register uploaded object key=log/605y4j1p6h49d25av0pxc84wjwns6iz3-ca-test.drv error="server returned 404: 404 page not found\n"17362026/10/14 16:46:41 INFO Signed narinfos id=1 count=117372026/10/14 16:46:41 INFO Uploading 1 narinfos17382026-10-14 16:46:41.757 UTC [1236] ERROR: Push does not exist: id=117392026-10-14 16:46:41.757 UTC [1236] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE17402026-10-14 16:46:41.757 UTC [1236] STATEMENT: SELECT commit_push($1)1741--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.64s)1742=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete17432026/10/14 16:46:41 INFO Received complete push request method=POST path=/api/pushes/1/complete17442026/10/14 16:46:41 WARN Failed to register uploaded object key=ygp8fmsqb4sacbyqalryj79gwg6p3x6s.narinfo error="server returned 404: 404 page not found\n"1745--- PASS: TestMetricsInventory (0.30s)1746=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark17472026/10/14 16:46:41 INFO Completed push id=1 objects=4 duration=7.032083ms17482026/10/14 16:46:41 INFO Upload complete. (99ms)1749=== NAME TestClientCADerivations1750 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2997789975/001/store/ygp8fmsqb4sacbyqalryj79gwg6p3x6s-ca-test1751 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1752 Compression: zstd1753 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1754 NarSize: 1441755 References: 1756 Deriver: /build/TestClientCADerivations2997789975/001/store/605y4j1p6h49d25av0pxc84wjwns6iz3-ca-test.drv1757 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1758 client_ca_test.go:185: Checking for realisation files in S3...1759 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1760 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1761--- PASS: TestPresentReportsOnlyClosureRoots (0.31s)1762=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17632026/10/14 16:46:41 INFO Received uploads request method=POST path=/1764=== RUN TestService_RequireScope_OIDC/builder_may_write1765=== PAUSE TestService_RequireScope_OIDC/builder_may_write1766=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1767=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1768=== RUN TestService_RequireScope_OIDC/ops_may_admin1769=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1770=== RUN TestService_RequireScope_OIDC/ops_may_not_write1771=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1772=== RUN TestService_RequireScope_OIDC/reader_may_not_write1773=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1774=== RUN TestService_RequireScope_OIDC/static_token_may_admin1775=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1776=== RUN TestService_RequireScope_OIDC/static_token_may_write1777=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1778=== RUN TestService_RequireScope_OIDC/reader_may_read1779=== PAUSE TestService_RequireScope_OIDC/reader_may_read1780=== RUN TestService_RequireScope_OIDC/writer_implies_read1781=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1782=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1783=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1784=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1785=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1786=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1787=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1788=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1789=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1790=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1791=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1792=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17932026/10/14 16:46:41 INFO Received request for more parts method=POST path=/17942026/10/14 16:46:41 INFO Received uploads request method=POST path=/api/pending_closures17952026/10/14 16:46:41 INFO Received uploads request method=POST path=/api/pending_closures17962026/10/14 16:46:41 INFO Received cleanup request method=DELETE path=/api/pending_closures1797=== NAME TestClientCADerivations1798 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1799 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1800 error: binary cache 's3://bucket67?endpoint=http://localhost:33179®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2997789975/001/store'1801 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11802=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18032026/10/14 16:46:41 INFO Received complete multipart upload request method=POST path=/1804--- PASS: TestClientCADerivations (0.74s)1805=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1806=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1807=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1808=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1809=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1810=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1811=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1812=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1813=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1814=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check18152026/10/14 16:46:41 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18162026/10/14 16:46:41 WARN Refused reserved pin name=worker-x86_64-linux18172026/10/14 16:46:41 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18182026/10/14 16:46:41 INFO Received create pin request method=POST path=/api/pins/my-app18192026/10/14 16:46:41 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1820--- PASS: TestCreatePin_ReservedPins (0.37s)1821=== CONT TestPush_RejectsBadRequests/no_roots18222026/10/14 16:46:41 INFO Received push request method=POST path=/api/pushes1823=== CONT TestPush_RejectsBadRequests/root_not_in_objects18242026/10/14 16:46:41 INFO Received push request method=POST path=/api/pushes1825=== CONT TestPush_RejectsBadRequests/bad_root18262026/10/14 16:46:41 INFO Received push request method=POST path=/api/pushes1827=== CONT TestPush_RejectsBadRequests/no_objects18282026/10/14 16:46:41 INFO Received push request method=POST path=/api/pushes1829=== CONT TestCacheConfigHandler/full_config,_no_issuer1830--- PASS: TestPush_RejectsBadRequests (0.36s)1831 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1832 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1833 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1834 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1835=== CONT TestCacheConfigHandler/no_signing_keys1836=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1837=== CONT TestCacheConfigHandler/no_cache_url_configured1838--- PASS: TestCacheConfigHandler (0.00s)1839 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1840 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1841 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1842 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1843=== CONT TestClientErrorHandling/InvalidStorePath1844=== CONT TestClientErrorHandling/InvalidAuthToken1845--- PASS: TestService_ReadAuthMiddleware (0.30s)1846=== CONT TestClientErrorHandling/ServerNotAvailable1847=== NAME TestNARDeduplicationMetadataUploadBug1848 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2633603674/001/store/w3vlb0rgaiy3z21jgbf59f4v2fh44npp-file1.txt18492026/10/14 16:46:41 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"18502026/10/14 16:46:41 WARN mTLS auth: bound subjects configured but subject DN unavailable18512026/10/14 16:46:41 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1852--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.31s)1853=== CONT TestServerTLSConfig/no_client_CA1854=== CONT TestServerTLSConfig/missing_CA_file1855=== CONT TestServerTLSConfig/not_a_PEM_file1856--- PASS: TestServerTLSConfig (0.00s)1857 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1858 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1859 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1860=== CONT TestIsValidCachePath/narinfo1861=== CONT TestIsValidCachePath/short_hash1862=== CONT TestIsValidCachePath/wrong_extension1863=== CONT TestIsValidCachePath/leading_slash1864=== CONT TestIsValidCachePath/empty1865=== CONT TestIsValidCachePath/random_path1866=== CONT TestIsValidCachePath/invalid_char_u1867=== CONT TestIsValidCachePath/invalid_char_e1868=== CONT TestIsValidCachePath/traversal_in_middle1869=== CONT TestIsValidCachePath/traversal_parent1870=== CONT TestIsValidCachePath/index.html1871=== CONT TestIsValidCachePath/nix-cache-info1872=== CONT TestIsValidCachePath/realisation1873=== CONT TestIsValidCachePath/log1874=== CONT TestIsValidCachePath/ls1875=== CONT TestIsValidCachePath/nar_uncompressed1876=== CONT TestIsValidCachePath/nar_bz21877=== CONT TestIsValidCachePath/nar_xz1878=== CONT TestIsValidCachePath/nar_zst1879=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1880=== CONT TestParseSingleRange/none1881=== CONT TestParseSingleRange/closed1882=== CONT TestParseSingleRange/malformed_end_before_start1883=== CONT TestParseSingleRange/malformed_both_empty1884=== CONT TestParseSingleRange/start_far_past_EOF1885=== CONT TestParseSingleRange/multi-range_ignored1886=== CONT TestParseSingleRange/malformed_no_dash1887=== CONT TestParseSingleRange/unknown_unit1888=== CONT TestParseSingleRange/open-ended1889=== CONT TestParseSingleRange/suffix1890=== CONT TestParseSingleRange/suffix_exceeds_size1891=== CONT TestParseSingleRange/end_clamped_to_size1892=== CONT TestParseSingleRange/single_byte1893=== CONT TestParseSingleRange/start_past_EOF1894=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1895--- PASS: TestIsValidCachePath (0.00s)1896 --- PASS: TestIsValidCachePath/narinfo (0.00s)1897 --- PASS: TestIsValidCachePath/short_hash (0.00s)1898 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1899 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1900 --- PASS: TestIsValidCachePath/empty (0.00s)1901 --- PASS: TestIsValidCachePath/random_path (0.00s)1902 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1903 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1904 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1905 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1906 --- PASS: TestIsValidCachePath/index.html (0.00s)1907 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1908 --- PASS: TestIsValidCachePath/realisation (0.00s)1909 --- PASS: TestIsValidCachePath/log (0.00s)1910 --- PASS: TestIsValidCachePath/ls (0.00s)1911 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1912 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1913 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1914 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1915 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1916--- PASS: TestParseSingleRange (0.00s)1917 --- PASS: TestParseSingleRange/none (0.00s)1918 --- PASS: TestParseSingleRange/closed (0.00s)1919 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1920 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1921 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1922 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1923 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1924 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1925 --- PASS: TestParseSingleRange/open-ended (0.00s)1926 --- PASS: TestParseSingleRange/suffix (0.00s)1927 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1928 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1929 --- PASS: TestParseSingleRange/single_byte (0.00s)1930 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)19312026/10/14 16:46:42 WARN readiness check failed error="closed pool"1932--- PASS: TestService_readinessHandler (0.31s)1933=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1934--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.32s)1935=== CONT TestService_RequireScope_OIDC/builder_may_write1936=== CONT TestService_RequireScope_OIDC/writer_implies_read1937=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1938=== CONT TestService_RequireScope_OIDC/reader_may_read1939=== CONT TestService_RequireScope_OIDC/static_token_may_write1940=== CONT TestService_RequireScope_OIDC/static_token_may_admin1941=== CONT TestService_RequireScope_OIDC/reader_may_not_write1942=== CONT TestService_RequireScope_OIDC/ops_may_not_write1943=== CONT TestService_RequireScope_OIDC/ops_may_admin1944=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1945=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1946=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19472026/10/14 16:46:42 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]1948=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1949=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1950=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token19512026/10/14 16:46:42 INFO Received push request method=POST path=/api/pushes1952--- PASS: TestService_RequireScope_OIDC (0.37s)1953 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1954 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1955 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1956 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1957 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1958 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1959 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1960 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1961 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1962 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1963 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1964 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1965 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1966 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)19672026/10/14 16:46:42 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/present1968=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19692026/10/14 16:46:42 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]1970=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1971=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19722026/10/14 16:46:42 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19732026/10/14 16:46:42 INFO Uploading w3vlb0rgaiy3z21jgbf59f4v2fh44npp-file1.txt (160B)19742026/10/14 16:46:42 WARN Authentication failed token_preview=eyJhbGciOi...ukSKHO98mw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1975--- PASS: TestService_AuthMiddleware_OIDC (0.53s)1976 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1977 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1978 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1979 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)19802026/10/14 16:46:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19812026/10/14 16:46:42 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"19822026/10/14 16:46:42 WARN Failed to register uploaded object key=w3vlb0rgaiy3z21jgbf59f4v2fh44npp.ls error="server returned 404: 404 page not found\n"19832026/10/14 16:46:42 INFO Signed narinfos id=1 count=119842026/10/14 16:46:42 INFO Uploading 1 narinfos19852026/10/14 16:46:42 INFO Received complete push request method=POST path=/api/pushes/1/complete19862026/10/14 16:46:42 WARN Failed to register uploaded object key=w3vlb0rgaiy3z21jgbf59f4v2fh44npp.narinfo error="server returned 404: 404 page not found\n"19872026/10/14 16:46:42 INFO Received uploads request method=POST path=/api/pending_closures19882026/10/14 16:46:42 INFO Completed push id=1 objects=3 duration=6.490138ms19892026/10/14 16:46:42 INFO Upload complete. (60ms)1990=== NAME TestNARDeduplicationMetadataUploadBug1991 metadata_upload_test.go:54: Retrieved narinfo from S3:1992 StorePath: /build/TestNARDeduplicationMetadataUploadBug2633603674/001/store/w3vlb0rgaiy3z21jgbf59f4v2fh44npp-file1.txt1993 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1994 Compression: zstd1995 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1996 NarSize: 1601997 References: 1998 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1999 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2000 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2001 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}2002 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2633603674/001/store/zrlbrdc0n9kb21cimvdrm5p85ab3wias-file2.txt20032026/10/14 16:46:42 INFO Aborted multipart uploads count=0 kept=020042026/10/14 16:46:42 WARN Force mode enabled - objects will be deleted immediately without grace period20052026/10/14 16:46:42 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:33179/bucket93/?delete=\": context canceled"20062026/10/14 16:46:42 WARN Request failed, retrying attempt=2 backoff=202.747658ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20072026/10/14 16:46:42 INFO Aborted multipart uploads count=0 kept=020082026/10/14 16:46:42 WARN Force mode enabled - objects will be deleted immediately without grace period20092026/10/14 16:46:42 INFO Received uploads request method=POST path=/api/pending_closures20102026/10/14 16:46:42 INFO Aborted multipart uploads count=0 kept=02011--- PASS: TestGCEndsOnShutdown (0.00s)2012 --- PASS: TestGCEndsOnShutdown/before_the_run (0.34s)2013 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.37s)2014 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.40s)20152026/10/14 16:46:42 WARN Force mode enabled - objects will be deleted immediately without grace period20162026/10/14 16:46:42 INFO Received uploads request method=POST path=/api/pending_closures20172026/10/14 16:46:42 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=020182026/10/14 16:46:42 INFO Received push request method=POST path=/api/pushes20192026/10/14 16:46:42 INFO Vacuumed table table=pending_closures20202026/10/14 16:46:42 INFO Vacuumed table table=pending_objects20212026/10/14 16:46:42 INFO Vacuumed table table=multipart_uploads20222026/10/14 16:46:42 INFO Vacuumed table table=closures20232026/10/14 16:46:42 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)20242026/10/14 16:46:42 INFO Vacuumed table table=objects20252026/10/14 16:46:42 INFO Aborted multipart uploads count=0 kept=020262026/10/14 16:46:42 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign20272026/10/14 16:46:42 INFO Signed narinfos id=2 count=120282026/10/14 16:46:42 WARN Failed to register uploaded object key=zrlbrdc0n9kb21cimvdrm5p85ab3wias.ls error="server returned 404: 404 page not found\n"20292026/10/14 16:46:42 INFO Uploading 1 narinfos20302026/10/14 16:46:42 WARN Force mode enabled - objects will be deleted immediately without grace period2031=== NAME TestOrphanedObjectsGC2032 orphaned_objects_gc_test.go:287: GC Test Summary:20332026/10/14 16:46:42 INFO Received complete push request method=POST path=/api/pushes/2/complete2034 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A2035 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B2036 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)2037 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)2038 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects20392026/10/14 16:46:42 WARN Failed to register uploaded object key=zrlbrdc0n9kb21cimvdrm5p85ab3wias.narinfo error="server returned 404: 404 page not found\n"2040--- PASS: TestOrphanedObjectsGC (0.64s)20412026/10/14 16:46:42 INFO Completed push id=2 objects=3 duration=2.081079ms20422026/10/14 16:46:42 INFO Upload complete. (56ms)20432026/10/14 16:46:42 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=02044=== NAME TestNARDeduplicationMetadataUploadBug2045 metadata_upload_test.go:76: Retrieved narinfo from S3:2046 StorePath: /build/TestNARDeduplicationMetadataUploadBug2633603674/001/store/zrlbrdc0n9kb21cimvdrm5p85ab3wias-file2.txt2047 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2048 Compression: zstd2049 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2050 NarSize: 1602051 References: 2052 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf20532026/10/14 16:46:42 INFO Vacuumed table table=pending_closures2054 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2055 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2056 {"version":1,"root":{"type":"regular","size":44}}20572026/10/14 16:46:42 INFO Vacuumed table table=pending_objects20582026/10/14 16:46:42 INFO Vacuumed table table=multipart_uploads20592026/10/14 16:46:42 INFO Vacuumed table table=closures20602026/10/14 16:46:42 INFO Vacuumed table table=objects2061--- PASS: TestNARDeduplicationMetadataUploadBug (0.60s)2062--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2063 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.33s)2064 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.33s)20652026/10/14 16:46:42 WARN Request failed, retrying attempt=3 backoff=413.010889ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20662026/10/14 16:46:42 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20672026/10/14 16:46:42 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20682026/10/14 16:46:42 INFO lead: released remote=192.0.2.1:12342069--- PASS: TestLeadElectsOneAndHandsOver (2.96s)20702026/10/14 16:46:42 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020712026/10/14 16:46:42 INFO Received create pin request method=POST path=/api/pins/myapp20722026/10/14 16:46:42 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC455414320/001/store/s1x484pgnxjk7d85vnw5cq0pvsai7384-pinned-file.txt narinfo_key=s1x484pgnxjk7d85vnw5cq0pvsai7384.narinfo20732026/10/14 16:46:42 INFO Starting cleanup of old closures method=DELETE path=/api/closures20742026/10/14 16:46:42 INFO Garbage collection started20752026/10/14 16:46:42 INFO Aborted multipart uploads count=0 kept=020762026/10/14 16:46:42 WARN Force mode enabled - objects will be deleted immediately without grace period20772026/10/14 16:46:42 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=020782026/10/14 16:46:42 INFO Vacuumed table table=pending_closures20792026/10/14 16:46:42 INFO Vacuumed table table=pending_objects20802026/10/14 16:46:42 INFO Vacuumed table table=multipart_uploads20812026/10/14 16:46:42 INFO Vacuumed table table=closures20822026/10/14 16:46:42 INFO Vacuumed table table=objects20832026/10/14 16:46:42 WARN Request failed, retrying attempt=4 backoff=810.040484ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2084--- PASS: TestObjectStatsLargeCommit (1.21s)2085--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2086 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.75s)2087 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.84s)2088--- PASS: TestPendingClosureWriteTimeout (0.05s)2089 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2090 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2091 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2092 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.14s)2093--- PASS: TestUploadHandlersRejectOversizedBody (0.14s)2094 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)2095 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)2096 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.09s)2097=== NAME TestOrphanedObjectsGCStressTest2098 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2099 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion2100 orphaned_objects_gc_test.go:503: Stress test completed successfully:2101 orphaned_objects_gc_test.go:504: - Active objects preserved: 202102 orphaned_objects_gc_test.go:505: - Objects deleted: 2102103 orphaned_objects_gc_test.go:506: - Total GC'd: 2102104--- PASS: TestOrphanedObjectsGCStressTest (1.90s)21052026/10/14 16:46:43 WARN Request failed, retrying attempt=5 backoff=1.524291107s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21062026/10/14 16:46:43 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02107=== NAME TestClientIntegration2108 client_integration_test.go:323: Objects in database after GC:2109 client_integration_test.go:323: Successfully deleted all objects with GC --force2110--- PASS: TestClientIntegration (2.53s)2111=== NAME TestPinProtectsFromGC2112 client_integration_test.go:840: Pin successfully protected closure from garbage collection2113--- PASS: TestPinProtectsFromGC (4.94s)21142026/10/14 16:46:44 WARN Rate limiter enabled after throttle name=s3-test rate=521152026/10/14 16:46:44 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2116=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2117 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102118 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002119--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.08s)2120--- PASS: TestConnectWaitsForAPeerMigration (5.34s)21212026/10/14 16:46:45 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-config2122--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.54s)21232026/10/14 16:46:45 WARN Request failed, retrying attempt=2 backoff=201.861812ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21242026/10/14 16:46:45 WARN Request failed, retrying attempt=3 backoff=399.220355ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21252026/10/14 16:46:45 WARN Request failed, retrying attempt=4 backoff=733.576428ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21262026/10/14 16:46:46 WARN Request failed, retrying attempt=5 backoff=1.615196009s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21272026/10/14 16:46:47 INFO Aborted multipart uploads count=1 kept=021282026/10/14 16:46:47 INFO Received cleanup request method=DELETE path=/api/pending_closures21292026/10/14 16:46:47 INFO Aborted multipart uploads count=1 kept=02130--- PASS: TestPendingCleanupUsesOneCutoff (6.34s)21312026/10/14 16:46:48 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"21322026/10/14 16:46:48 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-config21332026/10/14 16:46:48 WARN Request failed, retrying attempt=2 backoff=182.424459ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21342026/10/14 16:46:48 WARN Request failed, retrying attempt=3 backoff=401.637462ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21352026/10/14 16:46:48 WARN Request failed, retrying attempt=4 backoff=775.43282ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21362026/10/14 16:46:49 WARN Request failed, retrying attempt=5 backoff=1.685721784s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21372026/10/14 16:46:51 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_closures21382026/10/14 16:46:51 WARN Request failed, retrying attempt=2 backoff=182.728295ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21392026/10/14 16:46:51 WARN Request failed, retrying attempt=3 backoff=372.342959ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21402026/10/14 16:46:51 WARN Request failed, retrying attempt=4 backoff=763.26857ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21412026/10/14 16:46:52 WARN Request failed, retrying attempt=5 backoff=1.454948886s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2142--- PASS: TestClientErrorHandling (0.00s)2143 --- PASS: TestClientErrorHandling/InvalidStorePath (0.31s)2144 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.49s)2145 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.26s)2146PASS21472026-10-14 16:46:54.518 UTC [128] LOG: received smart shutdown request21482026-10-14 16:46:54.523 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 121492026-10-14 16:46:54.533 UTC [133] LOG: shutting down21502026-10-14 16:46:54.534 UTC [133] LOG: checkpoint starting: shutdown immediate21512026-10-14 16:46:55.576 UTC [133] LOG: checkpoint complete: wrote 11496 buffers (70.2%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.199 s, sync=0.806 s, total=1.043 s; sync files=34045, longest=0.007 s, average=0.001 s; distance=531594 kB, estimate=531594 kB; lsn=0/21E88880, redo lsn=0/21E8888021522026-10-14 16:46:55.656 UTC [128] LOG: database system is shut down2153Running OIDC tests...2154=== RUN TestAudienceForIssuer2155=== PAUSE TestAudienceForIssuer2156=== RUN TestGlobMatch2157=== PAUSE TestGlobMatch2158=== RUN TestValidateToken_ValidToken2159=== PAUSE TestValidateToken_ValidToken2160=== RUN TestValidateToken_WrongAudience2161=== PAUSE TestValidateToken_WrongAudience2162=== RUN TestValidateToken_Expired2163=== PAUSE TestValidateToken_Expired2164=== RUN TestValidateToken_BoundClaimsMismatch2165=== PAUSE TestValidateToken_BoundClaimsMismatch2166=== RUN TestValidateToken_BoundSubjectMismatch2167=== PAUSE TestValidateToken_BoundSubjectMismatch2168=== RUN TestValidateToken_MultipleProviders2169=== PAUSE TestValidateToken_MultipleProviders2170=== RUN TestValidateToken_NoMatchingProvider2171=== PAUSE TestValidateToken_NoMatchingProvider2172=== RUN TestValidateToken_KubernetesServiceAccount2173=== PAUSE TestValidateToken_KubernetesServiceAccount2174=== RUN TestNewValidator_KubernetesRequiresCA2175=== PAUSE TestNewValidator_KubernetesRequiresCA2176=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2177=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2178=== RUN TestPins_ReservedForMatchingRule2179=== PAUSE TestPins_ReservedForMatchingRule2180=== RUN TestPins_TopLevelShorthand2181=== PAUSE TestPins_TopLevelShorthand2182=== RUN TestPins_ConfigValidation2183=== PAUSE TestPins_ConfigValidation2184=== RUN TestScopes_LegacyProviderDefaultsToWrite2185=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2186=== RUN TestScopes_Rules2187=== PAUSE TestScopes_Rules2188=== RUN TestScopes_ConfigValidation2189=== PAUSE TestScopes_ConfigValidation2190=== CONT TestAudienceForIssuer2191--- PASS: TestAudienceForIssuer (0.00s)2192=== CONT TestScopes_ConfigValidation2193=== CONT TestValidateToken_KubernetesServiceAccount2194=== CONT TestPins_TopLevelShorthand2195=== CONT TestValidateToken_BoundClaimsMismatch2196=== CONT TestPins_ConfigValidation2197=== CONT TestScopes_LegacyProviderDefaultsToWrite2198--- PASS: TestScopes_ConfigValidation (0.00s)2199=== CONT TestValidateToken_Expired2200--- PASS: TestPins_ConfigValidation (0.00s)2201=== CONT TestValidateToken_WrongAudience2202=== CONT TestValidateToken_ValidToken2203=== CONT TestGlobMatch2204=== RUN TestGlobMatch/foo_foo2205=== PAUSE TestGlobMatch/foo_foo2206=== RUN TestGlobMatch/foo_bar2207=== PAUSE TestGlobMatch/foo_bar2208=== RUN TestGlobMatch/*_2209=== PAUSE TestGlobMatch/*_2210=== RUN TestGlobMatch/*_anything2211=== PAUSE TestGlobMatch/*_anything2212=== RUN TestGlobMatch/foo*_foo2213=== PAUSE TestGlobMatch/foo*_foo2214=== RUN TestGlobMatch/foo*_foobar2215=== PAUSE TestGlobMatch/foo*_foobar2216=== RUN TestGlobMatch/foo*_bar2217=== PAUSE TestGlobMatch/foo*_bar2218=== CONT TestScopes_Rules2219=== CONT TestValidateToken_MultipleProviders2220=== CONT TestValidateToken_NoMatchingProvider2221=== CONT TestValidateToken_BoundSubjectMismatch2222=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2223=== CONT TestPins_ReservedForMatchingRule2224=== CONT TestNewValidator_KubernetesRequiresCA2225=== RUN TestGlobMatch/*bar_bar2226=== PAUSE TestGlobMatch/*bar_bar2227=== RUN TestGlobMatch/*bar_foobar2228=== PAUSE TestGlobMatch/*bar_foobar2229=== RUN TestGlobMatch/*bar_foo2230=== PAUSE TestGlobMatch/*bar_foo2231=== RUN TestGlobMatch/foo*bar_foobar2232=== PAUSE TestGlobMatch/foo*bar_foobar2233=== RUN TestGlobMatch/foo*bar_foo123bar2234=== PAUSE TestGlobMatch/foo*bar_foo123bar2235=== RUN TestGlobMatch/foo*bar_foobarbaz2236=== PAUSE TestGlobMatch/foo*bar_foobarbaz2237=== RUN TestGlobMatch/*/*_foo/bar2238=== PAUSE TestGlobMatch/*/*_foo/bar2239=== RUN TestGlobMatch/*/*_foo2240=== PAUSE TestGlobMatch/*/*_foo2241=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2242=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2243=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02244=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02245=== RUN TestGlobMatch/refs/*/main_refs/heads/main2246=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2247=== RUN TestGlobMatch/fo?_foo2248=== PAUSE TestGlobMatch/fo?_foo2249=== RUN TestGlobMatch/fo?_fo2250=== PAUSE TestGlobMatch/fo?_fo2251=== RUN TestGlobMatch/fo?_fooo2252=== PAUSE TestGlobMatch/fo?_fooo2253=== RUN TestGlobMatch/?oo_foo2254=== PAUSE TestGlobMatch/?oo_foo2255=== RUN TestGlobMatch/?oo_boo2256=== PAUSE TestGlobMatch/?oo_boo2257=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2258=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2259=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2260=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2261=== CONT TestGlobMatch/foo_foo2262=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2263=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2264=== CONT TestGlobMatch/?oo_boo2265=== CONT TestGlobMatch/?oo_foo2266=== CONT TestGlobMatch/fo?_fooo2267=== CONT TestGlobMatch/fo?_fo2268=== CONT TestGlobMatch/fo?_foo2269=== CONT TestGlobMatch/refs/*/main_refs/heads/main2270=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02271=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2272=== CONT TestGlobMatch/*/*_foo2273=== CONT TestGlobMatch/*/*_foo/bar2274=== CONT TestGlobMatch/foo*bar_foobarbaz2275=== CONT TestGlobMatch/foo*bar_foo123bar2276=== CONT TestGlobMatch/foo*bar_foobar2277=== CONT TestGlobMatch/*bar_foo2278=== CONT TestGlobMatch/*bar_foobar2279=== CONT TestGlobMatch/*bar_bar2280=== CONT TestGlobMatch/foo*_bar2281=== CONT TestGlobMatch/foo*_foobar2282=== CONT TestGlobMatch/foo*_foo2283=== CONT TestGlobMatch/*_anything2284=== CONT TestGlobMatch/*_2285=== CONT TestGlobMatch/foo_bar2286--- PASS: TestGlobMatch (0.01s)2287 --- PASS: TestGlobMatch/foo_foo (0.00s)2288 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2289 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2290 --- PASS: TestGlobMatch/?oo_boo (0.00s)2291 --- PASS: TestGlobMatch/?oo_foo (0.00s)2292 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2293 --- PASS: TestGlobMatch/fo?_fo (0.00s)2294 --- PASS: TestGlobMatch/fo?_foo (0.00s)2295 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2296 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2297 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2298 --- PASS: TestGlobMatch/*/*_foo (0.00s)2299 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2300 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2301 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2302 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2303 --- PASS: TestGlobMatch/*bar_foo (0.00s)2304 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2305 --- PASS: TestGlobMatch/*bar_bar (0.00s)2306 --- PASS: TestGlobMatch/foo*_bar (0.00s)2307 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2308 --- PASS: TestGlobMatch/foo*_foo (0.00s)2309 --- PASS: TestGlobMatch/*_anything (0.00s)2310 --- PASS: TestGlobMatch/*_ (0.00s)2311 --- PASS: TestGlobMatch/foo_bar (0.00s)23122026/10/14 16:46:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37373/oidc23132026/10/14 16:46:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33653/oidc2314--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.06s)2315--- PASS: TestValidateToken_BoundClaimsMismatch (0.06s)23162026/10/14 16:46:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41041/oidc23172026/10/14 16:46:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42795/oidc2318--- PASS: TestValidateToken_BoundSubjectMismatch (0.08s)2319--- PASS: TestPins_ReservedForMatchingRule (0.08s)23202026/10/14 16:46:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42105/oidc23212026/10/14 16:46:57 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:33737/oidc23222026/10/14 16:46:57 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:46433/oidc2323--- PASS: TestValidateToken_Expired (0.10s)2324--- PASS: TestValidateToken_MultipleProviders (0.10s)23252026/10/14 16:46:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33849/oidc2326--- PASS: TestScopes_Rules (0.12s)23272026/10/14 16:46:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37911/oidc2328--- PASS: TestValidateToken_ValidToken (0.14s)23292026/10/14 16:46:57 http: TLS handshake error from 127.0.0.1:53720: remote error: tls: bad certificate2330--- PASS: TestNewValidator_KubernetesRequiresCA (0.16s)23312026/10/14 16:46:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37489/oidc2332--- PASS: TestValidateToken_WrongAudience (0.21s)23332026/10/14 16:46:57 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:338432334--- PASS: TestValidateToken_KubernetesServiceAccount (0.27s)23352026/10/14 16:46:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46329/oidc2336--- PASS: TestPins_TopLevelShorthand (0.33s)23372026/10/14 16:46:57 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:37403/oidc2338--- PASS: TestValidateToken_NoMatchingProvider (0.40s)23392026/10/14 16:46:57 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232340--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.54s)2341PASS2342Running hook tests...2343=== RUN TestSendPathsEmpty2344=== PAUSE TestSendPathsEmpty2345=== RUN TestQueueEnqueueAndFetch2346=== PAUSE TestQueueEnqueueAndFetch2347=== RUN TestQueueDeduplication2348=== PAUSE TestQueueDeduplication2349=== RUN TestQueueRemove2350=== PAUSE TestQueueRemove2351=== RUN TestQueueFetchBatchLimit2352=== PAUSE TestQueueFetchBatchLimit2353=== RUN TestQueueRetryMovesToBack2354=== PAUSE TestQueueRetryMovesToBack2355=== RUN TestQueueFetchRemoveLifecycle2356=== PAUSE TestQueueFetchRemoveLifecycle2357=== RUN TestQueueConcurrentWriters2358=== PAUSE TestQueueConcurrentWriters2359=== RUN TestQueueRemoveLargeClosure2360=== PAUSE TestQueueRemoveLargeClosure2361=== RUN TestServerClientIntegration2362--- PASS: TestServerClientIntegration (0.00s)2363=== RUN TestServerQueueError23642026/10/14 16:46:58 ERROR Failed to queue paths error="permission denied" count=12365--- PASS: TestServerQueueError (0.00s)2366=== RUN TestGetListenerSocketActivation2367 server_test.go:219: === RUN TestGetListenerSocketActivation2368 --- PASS: TestGetListenerSocketActivation (0.00s)2369 PASS2370 2371--- PASS: TestGetListenerSocketActivation (0.01s)2372=== RUN TestDrainIsolatesPoisonPath2373=== PAUSE TestDrainIsolatesPoisonPath2374=== RUN TestRunNotBlockedByPoisonHead2375=== PAUSE TestRunNotBlockedByPoisonHead2376=== RUN TestDrainGivesUpWhenServerDown2377=== PAUSE TestDrainGivesUpWhenServerDown2378=== RUN TestFailedPathPrunedByLaterClosure2379=== PAUSE TestFailedPathPrunedByLaterClosure2380=== RUN TestWorkerUploadsAndRemoves2381=== PAUSE TestWorkerUploadsAndRemoves2382=== RUN TestWorkerSkipsGCdPaths2383=== PAUSE TestWorkerSkipsGCdPaths2384=== RUN TestWorkerPrunesClosureDeps2385=== PAUSE TestWorkerPrunesClosureDeps2386=== RUN TestDrainTimeout2387=== PAUSE TestDrainTimeout2388=== CONT TestSendPathsEmpty2389=== CONT TestWorkerPrunesClosureDeps2390--- PASS: TestSendPathsEmpty (0.00s)2391=== CONT TestDrainTimeout2392=== CONT TestWorkerUploadsAndRemoves2393=== CONT TestQueueFetchRemoveLifecycle2394=== CONT TestQueueRetryMovesToBack2395=== CONT TestQueueFetchBatchLimit2396=== CONT TestQueueRemove2397=== CONT TestQueueDeduplication2398=== CONT TestQueueEnqueueAndFetch2399=== CONT TestQueueConcurrentWriters2400=== CONT TestRunNotBlockedByPoisonHead2401=== CONT TestDrainIsolatesPoisonPath2402=== CONT TestFailedPathPrunedByLaterClosure2403=== CONT TestDrainGivesUpWhenServerDown2404=== CONT TestQueueRemoveLargeClosure2405=== CONT TestWorkerSkipsGCdPaths2406--- PASS: TestQueueRetryMovesToBack (0.01s)24072026/10/14 16:46:58 INFO Uploading batch count=224082026/10/14 16:46:58 INFO Upload queue status pending=224092026/10/14 16:46:58 INFO Upload queue status pending=32410--- PASS: TestQueueFetchRemoveLifecycle (0.01s)24112026/10/14 16:46:58 INFO Uploading batch count=12412--- PASS: TestQueueDeduplication (0.01s)24132026/10/14 16:46:58 INFO Uploading batch count=424142026/10/14 16:46:58 ERROR Upload failed error="upload failed" count=424152026/10/14 16:46:58 INFO Uploading batch count=124162026/10/14 16:46:58 ERROR Upload failed error="upload failed" count=12417--- PASS: TestQueueEnqueueAndFetch (0.01s)24182026/10/14 16:46:58 INFO Uploading batch count=124192026/10/14 16:46:58 ERROR Upload failed error="upload failed" count=124202026/10/14 16:46:58 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2677738051/002/bbb24212026/10/14 16:46:58 INFO Uploading batch count=224222026/10/14 16:46:58 ERROR Upload failed error="upload failed" count=224232026/10/14 16:46:58 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1387217276/002/a24242026/10/14 16:46:58 INFO Uploading batch count=124252026/10/14 16:46:58 INFO Upload queue status pending=22426--- PASS: TestQueueFetchBatchLimit (0.01s)24272026/10/14 16:46:58 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1387217276/002/b24282026/10/14 16:46:58 INFO Upload queue status pending=224292026/10/14 16:46:58 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths517868472/002/nonexistent24302026/10/14 16:46:58 INFO Uploading batch count=22431--- PASS: TestQueueRemove (0.01s)24322026/10/14 16:46:58 INFO Uploading batch count=124332026/10/14 16:46:58 INFO Uploading batch count=124342026/10/14 16:46:58 INFO Uploading batch count=224352026/10/14 16:46:58 ERROR Upload failed error="upload failed" count=224362026/10/14 16:46:58 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1387217276/002/c24372026/10/14 16:46:58 INFO Uploading batch count=124382026/10/14 16:46:58 ERROR Upload failed error="upload failed" count=124392026/10/14 16:46:58 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1387217276/002/d24402026/10/14 16:46:58 INFO Uploading batch count=124412026/10/14 16:46:58 ERROR Upload failed error="upload failed" count=124422026/10/14 16:46:58 INFO Uploading batch count=224432026/10/14 16:46:58 ERROR Upload failed error="upload failed" count=224442026/10/14 16:46:58 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1387217276/002/e2445--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)24462026/10/14 16:46:58 INFO Uploading batch count=124472026/10/14 16:46:58 ERROR Upload failed error="upload failed" count=124482026/10/14 16:46:58 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1387217276/002/f24492026/10/14 16:46:58 ERROR Drain finished with paths left in queue remaining=124502026/10/14 16:46:58 ERROR Drain finished with paths left in queue remaining=102451--- PASS: TestDrainIsolatesPoisonPath (0.01s)2452--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2453--- PASS: TestWorkerPrunesClosureDeps (0.03s)2454--- PASS: TestWorkerUploadsAndRemoves (0.03s)2455--- PASS: TestWorkerSkipsGCdPaths (0.03s)2456--- PASS: TestQueueRemoveLargeClosure (0.10s)2457--- PASS: TestQueueConcurrentWriters (0.12s)24582026/10/14 16:46:58 ERROR Upload failed error="context deadline exceeded" count=224592026/10/14 16:46:58 ERROR Drain finished with paths left in queue remaining=42460--- PASS: TestDrainTimeout (0.21s)24612026/10/14 16:46:59 INFO Uploading batch count=124622026/10/14 16:46:59 INFO Uploading batch count=124632026/10/14 16:46:59 INFO Uploading batch count=124642026/10/14 16:46:59 ERROR Upload failed error="upload failed" count=124652026/10/14 16:46:59 INFO Uploading batch count=124662026/10/14 16:46:59 ERROR Upload failed error="upload failed" count=124672026/10/14 16:46:59 INFO Uploading batch count=124682026/10/14 16:46:59 ERROR Upload failed error="upload failed" count=124692026/10/14 16:46:59 INFO Uploading batch count=124702026/10/14 16:46:59 ERROR Upload failed error="upload failed" count=124712026/10/14 16:46:59 ERROR Drain finished with paths left in queue remaining=12472--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2473PASS2474Running signing tests...2475=== RUN TestExternalSigner2476=== PAUSE TestExternalSigner2477=== RUN TestExternalSignerWrongPublicKey2478=== PAUSE TestExternalSignerWrongPublicKey2479=== RUN TestExternalSignerErrors2480=== PAUSE TestExternalSignerErrors2481=== RUN TestExternalSignerRestartsAfterCrash2482=== PAUSE TestExternalSignerRestartsAfterCrash2483=== RUN TestExternalSignerProgramErrorKeepsProcess2484=== PAUSE TestExternalSignerProgramErrorKeepsProcess2485=== RUN TestExternalSignerClose2486=== PAUSE TestExternalSignerClose2487=== RUN TestExternalSignerRejectsInvalidPublicKey2488=== PAUSE TestExternalSignerRejectsInvalidPublicKey2489=== RUN TestExternalSignerCancellation2490=== PAUSE TestExternalSignerCancellation2491=== RUN TestGenerateFingerprint2492=== PAUSE TestGenerateFingerprint2493=== RUN TestParseSigningKey2494=== PAUSE TestParseSigningKey2495=== RUN TestSign2496=== PAUSE TestSign2497=== RUN TestSignBatch2498=== PAUSE TestSignBatch2499=== RUN TestNilKeyPublicKey2500=== PAUSE TestNilKeyPublicKey2501=== RUN TestSignErrors2502=== PAUSE TestSignErrors2503=== CONT TestExternalSigner2504=== CONT TestParseSigningKey2505=== RUN TestParseSigningKey/valid_32-byte_key2506=== PAUSE TestParseSigningKey/valid_32-byte_key2507=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2508=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2509=== CONT TestSignBatch2510=== RUN TestParseSigningKey/no_colon2511=== PAUSE TestParseSigningKey/no_colon2512=== CONT TestSignErrors2513=== CONT TestExternalSignerClose2514=== RUN TestParseSigningKey/empty_name2515=== PAUSE TestParseSigningKey/empty_name2516=== RUN TestParseSigningKey/invalid_base642517=== PAUSE TestParseSigningKey/invalid_base642518=== RUN TestParseSigningKey/wrong_length2519=== PAUSE TestParseSigningKey/wrong_length2520=== CONT TestParseSigningKey/valid_32-byte_key2521=== CONT TestParseSigningKey/wrong_length2522=== CONT TestParseSigningKey/invalid_base642523=== CONT TestParseSigningKey/no_colon2524=== CONT TestGenerateFingerprint2525=== RUN TestGenerateFingerprint/basic_with_references2526=== PAUSE TestGenerateFingerprint/basic_with_references2527=== RUN TestGenerateFingerprint/no_references2528=== PAUSE TestGenerateFingerprint/no_references2529=== CONT TestExternalSignerCancellation2530=== CONT TestExternalSignerRejectsInvalidPublicKey2531=== RUN TestExternalSignerRejectsInvalidPublicKey/#002532=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002533=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2534=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2535=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2536=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2537=== CONT TestSign2538=== CONT TestExternalSignerRestartsAfterCrash2539=== CONT TestExternalSignerProgramErrorKeepsProcess2540=== CONT TestExternalSignerErrors2541=== CONT TestExternalSignerWrongPublicKey2542=== CONT TestNilKeyPublicKey2543=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2544=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2545=== RUN TestExternalSignerErrors/wrong_signatures_shape2546=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2547=== RUN TestExternalSignerErrors/wrong_signature_length2548=== PAUSE TestExternalSignerErrors/wrong_signature_length2549=== RUN TestExternalSignerErrors/program_error2550=== PAUSE TestExternalSignerErrors/program_error2551=== RUN TestExternalSignerErrors/exit_on_request2552=== PAUSE TestExternalSignerErrors/exit_on_request2553=== RUN TestExternalSignerErrors/null2554=== PAUSE TestExternalSignerErrors/null2555=== RUN TestExternalSignerErrors/missing_signatures2556=== PAUSE TestExternalSignerErrors/missing_signatures2557=== RUN TestExternalSignerErrors/unrequested_key2558=== PAUSE TestExternalSignerErrors/unrequested_key2559=== RUN TestExternalSignerErrors/exit_at_startup2560=== PAUSE TestExternalSignerErrors/exit_at_startup2561=== RUN TestExternalSignerErrors/invalid_JSON2562=== PAUSE TestExternalSignerErrors/invalid_JSON2563=== RUN TestExternalSignerErrors/wrong_shape2564=== CONT TestParseSigningKey/empty_name2565--- PASS: TestNilKeyPublicKey (0.00s)2566=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2567=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2568=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2569=== PAUSE TestExternalSignerErrors/wrong_shape2570=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2571=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2572=== RUN TestExternalSignerErrors/wrong_id2573=== PAUSE TestExternalSignerErrors/wrong_id2574=== RUN TestExternalSignerErrors/null_signatures2575=== PAUSE TestExternalSignerErrors/null_signatures2576=== RUN TestExternalSignerErrors/missing_signature_name2577=== PAUSE TestExternalSignerErrors/missing_signature_name2578=== RUN TestExternalSignerErrors/invalid_signature_base642579=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2580=== CONT TestExternalSignerRejectsInvalidPublicKey/#002581=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2582=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2583=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2584=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2585=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2586--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2587 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2588 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2589 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2590 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2591 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2592=== RUN TestGenerateFingerprint/invalid_nar_hash_length2593=== PAUSE TestExternalSignerErrors/invalid_signature_base642594=== RUN TestExternalSignerErrors/too_few_signatures2595=== PAUSE TestExternalSignerErrors/too_few_signatures2596=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2597=== RUN TestGenerateFingerprint/invalid_store_path_prefix2598=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2599=== RUN TestGenerateFingerprint/invalid_reference_prefix2600=== RUN TestExternalSignerErrors/wrong_signature_name2601=== PAUSE TestExternalSignerErrors/wrong_signature_name2602=== CONT TestExternalSignerErrors/wrong_signatures_shape2603=== CONT TestExternalSignerErrors/wrong_shape2604=== CONT TestExternalSignerErrors/missing_signatures2605=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2606=== CONT TestExternalSignerErrors/invalid_signature_base642607=== CONT TestExternalSignerErrors/null_signatures2608=== CONT TestExternalSignerErrors/wrong_signature_name2609=== CONT TestExternalSignerErrors/too_few_signatures2610=== CONT TestExternalSignerErrors/exit_at_startup2611=== CONT TestExternalSignerErrors/invalid_JSON2612=== CONT TestExternalSignerErrors/program_error2613=== CONT TestExternalSignerErrors/missing_signature_name2614=== CONT TestExternalSignerErrors/null2615=== CONT TestExternalSignerErrors/wrong_signature_length2616=== CONT TestExternalSignerErrors/unrequested_key2617=== CONT TestExternalSignerErrors/exit_on_request2618=== CONT TestExternalSignerErrors/wrong_id2619=== RUN TestSignErrors/nil_key2620=== PAUSE TestSignErrors/nil_key2621=== RUN TestSignErrors/nil_narinfo2622--- PASS: TestParseSigningKey (0.00s)2623 --- PASS: TestParseSigningKey/wrong_length (0.00s)2624 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2625 --- PASS: TestParseSigningKey/no_colon (0.00s)2626 --- PASS: TestParseSigningKey/empty_name (0.00s)2627 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2628 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2629--- PASS: TestSign (0.00s)2630=== PAUSE TestSignErrors/nil_narinfo2631=== RUN TestSignErrors/invalid_narinfo2632=== PAUSE TestSignErrors/invalid_narinfo2633=== RUN TestSignErrors/canceled2634=== PAUSE TestSignErrors/canceled2635--- PASS: TestSignBatch (0.00s)2636=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2637=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2638=== CONT TestGenerateFingerprint/basic_with_references2639=== CONT TestGenerateFingerprint/invalid_reference_prefix2640=== CONT TestGenerateFingerprint/invalid_nar_hash_length2641=== CONT TestGenerateFingerprint/invalid_store_path_prefix2642=== CONT TestSignErrors/nil_key2643=== CONT TestSignErrors/canceled2644=== CONT TestSignErrors/invalid_narinfo2645=== CONT TestSignErrors/nil_narinfo2646--- PASS: TestSignErrors (0.00s)2647 --- PASS: TestSignErrors/nil_key (0.00s)2648 --- PASS: TestSignErrors/canceled (0.00s)2649 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2650 --- PASS: TestSignErrors/nil_narinfo (0.00s)2651--- PASS: TestExternalSignerWrongPublicKey (0.00s)2652=== CONT TestGenerateFingerprint/no_references2653--- PASS: TestGenerateFingerprint (0.00s)2654 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2655 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2656 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2657 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2658 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2659 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2660 --- PASS: TestGenerateFingerprint/no_references (0.00s)2661--- PASS: TestExternalSignerClose (0.01s)2662--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2663--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2664--- PASS: TestExternalSigner (0.01s)2665--- PASS: TestExternalSignerErrors (0.00s)2666 --- PASS: TestExternalSignerErrors/null_signatures (0.00s)2667 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2668 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2669 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2670 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2671 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2672 --- PASS: TestExternalSignerErrors/null (0.01s)2673 --- PASS: TestExternalSignerErrors/program_error (0.01s)2674 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2675 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2676 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2677 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2678 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2679 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2680 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2681 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2682--- PASS: TestExternalSignerCancellation (0.02s)2683PASS2684Running OpenBao signer tests...2685=== RUN TestSign2686=== PAUSE TestSign2687=== RUN TestSignErrors2688=== PAUSE TestSignErrors2689=== RUN TestServe2690=== PAUSE TestServe2691=== RUN TestServeRejectsGarbage2692=== PAUSE TestServeRejectsGarbage2693=== CONT TestSign2694=== CONT TestServe2695=== CONT TestServeRejectsGarbage2696--- PASS: TestServeRejectsGarbage (0.00s)2697=== CONT TestSignErrors2698=== RUN TestSignErrors/http_error2699--- PASS: TestServe (0.00s)2700=== PAUSE TestSignErrors/http_error2701=== RUN TestSignErrors/invalid_json2702=== PAUSE TestSignErrors/invalid_json2703=== RUN TestSignErrors/no_prefix2704=== PAUSE TestSignErrors/no_prefix2705=== RUN TestSignErrors/invalid_base642706=== PAUSE TestSignErrors/invalid_base642707=== CONT TestSignErrors/http_error2708=== CONT TestSignErrors/invalid_base642709=== CONT TestSignErrors/no_prefix2710=== CONT TestSignErrors/invalid_json2711--- PASS: TestSign (0.00s)2712--- PASS: TestSignErrors (0.00s)2713 --- PASS: TestSignErrors/invalid_base64 (0.00s)2714 --- PASS: TestSignErrors/invalid_json (0.00s)2715 --- PASS: TestSignErrors/http_error (0.00s)2716 --- PASS: TestSignErrors/no_prefix (0.00s)2717PASS