niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #418
· 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.12s)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 TestScriptTokenEmptyCommand114--- PASS: TestScriptTokenEmptyCommand (0.00s)115=== CONT TestDoServerRequestAttachesToken116=== CONT TestResolveStorePath117=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer118=== CONT TestDoWithRetry_BodyReplayedViaGetBody119=== CONT TestScriptTokenScriptFails120=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess121--- PASS: TestResolveStorePath (0.00s)122=== CONT TestDumpPathSingleFile123=== CONT TestClientSignaturesByStorePath124=== CONT TestRateLimiterFeedback125=== CONT TestPathInfoCACompatibility126=== CONT TestStreamPushReportsSkippedPaths127=== CONT TestParsePathInfoJSONMultiplePaths128=== CONT TestParsePathInfoJSON129=== CONT TestStreamPushReportsSignatures130=== CONT TestPathInfoHashCompatibility131=== CONT TestGetStorePathHash132=== CONT TestStreamPushRequestLine133=== CONT TestConvertHashToNix32134=== CONT TestStreamPushGivesUpOnDeadServer135=== CONT TestEncodeNixBase32WithRealHash136=== CONT TestEncodeNixBase32137=== CONT TestStreamPushStopsWhenCanceled138=== CONT TestStreamPushIsolatesFailures139=== CONT TestDumpPathWriterError140=== CONT TestFileTokenReadsAndCaches1412026/10/20 10:59:29 WARN Rate limiter enabled after throttle name=server-test rate=5142=== RUN TestRateLimiterFeedback/429_enables_limiter143=== PAUSE TestRateLimiterFeedback/429_enables_limiter144=== RUN TestPathInfoCACompatibility/null_ca_field145=== PAUSE TestPathInfoCACompatibility/null_ca_field146=== RUN TestPathInfoCACompatibility/old_string_format_-_text1472026/10/20 10:59:29 ERROR Upload failed error="connection refused" count=20148=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text1492026/10/20 10:59:29 ERROR Server seems unavailable, giving up on batch untried=17150=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive151=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths152=== RUN TestRateLimiterFeedback/503_enables_limiter153--- PASS: TestScriptTokenScriptFails (0.00s)154=== RUN TestEncodeNixBase32/test_string_hash155=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive156=== CONT TestStreamPushBatchesUnderLoad157=== RUN TestParsePathInfoJSON/Nix_format158--- PASS: TestClientSignaturesByStorePath (0.00s)159=== PAUSE TestRateLimiterFeedback/503_enables_limiter160=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths161=== RUN TestPathInfoCACompatibility/new_structured_format_-_text162=== CONT TestDumpPathMatchesNix163=== RUN TestGetStorePathHash/valid_store_path164--- PASS: TestEncodeNixBase32WithRealHash (0.00s)1652026/10/20 10:59:29 ERROR Upload failed error="bad path" count=3166=== PAUSE TestEncodeNixBase32/test_string_hash1672026/10/20 10:59:29 WARN Rate limiter enabled after throttle name=server-test rate=5168=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths1692026/10/20 10:59:29 ERROR Upload failed error=boom count=1170=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths171=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text1722026/10/20 10:59:29 ERROR Upload failed error=boom count=11732026/10/20 10:59:29 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:35383174=== PAUSE TestGetStorePathHash/valid_store_path175=== CONT TestPartSizeForNAR176=== CONT TestSupersededNARStillUploadsListing177=== CONT TestSetClientTLSErrors178=== RUN TestPartSizeForNAR/zero_stays_at_minimum179--- PASS: TestStreamPushStopsWhenCanceled (0.00s)180=== PAUSE TestParsePathInfoJSON/Nix_format181=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter182=== RUN TestEncodeNixBase32/empty_input183=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)184=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)185=== CONT TestSetClientTLSDoesNotMutateDefaultTransport1862026/10/20 10:59:29 WARN Rate limiter backed off name=server-test rate=5187=== RUN TestConvertHashToNix32/SRI_format_to_Nix321882026/10/20 10:59:29 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:35383189=== CONT TestStaticToken190=== CONT TestUploadMultipart_SupersededByPeer191=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method192=== CONT TestUploadMultipart_PartsInParallel193=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum194=== RUN TestGetStorePathHash/basename_without_hyphen_should_error195--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)196=== RUN TestSupersededNARStillUploadsListing/small_NAR197=== RUN TestParsePathInfoJSON/Lix_format198=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter199=== PAUSE TestSupersededNARStillUploadsListing/small_NAR200=== PAUSE TestParsePathInfoJSON/Lix_format201=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon202=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon203=== CONT TestSetClientTLS204=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter205=== RUN TestSupersededNARStillUploadsListing/dump_cut_short206=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32207=== RUN TestConvertHashToNix32/already_Nix32_format208=== RUN TestParsePathInfoJSON/empty_input209=== CONT TestFilterOversizedClosures210=== RUN TestUploadMultipart_SupersededByPeer/exists211=== PAUSE TestUploadMultipart_SupersededByPeer/exists212=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method213=== CONT TestCaseHackSuffix214=== RUN TestPartSizeForNAR/small_stays_at_minimum215=== PAUSE TestPartSizeForNAR/small_stays_at_minimum216--- PASS: TestStreamPushReportsSkippedPaths (0.00s)217=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error218=== PAUSE TestEncodeNixBase32/empty_input219=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter220=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI221=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short222=== CONT TestScriptTokenCachesUntilRefresh223=== PAUSE TestConvertHashToNix32/already_Nix32_format224=== PAUSE TestParsePathInfoJSON/empty_input225=== RUN TestUploadMultipart_SupersededByPeer/missing226=== RUN TestSetClientTLSErrors/missing_cert_file227=== RUN TestFilterOversizedClosures/no_limit_keeps_everything228=== CONT TestStreamPushReportsEveryPath229=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun230--- PASS: TestStreamPushIsolatesFailures (0.00s)231=== CONT TestScriptTokenBadJSON232=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum233=== RUN TestConvertHashToNix32/invalid_format234=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error235=== CONT TestShellSplitErrors236=== PAUSE TestSetClientTLSErrors/missing_cert_file237--- PASS: TestStreamPushReportsSignatures (0.00s)238--- PASS: TestFileTokenReadsAndCaches (0.00s)239--- PASS: TestStaticToken (0.00s)240--- PASS: TestDoServerRequestAttachesToken (0.01s)241--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)242--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)243=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI244=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything245--- PASS: TestStreamPushReportsEveryPath (0.03s)246=== CONT TestScriptTokenEmptyToken247=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails248=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails249=== RUN TestParsePathInfoJSON/whitespace_only250=== PAUSE TestParsePathInfoJSON/whitespace_only251=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped252=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica253=== PAUSE TestUploadMultipart_SupersededByPeer/missing254=== RUN TestSetClientTLS/rejects_connection_without_client_cert255=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert256=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum257=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts258=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts259=== PAUSE TestConvertHashToNix32/invalid_format260=== RUN TestSetClientTLSErrors/missing_key_file261--- PASS: TestShellSplitErrors (0.00s)262=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA263=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512264=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512265=== RUN TestParsePathInfoJSON/invalid_JSON266=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry267=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped268=== RUN TestFilterOversizedClosures/all_closures_skipped269=== PAUSE TestFilterOversizedClosures/all_closures_skipped270=== CONT TestShellSplit271=== CONT TestFileTokenEmpty272=== CONT TestScriptTokenNoExpiryRerunsEveryCall273=== CONT TestFileTokenMissing274=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error275=== CONT TestDoWithRetry_FinalResponseBodyReadable2762026/10/20 10:59:29 INFO Garbage collection started277=== RUN TestPartSizeForNAR/1_TiB278=== CONT TestRegisterUploadedObjectReusesConnections279=== PAUSE TestSetClientTLSErrors/missing_key_file2802026/10/20 10:59:29 INFO Garbage collection started281=== RUN TestSetClientTLSErrors/missing_ca_file282=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA283=== RUN TestSetClientTLS/preserves_debug_logging_transport284=== PAUSE TestSetClientTLS/preserves_debug_logging_transport285=== CONT TestRetryTimeoutOutlastsMaxRetries286=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths287--- PASS: TestDumpPathSingleFile (0.04s)288--- PASS: TestScriptTokenBadJSON (0.01s)289--- PASS: TestShellSplit (0.00s)290--- PASS: TestFileTokenMissing (0.00s)291--- PASS: TestFileTokenEmpty (0.00s)292=== CONT TestPathInfoCACompatibility/null_ca_field293=== PAUSE TestParsePathInfoJSON/invalid_JSON294=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2952026/10/20 10:59:29 WARN Rate limiter enabled after throttle name=server-test rate=5296--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)297 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)298 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)299=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error300=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error3012026/10/20 10:59:29 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:44011302=== CONT TestPathInfoCACompatibility/new_structured_format_-_text303=== CONT TestPathInfoCACompatibility/old_string_format_-_text304=== CONT TestEncodeNixBase32/test_string_hash305=== PAUSE TestSetClientTLSErrors/missing_ca_file306=== RUN TestSetClientTLSErrors/invalid_ca_file3072026/10/20 10:59:29 WARN Rate limiter backed off name=server-test rate=5308=== PAUSE TestSetClientTLSErrors/invalid_ca_file309=== CONT TestRateLimiterFeedback/429_enables_limiter310=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter311=== CONT TestSupersededNARStillUploadsListing/small_NAR312=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method313=== CONT TestSupersededNARStillUploadsListing/dump_cut_short3142026/10/20 10:59:29 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:427413152026/10/20 10:59:29 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=03162026/10/20 10:59:29 INFO Uploading abc-hello (1.0GB)3172026/10/20 10:59:29 WARN Rate limiter enabled after throttle name=server-test rate=5318=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive319=== PAUSE TestPartSizeForNAR/1_TiB320=== CONT TestRateLimiterFeedback/503_enables_limiter321--- PASS: TestScriptTokenEmptyToken (0.00s)322=== CONT TestEncodeNixBase32/empty_input323--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.00s)324--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.04s)325=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter326=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails327--- PASS: TestEncodeNixBase32 (0.01s)328 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)329 --- PASS: TestEncodeNixBase32/empty_input (0.00s)3302026/10/20 10:59:29 WARN Rate limiter enabled after throttle name=s3-test rate=5331=== RUN TestPartSizeForNAR/5_TiB_S3_max_object3322026/10/20 10:59:29 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:43835333=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object334=== RUN TestPartSizeForNAR/capped_at_5_GiB335=== PAUSE TestPartSizeForNAR/capped_at_5_GiB336--- PASS: TestPathInfoCACompatibility (0.01s)337 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)338 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)339 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)340 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)341 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)342=== CONT TestConvertHashToNix32/SRI_format_to_Nix32343=== CONT TestConvertHashToNix32/invalid_format344=== CONT TestConvertHashToNix32/already_Nix32_format345--- PASS: TestConvertHashToNix32 (0.04s)346 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)347 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)348 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)349=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)3502026/10/20 10:59:29 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:37281351=== CONT TestUploadMultipart_SupersededByPeer/exists3522026/10/20 10:59:29 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:427413532026/10/20 10:59:29 WARN Rate limiter backed off name=server-test rate=53542026/10/20 10:59:29 WARN Rate limiter enabled after throttle name=server-test rate=5355=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI3562026/10/20 10:59:29 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:37569357=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon358=== CONT TestFilterOversizedClosures/all_closures_skipped359=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3602026/10/20 10:59:29 WARN Garbage collection finished on another replica. Its statistics are not available here361=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha5123622026/10/20 10:59:29 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=20003632026/10/20 10:59:29 INFO Uploading abc-hello (1.0GB)364=== CONT TestSetClientTLS/rejects_connection_without_client_cert3652026/10/20 10:59:29 WARN Rate limiter backed off name=server-test rate=5366=== CONT TestParsePathInfoJSON/Nix_format367=== CONT TestGetStorePathHash/valid_store_path368=== CONT TestParsePathInfoJSON/whitespace_only369=== CONT TestParsePathInfoJSON/empty_input370=== CONT TestParsePathInfoJSON/Lix_format371=== CONT TestSetClientTLSErrors/missing_cert_file372=== CONT TestUploadMultipart_SupersededByPeer/missing373=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error374=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error375=== CONT TestGetStorePathHash/basename_without_hyphen_should_error3762026/10/20 10:59:29 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=50377=== CONT TestSetClientTLSErrors/invalid_ca_file378=== CONT TestSetClientTLSErrors/missing_ca_file379=== CONT TestSetClientTLS/preserves_debug_logging_transport380=== CONT TestSetClientTLSErrors/missing_key_file381=== CONT TestPartSizeForNAR/5_TiB_S3_max_object382=== CONT TestPartSizeForNAR/capped_at_5_GiB383=== CONT TestPartSizeForNAR/1_TiB384=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts385=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum386=== CONT TestPartSizeForNAR/small_stays_at_minimum3872026/10/20 10:59:29 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:42741388--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.27s)389=== CONT TestPartSizeForNAR/zero_stays_at_minimum390=== CONT TestFilterOversizedClosures/no_limit_keeps_everything391--- PASS: TestPathInfoHashCompatibility (0.04s)392 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)393 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)394 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)395 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)396--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.27s)397--- PASS: TestRateLimiterFeedback (0.01s)398 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.27s)399 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.27s)400 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)401 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)402--- PASS: TestGetStorePathHash (0.04s)403 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)404 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)405 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)406 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)407--- PASS: TestFilterOversizedClosures (0.04s)408 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)409 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)410 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)411=== CONT TestParsePathInfoJSON/invalid_JSON412=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA413--- PASS: TestUploadMultipart_SupersededByPeer (0.04s)414 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)415 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)416--- PASS: TestSetClientTLSErrors (0.04s)417 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)418 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)419 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)420 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)421--- PASS: TestParsePathInfoJSON (0.04s)422 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)423 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)424 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)425 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)426 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)427--- PASS: TestPartSizeForNAR (0.31s)428 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)429 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)430 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)431 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)432 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)433 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)434 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)4352026/10/20 10:59:29 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:42741436--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.27s)4372026/10/20 10:59:29 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:42741438--- PASS: TestScriptTokenCachesUntilRefresh (0.31s)439--- PASS: TestCaseHackSuffix (0.31s)4402026/10/20 10:59:29 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:427414412026/10/20 10:59:29 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:427414422026/10/20 10:59:29 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:427414432026/10/20 10:59:29 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:427414442026/10/20 10:59:29 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:427414452026/10/20 10:59:29 http: TLS handshake error from 127.0.0.1:51942: remote error: tls: bad certificate446--- PASS: TestSetClientTLS (0.04s)447 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)448 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)449 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)4502026/10/20 10:59:29 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:427414512026/10/20 10:59:29 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:42741452--- PASS: TestRegisterUploadedObjectReusesConnections (0.28s)4532026/10/20 10:59:29 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:42741454--- PASS: TestStreamPushRequestLine (0.33s)4552026/10/20 10:59:29 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:427414562026/10/20 10:59:29 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:427414572026/10/20 10:59:29 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:427414582026/10/20 10:59:29 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:427414592026/10/20 10:59:29 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:427414602026/10/20 10:59:29 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:42741461--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.29s)462--- PASS: TestDumpPathWriterError (0.34s)4632026/10/20 10:59:29 INFO Uploading abc-hello (1.0GB)464--- PASS: TestStreamPushBatchesUnderLoad (0.37s)465--- PASS: TestDumpPathMatchesNix (0.37s)4662026/10/20 10:59:29 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:42915/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:42915/part/24672026/10/20 10:59:29 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"468--- PASS: TestSupersededNARStillUploadsListing (0.04s)469 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.27s)470 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.00s)471 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.82s)472--- PASS: TestUploadMultipart_PartsInParallel (0.91s)4732026/10/20 10:59:30 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:45053/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:45053/api/uploads/complete4742026/10/20 10:59:30 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4752026/10/20 10:59:30 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:45053/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:45053/api/uploads/complete4762026/10/20 10:59:30 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4772026/10/20 10:59:30 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:45053/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:45053/api/uploads/complete4782026/10/20 10:59:30 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"479--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)480--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (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/postgres1801190698/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/postgres1801190698/data -l logfile start509510/build/postgres1801190698:5432 - no response5112026-10-20 10:59:31.063 UTC [127] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit5122026-10-20 10:59:31.063 UTC [127] LOG: listening on Unix socket "/build/postgres1801190698/.s.PGSQL.5432"5132026-10-20 10:59:31.067 UTC [134] LOG: database system was shut down at 2026-10-20 10:59:30 UTC5142026-10-20 10:59:31.070 UTC [127] LOG: database system is ready to accept connections515/build/postgres1801190698: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/20 10:59:31 INFO lead: acquired remote=192.0.2.1:12345642026/10/20 10:59:32 INFO lead: released remote=192.0.2.1:12345652026/10/20 10:59:32 INFO lead: acquired remote=192.0.2.1:12345662026/10/20 10:59:33 INFO lead: released remote=192.0.2.1:1234567--- PASS: TestLeadIncumbentWinsAfterRestart (1.83s)568=== RUN TestLeadIncumbentAnnouncesAtOnce569=== PAUSE TestLeadIncumbentAnnouncesAtOnce570=== RUN TestLeadEndsOnShutdown571=== PAUSE TestLeadEndsOnShutdown572=== RUN TestLeadEndsWhenItsConnectionHangs5732026/10/20 10:59:33 INFO lead: acquired remote=192.0.2.1:12345742026-10-20 10:59:34.704 UTC [380] FATAL: terminating connection due to administrator command5752026/10/20 10:59:34 INFO lead: acquired remote=192.0.2.1:12345762026/10/20 10:59:35 WARN lead: lock connection lost error="timeout: context deadline exceeded"5772026/10/20 10:59:35 INFO lead: released remote=192.0.2.1:12345782026/10/20 10:59:36 INFO lead: released remote=192.0.2.1:1234579--- PASS: TestLeadEndsWhenItsConnectionHangs (3.10s)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/20 10:59:36 INFO Starting HTTP server address=127.0.0.1:339376802026/10/20 10:59:36 INFO Starting HTTP server address=proxy.sock6812026/10/20 10:59:36 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6822026/10/20 10:59:36 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/20 10:59:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7522026/10/20 10:59:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7532026/10/20 10:59:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7542026/10/20 10:59:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7552026/10/20 10:59:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7562026/10/20 10:59:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7572026/10/20 10:59:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7582026/10/20 10:59:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7592026/10/20 10:59:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7602026/10/20 10:59:36 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 TestParseSize785=== CONT TestCompletedNarNotReofferedAcrossClosures786=== CONT TestPush_RepeatedRootCommitsOnce787=== CONT TestGCAdvisoryLockBlocksConcurrentRun788=== CONT TestGCTaskStore_Fail789=== CONT TestPushWaitsForSweepHoldingRow790=== CONT TestPresignedUploadRegisteredBeforeCommit791=== CONT TestCompleteMultipartUpload_ErrorButObjectExists792=== CONT TestRedundantMultipartUpload793=== CONT TestPush_SignsNarinfosOfItsPendingObjects794=== CONT TestPush_RejectsBadRequests795=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit796=== CONT TestPush_RootsAreLockedInByteOrder797=== CONT TestPush_CompleteWaitsForCleanupOfThePush798=== CONT TestGCTaskStore_PhaseUpdates799=== CONT TestSweepRechecksPendingAfterLocking800=== CONT TestGCTaskStore_CompletedAllowsNewTask801=== CONT TestGetExistingObjectsLocksRows802=== CONT TestGCTaskStore_GetReturnsLatest803=== CONT TestRegisterCompletedObjectNeedsPendingRow804=== CONT TestGCTaskStore_GetEmpty805=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT806=== CONT TestGCTaskStore_ConflictDifferentParams807=== CONT TestSweepSkipsRowsLockedByPush808=== CONT TestGCTaskStore_DeduplicateSameParams809=== CONT TestCompleteMultipartUnregistered810=== CONT TestGCTaskStore_StartNew811=== CONT TestFailedS3DeleteKeepsTombstone812=== CONT TestGCEndsOnShutdown813=== RUN TestGCEndsOnShutdown/before_the_run814=== PAUSE TestGCEndsOnShutdown/before_the_run815=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete816=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete817=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark818=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark819=== CONT TestService_verifyS3Integrity820=== CONT TestCommitRacingPendingCleanupKeepsObjects821=== CONT TestUploadHandlersRejectOversizedBody822--- PASS: TestParseSize (0.00s)823=== CONT TestService_AuthMiddleware824=== CONT TestService_Rustfstest825--- PASS: TestGCTaskStore_Fail (0.00s)826--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)827--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)828--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)829--- PASS: TestGCTaskStore_GetEmpty (0.00s)830--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)831--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)832--- PASS: TestGCTaskStore_StartNew (0.00s)833=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure834=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure835=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart836=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart837=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts838=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts839=== CONT TestUploadHandlersRejectInvalidKeys840=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info841=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info842=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal843=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal844=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key845=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key846=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key847=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key848=== CONT TestService_createPendingClosureHandler8492026/10/20 10:59:36 INFO Received push request method=POST path=/api/pushes8502026/10/20 10:59:36 INFO Received uploads request method=POST path=/api/pending_closures8512026/10/20 10:59:36 INFO Received complete push request method=POST path=/api/pushes/1/complete8522026/10/20 10:59:36 INFO Completed push id=1 objects=4 duration=9.163963ms853--- PASS: TestPush_RepeatedRootCommitsOnce (0.31s)854=== CONT TestIsValidUploadKey855=== RUN TestIsValidUploadKey/narinfo856=== PAUSE TestIsValidUploadKey/narinfo857=== RUN TestIsValidUploadKey/nar_zst858=== PAUSE TestIsValidUploadKey/nar_zst859=== RUN TestIsValidUploadKey/nar_xz860=== PAUSE TestIsValidUploadKey/nar_xz861=== RUN TestIsValidUploadKey/nar_plain862=== PAUSE TestIsValidUploadKey/nar_plain863=== RUN TestIsValidUploadKey/listing864=== PAUSE TestIsValidUploadKey/listing865=== RUN TestIsValidUploadKey/build_log866=== PAUSE TestIsValidUploadKey/build_log867=== RUN TestIsValidUploadKey/build_log_home-manager_file868=== PAUSE TestIsValidUploadKey/build_log_home-manager_file869=== RUN TestIsValidUploadKey/build_log_plus_in_name870=== PAUSE TestIsValidUploadKey/build_log_plus_in_name871=== RUN TestIsValidUploadKey/build_log_question_mark872=== PAUSE TestIsValidUploadKey/build_log_question_mark873=== RUN TestIsValidUploadKey/build_log_equals874=== PAUSE TestIsValidUploadKey/build_log_equals875=== RUN TestIsValidUploadKey/realisation876=== PAUSE TestIsValidUploadKey/realisation877=== RUN TestIsValidUploadKey/realisation_plus_in_output878=== PAUSE TestIsValidUploadKey/realisation_plus_in_output879=== RUN TestIsValidUploadKey/nix-cache-info880=== PAUSE TestIsValidUploadKey/nix-cache-info881=== RUN TestIsValidUploadKey/index.html882=== PAUSE TestIsValidUploadKey/index.html883=== RUN TestIsValidUploadKey/narinfo_key,_nar_type884=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type885=== RUN TestIsValidUploadKey/nar_key,_narinfo_type886=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type887=== RUN TestIsValidUploadKey/listing_key,_narinfo_type888=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type889=== RUN TestIsValidUploadKey/traversal890=== PAUSE TestIsValidUploadKey/traversal891=== RUN TestIsValidUploadKey/traversal_nar892=== PAUSE TestIsValidUploadKey/traversal_nar893=== RUN TestIsValidUploadKey/absolute894=== PAUSE TestIsValidUploadKey/absolute895=== RUN TestIsValidUploadKey/empty_key896=== PAUSE TestIsValidUploadKey/empty_key897=== RUN TestIsValidUploadKey/unknown_type898=== PAUSE TestIsValidUploadKey/unknown_type899=== CONT TestService_cleanupPendingClosuresHandler900=== RUN TestPush_RejectsBadRequests/no_roots901=== PAUSE TestPush_RejectsBadRequests/no_roots902=== RUN TestPush_RejectsBadRequests/no_objects903=== PAUSE TestPush_RejectsBadRequests/no_objects904=== RUN TestPush_RejectsBadRequests/bad_root905=== PAUSE TestPush_RejectsBadRequests/bad_root906=== RUN TestPush_RejectsBadRequests/root_not_in_objects907=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects908=== CONT TestPendingClosureWriteTimeout909=== RUN TestPendingClosureWriteTimeout/empty910=== PAUSE TestPendingClosureWriteTimeout/empty911=== RUN TestPendingClosureWriteTimeout/400_objects912=== PAUSE TestPendingClosureWriteTimeout/400_objects913=== RUN TestPendingClosureWriteTimeout/670k_objects914=== PAUSE TestPendingClosureWriteTimeout/670k_objects915=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline916=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline917=== CONT TestClientWithDependencies9182026/10/20 10:59:36 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"919--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.34s)920=== CONT TestLeadEndsOnShutdown9212026/10/20 10:59:36 INFO Received uploads request method=POST path=/api/pending_closures9222026/10/20 10:59:37 INFO Received uploads request method=POST path=/api/pending_closures9232026/10/20 10:59:37 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9242026/10/20 10:59:37 INFO Received uploads request method=POST path=/api/pending_closures925--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.38s)926=== CONT TestLeadIncumbentAnnouncesAtOnce9272026/10/20 10:59:37 INFO Received push request method=POST path=/api/pushes9282026/10/20 10:59:37 INFO Received complete push request method=POST path=/api/pushes/1/complete9292026/10/20 10:59:37 INFO Completed push id=1 objects=4 duration=8.554957ms9302026/10/20 10:59:37 INFO Received push request method=POST path=/api/pushes9312026/10/20 10:59:37 INFO Aborted multipart uploads count=0 kept=09322026/10/20 10:59:37 INFO Received uploads request method=POST path=/api/pending_closures9332026/10/20 10:59:37 WARN Force mode enabled - objects will be deleted immediately without grace period9342026/10/20 10:59:37 INFO Received uploads request method=POST path=/api/pending_closures9352026/10/20 10:59:37 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=09362026/10/20 10:59:37 INFO Vacuumed table table=pending_closures9372026/10/20 10:59:37 INFO Received push request method=POST path=/api/pushes9382026/10/20 10:59:37 INFO Vacuumed table table=pending_objects9392026/10/20 10:59:37 INFO Vacuumed table table=multipart_uploads9402026/10/20 10:59:37 INFO Vacuumed table table=closures9412026/10/20 10:59:37 INFO Vacuumed table table=objects942--- PASS: TestSweepRechecksPendingAfterLocking (0.45s)943=== CONT TestProxyWriteTimeout944=== RUN TestProxyWriteTimeout/narinfo945=== PAUSE TestProxyWriteTimeout/narinfo946=== RUN TestProxyWriteTimeout/1_GiB_nar947=== PAUSE TestProxyWriteTimeout/1_GiB_nar948=== RUN TestProxyWriteTimeout/10_GiB_nar949=== PAUSE TestProxyWriteTimeout/10_GiB_nar950=== RUN TestProxyWriteTimeout/unknown_size951=== PAUSE TestProxyWriteTimeout/unknown_size952=== CONT TestLeadElectsOneAndHandsOver9532026/10/20 10:59:37 INFO Received uploads request method=POST path=/api/pending_closures9542026/10/20 10:59:37 INFO Aborted multipart uploads count=0 kept=09552026/10/20 10:59:37 WARN Force mode enabled - objects will be deleted immediately without grace period9562026/10/20 10:59:37 INFO Received push request method=POST path=/api/pushes9572026/10/20 10:59:37 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=09582026/10/20 10:59:37 INFO Vacuumed table table=pending_closures9592026/10/20 10:59:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9602026/10/20 10:59:37 INFO Vacuumed table table=pending_objects9612026/10/20 10:59:37 INFO Vacuumed table table=multipart_uploads9622026/10/20 10:59:37 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjZlNTUxOTMtNDc4ZS00NDZmLWEwNjItZTRmYzI5MDUwM2QxLjgyYTJiODdlLTc5MzMtNDBhMC1hNmEwLTAwMWQ3YWM2ZTAwMHgxNzkyNDkzOTc3MTAxMTUyMzMz9632026/10/20 10:59:37 INFO Vacuumed table table=closures9642026/10/20 10:59:37 INFO Vacuumed table table=objects9652026/10/20 10:59:37 INFO Received complete push request method=POST path=/api/pushes/2/complete9662026/10/20 10:59:37 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjZlNTUxOTMtNDc4ZS00NDZmLWEwNjItZTRmYzI5MDUwM2QxLjgyYTJiODdlLTc5MzMtNDBhMC1hNmEwLTAwMWQ3YWM2ZTAwMHgxNzkyNDkzOTc3MTAxMTUyMzMz parts=19672026/10/20 10:59:37 INFO Completed push id=2 objects=4 duration=2.675424ms968--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.50s)969=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle970--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.51s)971=== CONT TestConnectWaitsForAPeerMigration9722026/10/20 10:59:37 INFO Received uploads request method=POST path=/api/pending_closures973--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.51s)974=== CONT TestSkippedUploadsHandler9752026/10/20 10:59:37 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000976--- PASS: TestSkippedUploadsHandler (0.00s)977=== CONT TestForceGCDuringPushOffersSweptObject978=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows979=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows980=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check981=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check982=== CONT TestResolveDBConnectionString983=== RUN TestResolveDBConnectionString/flag_wins984=== PAUSE TestResolveDBConnectionString/flag_wins985=== RUN TestResolveDBConnectionString/file_when_flag_empty986=== PAUSE TestResolveDBConnectionString/file_when_flag_empty987=== RUN TestResolveDBConnectionString/missing_file_is_an_error988=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error989=== RUN TestResolveDBConnectionString/PGHOST_allows_empty990=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty991=== RUN TestResolveDBConnectionString/nothing_configured992=== PAUSE TestResolveDBConnectionString/nothing_configured993=== CONT TestCacheConfigHandler994=== RUN TestCacheConfigHandler/full_config,_no_issuer995=== PAUSE TestCacheConfigHandler/full_config,_no_issuer996=== RUN TestCacheConfigHandler/no_cache_url_configured997=== PAUSE TestCacheConfigHandler/no_cache_url_configured998=== RUN TestCacheConfigHandler/no_signing_keys999=== PAUSE TestCacheConfigHandler/no_signing_keys1000=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1001=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1002=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock10032026-10-20 10:59:37.150 UTC [517] ERROR: could not obtain lock on row in relation "closures"10042026-10-20 10:59:37.150 UTC [517] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10052026-10-20 10:59:37.151 UTC [517] ERROR: could not obtain lock on row in relation "closures"10062026-10-20 10:59:37.151 UTC [517] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10072026-10-20 10:59:37.151 UTC [517] ERROR: could not obtain lock on row in relation "closures"10082026-10-20 10:59:37.151 UTC [517] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10092026-10-20 10:59:37.151 UTC [517] ERROR: could not obtain lock on row in relation "closures"10102026-10-20 10:59:37.151 UTC [517] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10112026-10-20 10:59:37.151 UTC [517] ERROR: could not obtain lock on row in relation "closures"10122026-10-20 10:59:37.151 UTC [517] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1013--- PASS: TestPush_RootsAreLockedInByteOrder (0.53s)1014=== CONT TestDeduplicatedObjectsRecordedAsPending10152026/10/20 10:59:37 INFO Received uploads request method=POST path=/api/pending_closures10162026/10/20 10:59:37 INFO Received push request method=POST path=/api/pushes10172026/10/20 10:59:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10182026/10/20 10:59:37 INFO Signed narinfos id=1 count=110192026/10/20 10:59:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10202026/10/20 10:59:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10212026/10/20 10:59:37 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"10222026/10/20 10:59:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10232026/10/20 10:59:37 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"10242026/10/20 10:59:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10252026/10/20 10:59:37 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=110262026/10/20 10:59:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10272026/10/20 10:59:37 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1028--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.59s)1029=== CONT TestDeleteClosuresRacingPins10302026/10/20 10:59:37 INFO Aborted multipart uploads count=0 kept=010312026/10/20 10:59:37 WARN Force mode enabled - objects will be deleted immediately without grace period1032--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.59s)1033=== CONT TestPushDedupSurvivesConcurrentGC10342026/10/20 10:59:37 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=010352026/10/20 10:59:37 INFO Vacuumed table table=pending_closures10362026/10/20 10:59:37 INFO Vacuumed table table=pending_objects10372026/10/20 10:59:37 INFO Vacuumed table table=multipart_uploads10382026/10/20 10:59:37 INFO Aborted multipart uploads count=0 kept=010392026/10/20 10:59:37 INFO Vacuumed table table=closures10402026/10/20 10:59:37 INFO Vacuumed table table=objects10412026/10/20 10:59:37 WARN Force mode enabled - objects will be deleted immediately without grace period1042--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.61s)1043=== CONT TestClientMultipleUploads10442026/10/20 10:59:37 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."10452026/10/20 10:59:37 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1046--- PASS: TestFailedS3DeleteKeepsTombstone (0.62s)1047=== CONT TestGCMetrics10482026/10/20 10:59:37 INFO Aborted multipart uploads count=0 kept=010492026/10/20 10:59:37 INFO Received uploads request method=POST path=/api/pending_closures10502026/10/20 10:59:37 WARN Force mode enabled - objects will be deleted immediately without grace period10512026/10/20 10:59:37 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=010522026/10/20 10:59:37 INFO Vacuumed table table=pending_closures10532026/10/20 10:59:37 INFO Vacuumed table table=pending_objects10542026/10/20 10:59:37 INFO Vacuumed table table=multipart_uploads10552026/10/20 10:59:37 INFO Vacuumed table table=closures10562026/10/20 10:59:37 INFO Vacuumed table table=objects10572026/10/20 10:59:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10582026/10/20 10:59:37 INFO Aborted multipart uploads count=0 kept=010592026/10/20 10:59:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10602026/10/20 10:59:37 WARN Force mode enabled - objects will be deleted immediately without grace period10612026/10/20 10:59:37 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1062--- PASS: TestCompleteMultipartUnregistered (0.66s)1063=== CONT TestGCSweepSkipsPendingObjects10642026/10/20 10:59:37 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NjZlNTUxOTMtNDc4ZS00NDZmLWEwNjItZTRmYzI5MDUwM2QxLjI0OTE2Y2UwLTQ5NDQtNDQzZC04NDY5LWYxNmQxMjljMzhlZHgxNzkyNDkzOTc2OTM1NTY0OTQ1 parts=1210652026/10/20 10:59:37 INFO Received uploads request method=POST path=/api/pending_closures1066--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.68s)1067=== CONT TestClientIntegration10682026/10/20 10:59:37 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=010692026/10/20 10:59:37 INFO Vacuumed table table=pending_closures10702026/10/20 10:59:37 INFO Vacuumed table table=pending_objects10712026/10/20 10:59:37 INFO Vacuumed table table=multipart_uploads10722026/10/20 10:59:37 INFO Vacuumed table table=closures10732026/10/20 10:59:37 INFO Vacuumed table table=objects1074--- PASS: TestSweepSkipsRowsLockedByPush (0.69s)1075=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1076--- PASS: TestGetExistingObjectsLocksRows (0.70s)1077=== CONT TestClientErrorHandling1078=== RUN TestClientErrorHandling/InvalidStorePath1079=== PAUSE TestClientErrorHandling/InvalidStorePath1080=== RUN TestClientErrorHandling/InvalidAuthToken1081=== PAUSE TestClientErrorHandling/InvalidAuthToken1082=== RUN TestClientErrorHandling/ServerNotAvailable1083=== PAUSE TestClientErrorHandling/ServerNotAvailable1084=== CONT TestClientCADerivations1085--- PASS: TestService_Rustfstest (0.64s)1086=== CONT TestCacheStatsHandler10872026/10/20 10:59:37 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1088--- PASS: TestService_AuthMiddleware (0.66s)1089=== CONT TestGCSweepDeliversEachKeyOnce10902026/10/20 10:59:37 INFO Received uploads request method=POST path=/api/pending_closures10912026/10/20 10:59:37 INFO Received uploads request method=POST path=/api/pending_closures10922026/10/20 10:59:37 INFO Received uploads request method=POST path=/api/pending_closures10932026-10-20 10:59:37.388 UTC [502] ERROR: Push does not exist: id=110942026-10-20 10:59:37.388 UTC [502] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE10952026-10-20 10:59:37.388 UTC [502] STATEMENT: SELECT commit_push($1)1096--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.76s)1097=== CONT TestService_AuthMiddleware_OIDC10982026/10/20 10:59:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10992026/10/20 10:59:37 INFO Received cleanup request method=DELETE path=/api/pending_closures11002026/10/20 10:59:37 INFO Aborted multipart uploads count=0 kept=011012026/10/20 10:59:37 INFO Received uploads request method=POST path=/api/pending_closures11022026/10/20 10:59:37 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NjZlNTUxOTMtNDc4ZS00NDZmLWEwNjItZTRmYzI5MDUwM2QxLjNiM2JiMjUyLWU5NzAtNDc1OC1hMzMwLTNiOTgxMzJkYTIzM3gxNzkyNDkzOTc3MDY0MTU2MTYx parts=1211032026/10/20 10:59:37 INFO Received uploads request method=POST path=/api/pending_closures11042026/10/20 10:59:37 INFO Received cleanup request method=DELETE path=/api/pending_closures11052026/10/20 10:59:37 INFO Aborted multipart uploads count=1 kept=011062026/10/20 10:59:37 INFO Received uploads request method=POST path=/api/pending_closures11072026/10/20 10:59:37 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11082026-10-20 10:59:37.446 UTC [495] ERROR: Closure does not exist: id=111092026-10-20 10:59:37.446 UTC [495] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE11102026-10-20 10:59:37.446 UTC [495] STATEMENT: -- name: CommitPendingClosure :one1111 SELECT commit_pending_closure($1::bigint)::bigint1112 1113--- PASS: TestService_cleanupPendingClosuresHandler (0.51s)1114=== CONT TestTombstonedObjectOfferedWithoutWaiting11152026/10/20 10:59:37 INFO lead: acquired remote=192.0.2.1:123411162026/10/20 10:59:37 INFO lead: acquired remote=192.0.2.1:123411172026/10/20 10:59:37 INFO lead: released remote=192.0.2.1:12341118--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.47s)1119=== CONT TestGCBugBareHashReferences1120=== NAME TestClientWithDependencies1121 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies16720165/001/store/j1ipgpqcayigqpnzscg7mrl035vszz7q-test-script1122--- PASS: TestPushWaitsForSweepHoldingRow (0.88s)1123=== CONT TestService_ReadScope_PublicByDefault11242026/10/20 10:59:37 INFO lead: acquired remote=192.0.2.1:123411252026/10/20 10:59:37 INFO Received uploads request method=POST path=/api/pending_closures1126=== NAME TestClientWithDependencies1127 client_integration_test.go:615: Found 1 dependencies (including self)11282026/10/20 10:59:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11292026/10/20 10:59:37 INFO Received uploads request method=POST path=/api/pending_closures1130--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.43s)1131=== CONT TestService_AuthMiddleware_MTLSBoundSubjects11322026/10/20 10:59:37 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NjZlNTUxOTMtNDc4ZS00NDZmLWEwNjItZTRmYzI5MDUwM2QxLjI1ZWRlNmQ5LWI1YjgtNDEwZi1hMzlmLWYyZGI0OWQyMjU4Y3gxNzkyNDkzOTc3Mjg0MDQ1MDc4 parts=1011332026/10/20 10:59:37 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11342026/10/20 10:59:37 INFO Completed upload id=1 objects=2 duration=2.719124ms11352026/10/20 10:59:37 INFO Received uploads request method=POST path=/api/pending_closures11362026/10/20 10:59:37 INFO Received uploads request method=POST path=/api/pending_closures11372026/10/20 10:59:37 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo11382026/10/20 10:59:37 WARN Found objects in DB but missing from S3, will re-upload count=11139--- PASS: TestService_verifyS3Integrity (0.97s)1140=== CONT TestService_ReadAuthMiddleware11412026/10/20 10:59:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11422026/10/20 10:59:37 INFO Received push request method=POST path=/api/pushes11432026/10/20 10:59:37 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11442026/10/20 10:59:37 INFO Uploading j1ipgpqcayigqpnzscg7mrl035vszz7q-test-script (136B)11452026/10/20 10:59:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42399/oidc11462026/10/20 10:59:37 WARN Failed to register uploaded object key=j1ipgpqcayigqpnzscg7mrl035vszz7q.ls error="server returned 404: 404 page not found\n"11472026/10/20 10:59:37 WARN Failed to register uploaded object key=log/snhsjxwrjif849bwg7cf79gq46mgav0d-test-script.drv error="server returned 404: 404 page not found\n"11482026/10/20 10:59:37 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"11492026/10/20 10:59:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11502026/10/20 10:59:37 INFO Signed narinfos id=1 count=111512026/10/20 10:59:37 INFO Uploading 1 narinfos11522026/10/20 10:59:37 INFO Received complete push request method=POST path=/api/pushes/1/complete11532026/10/20 10:59:37 WARN Failed to register uploaded object key=j1ipgpqcayigqpnzscg7mrl035vszz7q.narinfo error="server returned 404: 404 page not found\n"11542026/10/20 10:59:37 INFO Completed push id=1 objects=4 duration=6.76566ms11552026/10/20 10:59:37 INFO Upload complete. (62ms)11562026/10/20 10:59:37 INFO Received uploads request method=POST path=/api/pending_closures1157=== NAME TestClientWithDependencies1158 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies16720165/001/store) requires matching store prefix1159--- PASS: TestClientWithDependencies (0.70s)1160=== CONT TestPresentRefreshesOnlyStaleClosures11612026/10/20 10:59:37 INFO Aborted multipart uploads count=0 kept=011622026/10/20 10:59:37 WARN Force mode enabled - objects will be deleted immediately without grace period11632026/10/20 10:59:37 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=011642026/10/20 10:59:37 INFO Vacuumed table table=pending_closures11652026/10/20 10:59:37 INFO Vacuumed table table=pending_objects11662026/10/20 10:59:37 INFO Vacuumed table table=multipart_uploads11672026/10/20 10:59:37 INFO Vacuumed table table=closures11682026/10/20 10:59:37 INFO Vacuumed table table=objects1169=== NAME TestClientMultipleUploads1170 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads3862039684/001/store/mwnb7yg3d282fvrz7mihvp5pcw9lab4c-test-file-0.txt11712026/10/20 10:59:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1172--- PASS: TestGCMetrics (0.43s)1173=== CONT TestReadProxyOutlastsServerWriteTimeout11742026/10/20 10:59:37 INFO Received uploads request method=POST path=/api/pending_closures11752026/10/20 10:59:37 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NjZlNTUxOTMtNDc4ZS00NDZmLWEwNjItZTRmYzI5MDUwM2QxLjU4YzkxY2UyLWJkNWItNDYyNC1iMzUwLWJjNmJkNzAwYzJiNngxNzkyNDkzOTc3MzkyMDk5MDA5 parts=1011762026/10/20 10:59:37 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11772026/10/20 10:59:37 INFO Completed upload id=1 objects=2 duration=3.094607ms11782026/10/20 10:59:37 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000011792026/10/20 10:59:37 INFO Received uploads request method=POST path=/api/pending_closures11802026/10/20 10:59:37 INFO Starting cleanup of old closures method=DELETE path=/api/closures11812026/10/20 10:59:37 INFO Aborted multipart uploads count=0 kept=011822026/10/20 10:59:37 INFO Aborted multipart uploads count=0 kept=011832026/10/20 10:59:37 WARN Force mode enabled - objects will be deleted immediately without grace period11842026/10/20 10:59:37 INFO Aborted multipart uploads count=0 kept=01185=== NAME TestClientMultipleUploads1186 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads3862039684/001/store/h4dqhqamcpkwp0dgxjfbqpkik75yjiwa-test-file-1.txt11872026/10/20 10:59:37 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=011882026/10/20 10:59:37 INFO Vacuumed table table=pending_closures11892026/10/20 10:59:37 INFO Vacuumed table table=pending_objects11902026/10/20 10:59:37 INFO Vacuumed table table=multipart_uploads11912026/10/20 10:59:37 INFO Vacuumed table table=closures11922026/10/20 10:59:37 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=011932026/10/20 10:59:37 INFO Vacuumed table table=objects11942026/10/20 10:59:37 INFO Vacuumed table table=pending_closures11952026/10/20 10:59:37 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=011962026/10/20 10:59:37 INFO Vacuumed table table=pending_objects11972026/10/20 10:59:37 INFO Vacuumed table table=multipart_uploads11982026/10/20 10:59:37 INFO Vacuumed table table=pending_closures11992026/10/20 10:59:37 INFO Vacuumed table table=closures1200--- PASS: TestGCSweepSkipsPendingObjects (0.43s)1201=== CONT TestService_RequireScope_OIDC12022026/10/20 10:59:37 INFO Vacuumed table table=pending_objects12032026/10/20 10:59:37 INFO Vacuumed table table=objects12042026/10/20 10:59:37 INFO Received uploads request method=POST path=/api/pending_closures12052026/10/20 10:59:37 INFO Vacuumed table table=multipart_uploads12062026/10/20 10:59:37 INFO Aborted multipart uploads count=0 kept=012072026/10/20 10:59:37 INFO Vacuumed table table=closures12082026/10/20 10:59:37 WARN Force mode enabled - objects will be deleted immediately without grace period12092026/10/20 10:59:37 INFO Vacuumed table table=objects12102026/10/20 10:59:37 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=012112026/10/20 10:59:37 INFO Vacuumed table table=pending_closures1212=== NAME TestClientMultipleUploads1213 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads3862039684/001/store/znzhxjzajcmsyc9mfcigiv33lhyqij1q-test-file-2.txt12142026/10/20 10:59:37 INFO Vacuumed table table=pending_objects12152026/10/20 10:59:37 INFO Vacuumed table table=multipart_uploads12162026/10/20 10:59:37 INFO Vacuumed table table=closures1217=== NAME TestClientIntegration1218 client_integration_test.go:286: Created store path: /build/TestClientIntegration2898745807/002/store/k80v4x0xcd803crs4ddzfy50csp41byf-test-file.txt12192026/10/20 10:59:37 INFO Vacuumed table table=objects1220--- PASS: TestPushDedupSurvivesConcurrentGC (0.52s)1221=== CONT TestPush_CompleteCommitsEveryRoot12222026/10/20 10:59:37 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001223--- PASS: TestService_createPendingClosureHandler (0.98s)1224=== CONT TestServerTLSConfig1225=== RUN TestServerTLSConfig/no_client_CA1226=== PAUSE TestServerTLSConfig/no_client_CA1227=== RUN TestServerTLSConfig/missing_CA_file1228=== PAUSE TestServerTLSConfig/missing_CA_file1229=== RUN TestServerTLSConfig/not_a_PEM_file1230=== PAUSE TestServerTLSConfig/not_a_PEM_file1231=== CONT TestPush_OverlappingRootsStoreOneRowPerKey1232--- PASS: TestCacheStatsHandler (0.45s)1233=== CONT TestPresentReportsOnlyClosureRoots12342026/10/20 10:59:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12352026/10/20 10:59:37 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NjZlNTUxOTMtNDc4ZS00NDZmLWEwNjItZTRmYzI5MDUwM2QxLjJhNGNhNTdhLTU1NTYtNDFhZi1hNzc2LTQzNThkMjE5YTk4NHgxNzkyNDkzOTc3NDQ3NTAzOTQ3 error="Get \"http://127.0.0.1:1/bucket12/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"12362026/10/20 10:59:37 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NjZlNTUxOTMtNDc4ZS00NDZmLWEwNjItZTRmYzI5MDUwM2QxLjNkMTZkMjE1LWNkN2EtNDUyYi05ZDE0LWVlYzRjN2UwM2Y5M3gxNzkyNDkzOTc3NDQyMjU0MDQw parts=1212372026/10/20 10:59:37 INFO Received cleanup request method=DELETE path=/api/pending_closures12382026/10/20 10:59:37 INFO Aborted multipart uploads count=1 kept=012392026/10/20 10:59:37 INFO Received push request method=POST path=/api/pushes12402026/10/20 10:59:37 INFO Received push request method=POST path=/api/pushes1241--- PASS: TestRedundantMultipartUpload (1.19s)1242=== CONT TestService_AuthMiddleware_MTLSProxyHeader12432026/10/20 10:59:37 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12442026/10/20 10:59:37 INFO Uploading k80v4x0xcd803crs4ddzfy50csp41byf-test-file.txt (152B)12452026/10/20 10:59:37 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)12462026/10/20 10:59:37 INFO Uploading mwnb7yg3d282fvrz7mihvp5pcw9lab4c-test-file-0.txt (160B)12472026/10/20 10:59:37 INFO Uploading znzhxjzajcmsyc9mfcigiv33lhyqij1q-test-file-2.txt (160B)12482026/10/20 10:59:37 INFO Uploading h4dqhqamcpkwp0dgxjfbqpkik75yjiwa-test-file-1.txt (160B)12492026/10/20 10:59:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43043/oidc12502026/10/20 10:59:37 WARN Failed to register uploaded object key=k80v4x0xcd803crs4ddzfy50csp41byf.ls error="server returned 404: 404 page not found\n"12512026/10/20 10:59:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12522026/10/20 10:59:37 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12532026/10/20 10:59:37 WARN Failed to register uploaded object key=znzhxjzajcmsyc9mfcigiv33lhyqij1q.ls error="server returned 404: 404 page not found\n"12542026/10/20 10:59:37 WARN Failed to register uploaded object key=h4dqhqamcpkwp0dgxjfbqpkik75yjiwa.ls error="server returned 404: 404 page not found\n"12552026/10/20 10:59:37 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"12562026/10/20 10:59:37 INFO Signed narinfos id=1 count=112572026/10/20 10:59:37 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"12582026/10/20 10:59:37 WARN Failed to register uploaded object key=mwnb7yg3d282fvrz7mihvp5pcw9lab4c.ls error="server returned 404: 404 page not found\n"12592026/10/20 10:59:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12602026/10/20 10:59:37 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"12612026/10/20 10:59:37 INFO Uploading 1 narinfos12622026/10/20 10:59:37 INFO Signed narinfos id=1 count=312632026/10/20 10:59:37 INFO Uploading 3 narinfos12642026/10/20 10:59:37 INFO Received uploads request method=POST path=/api/pending_closures12652026/10/20 10:59:37 INFO Received complete push request method=POST path=/api/pushes/1/complete12662026/10/20 10:59:37 WARN Failed to register uploaded object key=k80v4x0xcd803crs4ddzfy50csp41byf.narinfo error="server returned 404: 404 page not found\n"12672026/10/20 10:59:37 INFO Aborted multipart uploads count=0 kept=012682026/10/20 10:59:37 WARN Failed to register uploaded object key=znzhxjzajcmsyc9mfcigiv33lhyqij1q.narinfo error="server returned 404: 404 page not found\n"12692026/10/20 10:59:37 WARN Failed to register uploaded object key=h4dqhqamcpkwp0dgxjfbqpkik75yjiwa.narinfo error="server returned 404: 404 page not found\n"12702026/10/20 10:59:37 INFO Received complete push request method=POST path=/api/pushes/1/complete12712026/10/20 10:59:37 WARN Failed to register uploaded object key=mwnb7yg3d282fvrz7mihvp5pcw9lab4c.narinfo error="server returned 404: 404 page not found\n"1272--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.39s)1273=== CONT TestReadRedirectUsesPublicS3URL12742026/10/20 10:59:37 WARN Force mode enabled - objects will be deleted immediately without grace period12752026/10/20 10:59:37 INFO Completed push id=1 objects=3 duration=6.303256ms12762026/10/20 10:59:37 INFO Upload complete. (55ms)12772026/10/20 10:59:37 INFO Completed push id=1 objects=9 duration=6.313556ms12782026/10/20 10:59:37 INFO Upload complete. (61ms)1279=== NAME TestClientMultipleUploads1280 client_integration_test.go:369: Uploaded 3 paths in 91.453703ms1281=== NAME TestClientCADerivations1282 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3152226929/001/store/qf8snf6xx49k0mfc24mxy47a766lx96v-ca-test1283--- PASS: TestClientMultipleUploads (0.60s)1284=== CONT TestCreatePin_ReservedPins1285--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.70s)1286=== CONT TestReadProxyRangeRequest1287--- PASS: TestService_ReadScope_PublicByDefault (0.36s)1288=== CONT TestCreatePendingClosureRejectsOversizedNAR12892026/10/20 10:59:37 INFO Received uploads request method=POST path=/api/pending_closures1290--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1291=== CONT TestReadRedirectKeepsNarinfoProxied12922026/10/20 10:59:37 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=012932026/10/20 10:59:37 INFO Vacuumed table table=pending_closures12942026/10/20 10:59:37 INFO Vacuumed table table=pending_objects12952026/10/20 10:59:37 INFO Vacuumed table table=multipart_uploads12962026/10/20 10:59:37 INFO Vacuumed table table=closures12972026/10/20 10:59:37 INFO All 1 paths already cached1298=== NAME TestClientCADerivations1299 client_ca_test.go:139: Found 1 dependencies (including self)1300=== NAME TestClientIntegration1301 client_integration_test.go:312: Retrieved narinfo from S3:1302 StorePath: /build/TestClientIntegration2898745807/002/store/k80v4x0xcd803crs4ddzfy50csp41byf-test-file.txt1303 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1304 Compression: zstd1305 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11306 NarSize: 1521307 References: 1308 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk113092026/10/20 10:59:37 INFO Vacuumed table table=objects1310--- PASS: TestGCSweepDeliversEachKeyOnce (0.51s)1311=== CONT TestOrphanedObjectsGCStressTest1312=== NAME TestClientIntegration1313 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1314 client_integration_test.go:313: Decompressed .ls content (64 bytes):1315 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1316 client_integration_test.go:316: Testing garbage collection...13172026/10/20 10:59:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40831/oidc13182026/10/20 10:59:37 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"13192026/10/20 10:59:37 WARN mTLS auth: bound subjects configured but subject DN unavailable13202026/10/20 10:59:37 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1321--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.31s)1322=== CONT TestService_NativeMTLS1323--- PASS: TestService_ReadAuthMiddleware (0.31s)1324=== CONT TestOrphanedObjectsGC13252026/10/20 10:59:37 INFO Starting cleanup of old closures method=DELETE path=/api/closures13262026/10/20 10:59:37 INFO Garbage collection started13272026/10/20 10:59:37 INFO Aborted multipart uploads count=0 kept=01328=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1329=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1330=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1331=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1332=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1333=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1334=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1335=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1336=== CONT TestReadRedirectNar13372026/10/20 10:59:37 WARN Force mode enabled - objects will be deleted immediately without grace period1338--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.62s)1339=== CONT TestMetricsCommit1340--- PASS: TestPresentRefreshesOnlyStaleClosures (0.33s)1341=== CONT TestClientFallsBackToClosures13422026/10/20 10:59:37 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=013432026/10/20 10:59:37 INFO Received push request method=POST path=/api/pushes13442026/10/20 10:59:37 INFO Vacuumed table table=pending_closures13452026/10/20 10:59:37 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13462026/10/20 10:59:37 INFO Uploading qf8snf6xx49k0mfc24mxy47a766lx96v-ca-test (144B)13472026/10/20 10:59:37 INFO Vacuumed table table=pending_objects13482026/10/20 10:59:37 INFO Vacuumed table table=multipart_uploads13492026/10/20 10:59:37 WARN Failed to register uploaded object key=qf8snf6xx49k0mfc24mxy47a766lx96v.ls error="server returned 404: 404 page not found\n"13502026/10/20 10:59:37 WARN Failed to register uploaded object key=log/dckny51dr5n4jhqx0dziz0nlcajcyd1b-ca-test.drv error="server returned 404: 404 page not found\n"13512026/10/20 10:59:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13522026/10/20 10:59:37 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13532026/10/20 10:59:37 INFO Signed narinfos id=1 count=113542026/10/20 10:59:37 INFO Uploading 1 narinfos13552026/10/20 10:59:37 INFO Vacuumed table table=closures13562026/10/20 10:59:37 INFO Received complete push request method=POST path=/api/pushes/1/complete13572026/10/20 10:59:37 WARN Failed to register uploaded object key=qf8snf6xx49k0mfc24mxy47a766lx96v.narinfo error="server returned 404: 404 page not found\n"13582026/10/20 10:59:37 INFO Vacuumed table table=objects13592026/10/20 10:59:37 INFO Completed push id=1 objects=4 duration=6.773201ms13602026/10/20 10:59:37 INFO Upload complete. (89ms)1361=== NAME TestClientCADerivations1362 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3152226929/001/store/qf8snf6xx49k0mfc24mxy47a766lx96v-ca-test1363 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1364 Compression: zstd1365 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1366 NarSize: 1441367 References: 1368 Deriver: /build/TestClientCADerivations3152226929/001/store/dckny51dr5n4jhqx0dziz0nlcajcyd1b-ca-test.drv1369 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1370 client_ca_test.go:185: Checking for realisation files in S3...1371 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1372 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache13732026/10/20 10:59:38 INFO Received push request method=POST path=/api/pushes13742026/10/20 10:59:38 INFO Received complete push request method=POST path=/api/pushes/1/complete13752026/10/20 10:59:38 INFO Received push request method=POST path=/api/pushes13762026/10/20 10:59:38 INFO Completed push id=1 objects=6 duration=8.142633ms1377--- PASS: TestPush_CompleteCommitsEveryRoot (0.28s)1378=== CONT TestReadProxyHead1379--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.29s)1380=== CONT TestClientPushesUseOnePush1381--- PASS: TestPresentReportsOnlyClosureRoots (0.27s)1382=== CONT TestReadProxyInvalidPath1383--- PASS: TestGCBugBareHashReferences (0.60s)1384=== CONT TestPinProtectsFromGC1385=== RUN TestService_RequireScope_OIDC/builder_may_write1386=== PAUSE TestService_RequireScope_OIDC/builder_may_write1387=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1388=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1389=== RUN TestService_RequireScope_OIDC/ops_may_admin1390=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1391=== RUN TestService_RequireScope_OIDC/ops_may_not_write1392=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1393=== RUN TestService_RequireScope_OIDC/reader_may_not_write1394=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1395=== RUN TestService_RequireScope_OIDC/static_token_may_admin1396=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1397=== RUN TestService_RequireScope_OIDC/static_token_may_write1398=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1399=== RUN TestService_RequireScope_OIDC/reader_may_read1400=== PAUSE TestService_RequireScope_OIDC/reader_may_read1401=== RUN TestService_RequireScope_OIDC/writer_implies_read1402=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1403=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1404=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1405=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1406=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1407=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1408=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1409=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1410=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1411=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1412=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1413=== CONT TestMetricsInventory1414--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.27s)1415=== CONT TestClientSharedPathCommittedMidPush1416=== NAME TestClientCADerivations1417 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1418 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1419 error: binary cache 's3://bucket43?endpoint=http://localhost:35389®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3152226929/001/store'1420 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11421--- PASS: TestClientCADerivations (0.78s)1422=== CONT TestReadProxy4041423--- PASS: TestReadRedirectUsesPublicS3URL (0.30s)1424=== CONT TestReadProxyNarStreaming1425--- PASS: TestReadProxyRangeRequest (0.30s)1426=== CONT TestPendingCleanupUsesOneCutoff1427--- PASS: TestReadRedirectKeepsNarinfoProxied (0.30s)1428=== CONT TestNARDeduplicationMetadataUploadBug14292026/10/20 10:59:38 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14302026/10/20 10:59:38 WARN Refused reserved pin name=worker-x86_64-linux14312026/10/20 10:59:38 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14322026/10/20 10:59:38 INFO Received create pin request method=POST path=/api/pins/my-app14332026/10/20 10:59:38 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1434--- PASS: TestCreatePin_ReservedPins (0.38s)1435=== CONT TestReadProxyContentNegotiation14362026/10/20 10:59:38 WARN mTLS auth: subject not in bound subjects subject="CN=reader"14372026/10/20 10:59:38 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1438--- PASS: TestService_NativeMTLS (0.35s)1439=== CONT TestObjectStatsTrigger1440--- PASS: TestReadRedirectNar (0.36s)1441=== CONT TestIsValidCachePath1442=== RUN TestIsValidCachePath/narinfo1443=== PAUSE TestIsValidCachePath/narinfo1444=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1445=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1446=== RUN TestIsValidCachePath/nar_zst1447=== PAUSE TestIsValidCachePath/nar_zst1448=== RUN TestIsValidCachePath/nar_xz1449=== PAUSE TestIsValidCachePath/nar_xz1450=== RUN TestIsValidCachePath/nar_bz21451=== PAUSE TestIsValidCachePath/nar_bz21452=== RUN TestIsValidCachePath/nar_uncompressed1453=== PAUSE TestIsValidCachePath/nar_uncompressed1454=== RUN TestIsValidCachePath/ls1455=== PAUSE TestIsValidCachePath/ls1456=== RUN TestIsValidCachePath/log1457=== PAUSE TestIsValidCachePath/log1458=== RUN TestIsValidCachePath/realisation1459=== PAUSE TestIsValidCachePath/realisation1460=== RUN TestIsValidCachePath/nix-cache-info1461=== PAUSE TestIsValidCachePath/nix-cache-info1462=== RUN TestIsValidCachePath/index.html1463=== PAUSE TestIsValidCachePath/index.html1464=== RUN TestIsValidCachePath/traversal_parent1465=== PAUSE TestIsValidCachePath/traversal_parent1466=== RUN TestIsValidCachePath/traversal_in_middle1467=== PAUSE TestIsValidCachePath/traversal_in_middle1468=== RUN TestIsValidCachePath/invalid_char_e1469=== PAUSE TestIsValidCachePath/invalid_char_e1470=== RUN TestIsValidCachePath/invalid_char_u1471=== PAUSE TestIsValidCachePath/invalid_char_u1472=== RUN TestIsValidCachePath/random_path1473=== PAUSE TestIsValidCachePath/random_path1474=== RUN TestIsValidCachePath/empty1475=== PAUSE TestIsValidCachePath/empty1476=== RUN TestIsValidCachePath/leading_slash1477=== PAUSE TestIsValidCachePath/leading_slash1478=== RUN TestIsValidCachePath/wrong_extension1479=== PAUSE TestIsValidCachePath/wrong_extension1480=== RUN TestIsValidCachePath/short_hash1481=== PAUSE TestIsValidCachePath/short_hash1482=== CONT TestParseSingleRange1483=== RUN TestParseSingleRange/none1484=== PAUSE TestParseSingleRange/none1485=== RUN TestParseSingleRange/unknown_unit1486=== PAUSE TestParseSingleRange/unknown_unit1487=== RUN TestParseSingleRange/multi-range_ignored1488=== PAUSE TestParseSingleRange/multi-range_ignored1489=== RUN TestParseSingleRange/malformed_no_dash1490=== PAUSE TestParseSingleRange/malformed_no_dash1491=== RUN TestParseSingleRange/malformed_both_empty1492=== PAUSE TestParseSingleRange/malformed_both_empty1493=== RUN TestParseSingleRange/malformed_end_before_start1494=== PAUSE TestParseSingleRange/malformed_end_before_start1495=== RUN TestParseSingleRange/closed1496=== PAUSE TestParseSingleRange/closed1497=== RUN TestParseSingleRange/open-ended1498=== PAUSE TestParseSingleRange/open-ended1499=== RUN TestParseSingleRange/end_clamped_to_size1500=== PAUSE TestParseSingleRange/end_clamped_to_size1501=== RUN TestParseSingleRange/suffix1502=== PAUSE TestParseSingleRange/suffix1503=== RUN TestParseSingleRange/suffix_exceeds_size1504=== PAUSE TestParseSingleRange/suffix_exceeds_size1505=== RUN TestParseSingleRange/single_byte1506=== PAUSE TestParseSingleRange/single_byte1507=== RUN TestParseSingleRange/start_past_EOF1508=== PAUSE TestParseSingleRange/start_past_EOF1509=== RUN TestParseSingleRange/start_far_past_EOF1510=== PAUSE TestParseSingleRange/start_far_past_EOF1511=== CONT TestReadProxyNarinfoAlreadyDecompressed15122026/10/20 10:59:38 INFO Received push request method=POST path=/api/pushes15132026/10/20 10:59:38 INFO Received complete push request method=POST path=/api/pushes/1/complete15142026/10/20 10:59:38 INFO Completed push id=1 objects=4 duration=8.661978ms15152026/10/20 10:59:38 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15162026/10/20 10:59:38 INFO Completed upload id=2 objects=2 duration=1.216571ms1517--- PASS: TestMetricsCommit (0.39s)1518=== CONT TestPresentNotReportedWhileGCDeletesClosure1519=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1520=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1521=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1522=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1523=== CONT TestService_healthCheckHandler1524--- PASS: TestReadProxyHead (0.32s)1525=== CONT TestReadProxyNarinfo1526--- PASS: TestReadProxyInvalidPath (0.33s)1527=== CONT TestGracefulShutdownDrainsInflight15282026/10/20 10:59:38 INFO Starting HTTP server address=127.0.0.1:4349115292026/10/20 10:59:38 INFO Shutdown signal received, draining in-flight requests timeout=10s1530--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1531=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1532--- PASS: TestMetricsInventory (0.37s)1533=== CONT TestReadProxyRootRedirectsToIndexHTML1534=== NAME TestPinProtectsFromGC1535 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC3748756100/001/store/k6p478vkghb1i55nkn0h1ygql56plla9-pinned-file.txt1536 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC3748756100/001/store/1y9a33fx3ijh7697r88qcfn26i9lwb4f-unpinned-file.txt1537--- PASS: TestReadProxyNarStreaming (0.36s)1538=== CONT TestCacheConfigHandlerMaxNarSize1539--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1540=== CONT TestReadProxyConditionalGet15412026/10/20 10:59:38 INFO lead: released remote=192.0.2.1:12341542--- PASS: TestLeadEndsOnShutdown (1.53s)1543=== CONT TestMultipartCleanup15442026/10/20 10:59:38 INFO Received uploads request method=POST path=/api/pending_closures15452026/10/20 10:59:38 INFO Received uploads request method=POST path=/api/pending_closures1546--- PASS: TestReadProxy404 (0.40s)1547=== CONT TestGenerateLandingPage1548--- PASS: TestGenerateLandingPage (0.00s)1549=== CONT TestObjectStatsLargeCommit15502026/10/20 10:59:38 INFO Received uploads request method=POST path=/api/pending_closures15512026/10/20 10:59:38 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15522026/10/20 10:59:38 INFO Uploading ahl9xcvqm62sy35h8g9wdzh2v2x4qbdz-b (216B)15532026/10/20 10:59:38 INFO Uploading kgyvavd2bv7hclxdazsbfnb6i7jqncri-shared-dep (136B)15542026/10/20 10:59:38 INFO Received uploads request method=POST path=/api/pending_closures15552026/10/20 10:59:38 WARN Failed to register uploaded object key=am4402pv7csfvg15zj39l5680hqc02py.ls error="server returned 404: 404 page not found\n"15562026/10/20 10:59:38 WARN Failed to register uploaded object key=ahl9xcvqm62sy35h8g9wdzh2v2x4qbdz.ls error="server returned 404: 404 page not found\n"15572026/10/20 10:59:38 WARN Failed to register uploaded object key=kgyvavd2bv7hclxdazsbfnb6i7jqncri.ls error="server returned 404: 404 page not found\n"15582026/10/20 10:59:38 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15592026/10/20 10:59:38 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15602026/10/20 10:59:38 WARN Failed to register uploaded object key=nar/03mjw72g4ncjkfvj1nmh3pi0ah8cz80rz21i48pq3swybnflyw08.nar.zst error="server returned 404: 404 page not found\n"15612026/10/20 10:59:38 INFO Signed narinfos id=1 count=215622026/10/20 10:59:38 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15632026/10/20 10:59:38 INFO Signed narinfos id=2 count=215642026/10/20 10:59:38 INFO Uploading 4 narinfos15652026/10/20 10:59:38 INFO Received push request method=POST path=/api/pushes15662026/10/20 10:59:38 INFO Received cleanup request method=DELETE path=/api/pending_closures15672026/10/20 10:59:38 WARN Failed to register uploaded object key=kgyvavd2bv7hclxdazsbfnb6i7jqncri.narinfo error="server returned 404: 404 page not found\n"15682026/10/20 10:59:38 WARN Failed to register uploaded object key=ahl9xcvqm62sy35h8g9wdzh2v2x4qbdz.narinfo error="server returned 404: 404 page not found\n"15692026/10/20 10:59:38 WARN Failed to register uploaded object key=am4402pv7csfvg15zj39l5680hqc02py.narinfo error="server returned 404: 404 page not found\n"15702026/10/20 10:59:38 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15712026/10/20 10:59:38 INFO Uploading nmdsqs2z2shppjwwc3snfwrdaym8sfx8-b (208B)15722026/10/20 10:59:38 INFO Uploading izfg69flr6sibfsgc5vdhhfrcd5z1dka-shared-dep (136B)15732026/10/20 10:59:38 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15742026/10/20 10:59:38 WARN Failed to register uploaded object key=kgyvavd2bv7hclxdazsbfnb6i7jqncri.narinfo error="server returned 404: 404 page not found\n"15752026/10/20 10:59:38 WARN Failed to register uploaded object key=izfg69flr6sibfsgc5vdhhfrcd5z1dka.ls error="server returned 404: 404 page not found\n"15762026/10/20 10:59:38 INFO Completed upload id=1 objects=6 duration=4.997585ms15772026/10/20 10:59:38 WARN Failed to register uploaded object key=a4vfc1al5gsm45sl1advpkv2p3q8z9sc.ls error="server returned 404: 404 page not found\n"15782026/10/20 10:59:38 WARN Failed to register uploaded object key=nmdsqs2z2shppjwwc3snfwrdaym8sfx8.ls error="server returned 404: 404 page not found\n"15792026/10/20 10:59:38 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15802026/10/20 10:59:38 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15812026/10/20 10:59:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15822026/10/20 10:59:38 WARN Failed to register uploaded object key=nar/18j375l47pd4vbvyk7zynx4c2hl3y3ky9vfc5wiyzcqrkpb253cy.nar.zst error="server returned 404: 404 page not found\n"15832026/10/20 10:59:38 INFO Signed narinfos id=1 count=315842026/10/20 10:59:38 INFO Uploading 3 narinfos15852026/10/20 10:59:38 INFO Completed upload id=2 objects=6 duration=1.839776ms15862026/10/20 10:59:38 INFO Upload complete. (74ms)1587=== NAME TestClientFallsBackToClosures1588 client_pushes_test.go:112: Retrieved narinfo from S3:1589 StorePath: /build/TestClientFallsBackToClosures3495339623/001/store/kgyvavd2bv7hclxdazsbfnb6i7jqncri-shared-dep1590 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1591 Compression: zstd1592 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821593 NarSize: 1361594 References: 1595 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n15962026/10/20 10:59:38 INFO Received push request method=POST path=/api/pushes15972026/10/20 10:59:38 WARN Failed to register uploaded object key=izfg69flr6sibfsgc5vdhhfrcd5z1dka.narinfo error="server returned 404: 404 page not found\n"15982026/10/20 10:59:38 WARN Failed to register uploaded object key=nmdsqs2z2shppjwwc3snfwrdaym8sfx8.narinfo error="server returned 404: 404 page not found\n"15992026/10/20 10:59:38 INFO Received complete push request method=POST path=/api/pushes/1/complete16002026/10/20 10:59:38 WARN Failed to register uploaded object key=a4vfc1al5gsm45sl1advpkv2p3q8z9sc.narinfo error="server returned 404: 404 page not found\n"1601 client_pushes_test.go:112: Retrieved narinfo from S3:1602 StorePath: /build/TestClientFallsBackToClosures3495339623/001/store/am4402pv7csfvg15zj39l5680hqc02py-a1603 URL: nar/03mjw72g4ncjkfvj1nmh3pi0ah8cz80rz21i48pq3swybnflyw08.nar.zst1604 Compression: zstd1605 NarHash: sha256:03mjw72g4ncjkfvj1nmh3pi0ah8cz80rz21i48pq3swybnflyw081606 NarSize: 2161607 References: /build/TestClientFallsBackToClosures3495339623/001/store/kgyvavd2bv7hclxdazsbfnb6i7jqncri-shared-dep1608 CA: text:sha256:145zqmkl1m9b6v738vfig368l2cjian52l088mm64a65pbzjwlh116092026/10/20 10:59:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1610 client_pushes_test.go:112: Retrieved narinfo from S3:1611 StorePath: /build/TestClientFallsBackToClosures3495339623/001/store/ahl9xcvqm62sy35h8g9wdzh2v2x4qbdz-b16122026/10/20 10:59:38 INFO Uploading k6p478vkghb1i55nkn0h1ygql56plla9-pinned-file.txt (128B)1613 URL: nar/03mjw72g4ncjkfvj1nmh3pi0ah8cz80rz21i48pq3swybnflyw08.nar.zst1614 Compression: zstd1615 NarHash: sha256:03mjw72g4ncjkfvj1nmh3pi0ah8cz80rz21i48pq3swybnflyw081616 NarSize: 2161617 References: /build/TestClientFallsBackToClosures3495339623/001/store/kgyvavd2bv7hclxdazsbfnb6i7jqncri-shared-dep1618 CA: text:sha256:145zqmkl1m9b6v738vfig368l2cjian52l088mm64a65pbzjwlh116192026/10/20 10:59:38 INFO Completed push id=1 objects=8 duration=7.041723ms16202026/10/20 10:59:38 INFO Upload complete. (63ms)1621--- PASS: TestClientFallsBackToClosures (0.59s)1622=== CONT TestService_readinessHandler1623=== NAME TestClientPushesUseOnePush1624 client_pushes_test.go:97: Retrieved narinfo from S3:1625 StorePath: /build/TestClientPushesUseOnePush953726414/001/store/izfg69flr6sibfsgc5vdhhfrcd5z1dka-shared-dep1626 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1627 Compression: zstd1628 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821629 NarSize: 1361630 References: 1631 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n16322026/10/20 10:59:38 WARN Failed to register uploaded object key=k6p478vkghb1i55nkn0h1ygql56plla9.ls error="server returned 404: 404 page not found\n"16332026/10/20 10:59:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16342026/10/20 10:59:38 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"16352026/10/20 10:59:38 INFO Signed narinfos id=1 count=116362026/10/20 10:59:38 INFO Uploading 1 narinfos1637 client_pushes_test.go:97: Retrieved narinfo from S3:1638 StorePath: /build/TestClientPushesUseOnePush953726414/001/store/a4vfc1al5gsm45sl1advpkv2p3q8z9sc-a1639 URL: nar/18j375l47pd4vbvyk7zynx4c2hl3y3ky9vfc5wiyzcqrkpb253cy.nar.zst1640 Compression: zstd1641 NarHash: sha256:18j375l47pd4vbvyk7zynx4c2hl3y3ky9vfc5wiyzcqrkpb253cy1642 NarSize: 2081643 References: /build/TestClientPushesUseOnePush953726414/001/store/izfg69flr6sibfsgc5vdhhfrcd5z1dka-shared-dep1644 CA: text:sha256:14s221yxbd4z0yhyfy25x1lmjp7qp0hqpnh2ahr0w4pzp8xwj2vp1645 client_pushes_test.go:97: Retrieved narinfo from S3:1646 StorePath: /build/TestClientPushesUseOnePush953726414/001/store/nmdsqs2z2shppjwwc3snfwrdaym8sfx8-b1647 URL: nar/18j375l47pd4vbvyk7zynx4c2hl3y3ky9vfc5wiyzcqrkpb253cy.nar.zst1648 Compression: zstd1649 NarHash: sha256:18j375l47pd4vbvyk7zynx4c2hl3y3ky9vfc5wiyzcqrkpb253cy1650 NarSize: 2081651 References: /build/TestClientPushesUseOnePush953726414/001/store/izfg69flr6sibfsgc5vdhhfrcd5z1dka-shared-dep1652 CA: text:sha256:14s221yxbd4z0yhyfy25x1lmjp7qp0hqpnh2ahr0w4pzp8xwj2vp16532026/10/20 10:59:38 INFO Received complete push request method=POST path=/api/pushes/1/complete16542026/10/20 10:59:38 WARN Failed to register uploaded object key=k6p478vkghb1i55nkn0h1ygql56plla9.narinfo error="server returned 404: 404 page not found\n"1655--- PASS: TestClientPushesUseOnePush (0.52s)1656=== CONT TestReadProxyDisabled16572026/10/20 10:59:38 INFO Completed push id=1 objects=3 duration=5.872353ms16582026/10/20 10:59:38 INFO Upload complete. (62ms)16592026/10/20 10:59:38 INFO Received push request method=POST path=/api/pushes1660=== NAME TestNARDeduplicationMetadataUploadBug1661 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1936993995/001/store/qzls92mgkiaj94xs7m53k3pknp8xqvnj-file1.txt16622026/10/20 10:59:38 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)16632026/10/20 10:59:38 INFO Uploading sr339l5wf6x6s4h0vcfqfiq5hb917r31-shared-dep (136B)16642026/10/20 10:59:38 INFO Uploading vvi2jigfim7a7r2l4jssifil14ma5qhh-top (224B)16652026/10/20 10:59:38 WARN Failed to register uploaded object key=vvi2jigfim7a7r2l4jssifil14ma5qhh.ls error="server returned 404: 404 page not found\n"16662026/10/20 10:59:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16672026/10/20 10:59:38 WARN Failed to register uploaded object key=nar/1fzvkmq8i0bd85625g1rdwxsc28lxxwvimvkwrm2vfxlspmzllmd.nar.zst error="server returned 404: 404 page not found\n"16682026/10/20 10:59:38 WARN Failed to register uploaded object key=sr339l5wf6x6s4h0vcfqfiq5hb917r31.ls error="server returned 404: 404 page not found\n"16692026/10/20 10:59:38 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16702026/10/20 10:59:38 INFO Signed narinfos id=1 count=216712026/10/20 10:59:38 INFO Uploading 2 narinfos16722026/10/20 10:59:38 WARN Failed to register uploaded object key=vvi2jigfim7a7r2l4jssifil14ma5qhh.narinfo error="server returned 404: 404 page not found\n"16732026/10/20 10:59:38 INFO Received complete push request method=POST path=/api/pushes/1/complete16742026/10/20 10:59:38 WARN Failed to register uploaded object key=sr339l5wf6x6s4h0vcfqfiq5hb917r31.narinfo error="server returned 404: 404 page not found\n"1675--- PASS: TestObjectStatsTrigger (0.35s)1676=== CONT TestGCEndsOnShutdown/before_the_run16772026/10/20 10:59:38 INFO Completed push id=1 objects=6 duration=6.807882ms16782026/10/20 10:59:38 INFO Upload complete. (69ms)1679=== NAME TestClientSharedPathCommittedMidPush1680 client_integration_test.go:680: Retrieved narinfo from S3:1681 StorePath: /build/TestClientSharedPathCommittedMidPush14752475/001/store/sr339l5wf6x6s4h0vcfqfiq5hb917r31-shared-dep1682 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1683 Compression: zstd1684 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821685 NarSize: 1361686 References: 1687 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1688 client_integration_test.go:680: Retrieved narinfo from S3:1689 StorePath: /build/TestClientSharedPathCommittedMidPush14752475/001/store/vvi2jigfim7a7r2l4jssifil14ma5qhh-top1690 URL: nar/1fzvkmq8i0bd85625g1rdwxsc28lxxwvimvkwrm2vfxlspmzllmd.nar.zst1691 Compression: zstd1692 NarHash: sha256:1fzvkmq8i0bd85625g1rdwxsc28lxxwvimvkwrm2vfxlspmzllmd1693 NarSize: 2241694 References: /build/TestClientSharedPathCommittedMidPush14752475/001/store/sr339l5wf6x6s4h0vcfqfiq5hb917r31-shared-dep1695 CA: text:sha256:1cphw4vvjc72g2g3pzcgmcvw95sz0icc319faa16avpc962azppg1696--- PASS: TestClientSharedPathCommittedMidPush (0.51s)1697=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1698--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.31s)1699=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1700--- PASS: TestReadProxyContentNegotiation (0.39s)1701=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17022026/10/20 10:59:38 INFO Received uploads request method=POST path=/1703--- PASS: TestService_healthCheckHandler (0.29s)1704=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17052026/10/20 10:59:38 INFO Received complete multipart upload request method=POST path=/1706=== NAME TestOrphanedObjectsGC1707 orphaned_objects_gc_test.go:287: GC Test Summary:1708 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1709 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1710 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1711 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1712 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1713--- PASS: TestOrphanedObjectsGC (0.72s)1714=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17152026/10/20 10:59:38 INFO Received request for more parts method=POST path=/17162026/10/20 10:59:38 INFO Received push request method=POST path=/api/pushes17172026/10/20 10:59:38 INFO Received push request method=POST path=/api/pushes17182026/10/20 10:59:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17192026/10/20 10:59:38 INFO Uploading 1y9a33fx3ijh7697r88qcfn26i9lwb4f-unpinned-file.txt (128B)17202026/10/20 10:59:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17212026/10/20 10:59:38 INFO Uploading qzls92mgkiaj94xs7m53k3pknp8xqvnj-file1.txt (160B)17222026/10/20 10:59:38 WARN Failed to register uploaded object key=1y9a33fx3ijh7697r88qcfn26i9lwb4f.ls error="server returned 404: 404 page not found\n"17232026/10/20 10:59:38 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17242026/10/20 10:59:38 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"17252026/10/20 10:59:38 INFO Signed narinfos id=2 count=117262026/10/20 10:59:38 INFO Uploading 1 narinfos17272026/10/20 10:59:38 WARN Failed to register uploaded object key=qzls92mgkiaj94xs7m53k3pknp8xqvnj.ls error="server returned 404: 404 page not found\n"17282026/10/20 10:59:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17292026/10/20 10:59:38 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"17302026/10/20 10:59:38 INFO Signed narinfos id=1 count=117312026/10/20 10:59:38 INFO Uploading 1 narinfos17322026/10/20 10:59:38 INFO Received complete push request method=POST path=/api/pushes/2/complete17332026/10/20 10:59:38 WARN Failed to register uploaded object key=1y9a33fx3ijh7697r88qcfn26i9lwb4f.narinfo error="server returned 404: 404 page not found\n"17342026/10/20 10:59:38 INFO Completed push id=2 objects=3 duration=1.846856ms17352026/10/20 10:59:38 INFO Upload complete. (59ms)17362026/10/20 10:59:38 INFO Received complete push request method=POST path=/api/pushes/1/complete17372026/10/20 10:59:38 WARN Failed to register uploaded object key=qzls92mgkiaj94xs7m53k3pknp8xqvnj.narinfo error="server returned 404: 404 page not found\n"17382026/10/20 10:59:38 INFO Completed push id=1 objects=3 duration=5.164006ms17392026/10/20 10:59:38 INFO Upload complete. (62ms)1740=== NAME TestNARDeduplicationMetadataUploadBug1741 metadata_upload_test.go:54: Retrieved narinfo from S3:1742 StorePath: /build/TestNARDeduplicationMetadataUploadBug1936993995/001/store/qzls92mgkiaj94xs7m53k3pknp8xqvnj-file1.txt1743 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1744 Compression: zstd1745 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1746 NarSize: 1601747 References: 1748 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1749=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17502026/10/20 10:59:38 INFO Received uploads request method=POST path=/1751=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17522026/10/20 10:59:38 INFO Received complete multipart upload request method=POST path=/1753=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17542026/10/20 10:59:38 INFO Received request for more parts method=POST path=/1755=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17562026/10/20 10:59:38 INFO Received uploads request method=POST path=/1757--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1758 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1759 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1760 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1761 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1762=== CONT TestIsValidUploadKey/narinfo1763=== CONT TestIsValidUploadKey/empty_key1764=== CONT TestIsValidUploadKey/unknown_type1765=== CONT TestIsValidUploadKey/absolute1766=== CONT TestIsValidUploadKey/build_log_equals1767=== CONT TestIsValidUploadKey/build_log_question_mark1768=== CONT TestIsValidUploadKey/build_log_plus_in_name1769=== CONT TestIsValidUploadKey/nar_plain1770=== CONT TestIsValidUploadKey/nar_xz1771=== CONT TestIsValidUploadKey/nar_zst1772=== CONT TestIsValidUploadKey/listing1773=== CONT TestIsValidUploadKey/realisation1774=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1775=== CONT TestIsValidUploadKey/build_log_home-manager_file1776=== CONT TestIsValidUploadKey/build_log1777=== CONT TestIsValidUploadKey/traversal1778=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1779=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1780=== CONT TestIsValidUploadKey/nix-cache-info1781=== CONT TestIsValidUploadKey/traversal_nar1782=== CONT TestIsValidUploadKey/index.html1783=== CONT TestIsValidUploadKey/realisation_plus_in_output1784--- PASS: TestIsValidUploadKey (0.00s)1785 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1786 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1787 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1788 --- PASS: TestIsValidUploadKey/absolute (0.00s)1789 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1790 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1791 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1792 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1793 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1794 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1795 --- PASS: TestIsValidUploadKey/listing (0.00s)1796 --- PASS: TestIsValidUploadKey/realisation (0.00s)1797 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1798 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1799 --- PASS: TestIsValidUploadKey/build_log (0.00s)1800 --- PASS: TestIsValidUploadKey/traversal (0.00s)1801 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1802 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1803 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1804 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1805 --- PASS: TestIsValidUploadKey/index.html (0.00s)1806 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1807=== CONT TestPush_RejectsBadRequests/no_roots18082026/10/20 10:59:38 INFO Received push request method=POST path=/api/pushes1809=== CONT TestPush_RejectsBadRequests/bad_root18102026/10/20 10:59:38 INFO Received push request method=POST path=/api/pushes1811=== NAME TestNARDeduplicationMetadataUploadBug1812 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1813=== CONT TestPush_RejectsBadRequests/root_not_in_objects18142026/10/20 10:59:38 INFO Received push request method=POST path=/api/pushes1815=== NAME TestNARDeduplicationMetadataUploadBug1816 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1817 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1818=== CONT TestPush_RejectsBadRequests/no_objects18192026/10/20 10:59:38 INFO Received push request method=POST path=/api/pushes1820=== CONT TestPendingClosureWriteTimeout/empty1821=== CONT TestPendingClosureWriteTimeout/670k_objects1822--- PASS: TestPush_RejectsBadRequests (0.31s)1823 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1824 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1825 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1826 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1827=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1828--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.22s)1829=== CONT TestPendingClosureWriteTimeout/400_objects1830=== CONT TestProxyWriteTimeout/narinfo1831=== CONT TestProxyWriteTimeout/10_GiB_nar1832=== CONT TestProxyWriteTimeout/1_GiB_nar1833=== CONT TestProxyWriteTimeout/unknown_size1834--- PASS: TestProxyWriteTimeout (0.00s)1835 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1836 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1837 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1838 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1839=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1840=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check18412026/10/20 10:59:38 INFO Received uploads request method=POST path=/api/pending_closures18422026/10/20 10:59:38 INFO Starting cleanup of old closures method=DELETE path=/api/closures18432026/10/20 10:59:38 INFO Garbage collection started1844=== NAME TestNARDeduplicationMetadataUploadBug1845 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1936993995/001/store/zhv8w7hid5f13mxc20sm5majdddh69rx-file2.txt18462026/10/20 10:59:38 INFO Aborted multipart uploads count=0 kept=01847--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.26s)1848=== CONT TestResolveDBConnectionString/flag_wins1849=== CONT TestResolveDBConnectionString/nothing_configured1850=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1851=== CONT TestResolveDBConnectionString/missing_file_is_an_error1852=== CONT TestResolveDBConnectionString/file_when_flag_empty1853=== CONT TestCacheConfigHandler/full_config,_no_issuer1854=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1855=== CONT TestCacheConfigHandler/no_signing_keys1856=== CONT TestCacheConfigHandler/no_cache_url_configured1857--- PASS: TestResolveDBConnectionString (0.00s)1858 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1859 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1860 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1861 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1862 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1863--- PASS: TestCacheConfigHandler (0.00s)1864 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1865 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1866 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1867 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1868=== CONT TestClientErrorHandling/InvalidStorePath18692026/10/20 10:59:38 WARN Force mode enabled - objects will be deleted immediately without grace period18702026/10/20 10:59:38 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1871--- PASS: TestReadProxyNarinfo (0.37s)1872=== CONT TestClientErrorHandling/InvalidAuthToken1873--- PASS: TestReadProxyConditionalGet (0.24s)1874=== CONT TestClientErrorHandling/ServerNotAvailable18752026/10/20 10:59:38 INFO Received uploads request method=POST path=/api/pending_closures18762026/10/20 10:59:38 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=018772026/10/20 10:59:38 INFO lead: released remote=192.0.2.1:123418782026/10/20 10:59:38 INFO Vacuumed table table=pending_closures18792026/10/20 10:59:38 INFO Vacuumed table table=pending_objects18802026/10/20 10:59:38 INFO Vacuumed table table=multipart_uploads18812026/10/20 10:59:38 INFO Vacuumed table table=closures18822026/10/20 10:59:38 INFO Vacuumed table table=objects18832026/10/20 10:59:38 INFO Received push request method=POST path=/api/pushes18842026/10/20 10:59:38 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)18852026/10/20 10:59:38 WARN readiness check failed error="closed pool"1886--- PASS: TestService_readinessHandler (0.23s)1887=== CONT TestServerTLSConfig/no_client_CA1888=== CONT TestServerTLSConfig/missing_CA_file1889=== CONT TestServerTLSConfig/not_a_PEM_file1890--- PASS: TestServerTLSConfig (0.00s)1891 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1892 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1893 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1894=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token18952026/10/20 10:59:38 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18962026/10/20 10:59:38 WARN Failed to register uploaded object key=zhv8w7hid5f13mxc20sm5majdddh69rx.ls error="server returned 404: 404 page not found\n"18972026/10/20 10:59:38 INFO Signed narinfos id=2 count=118982026/10/20 10:59:38 INFO Uploading 1 narinfos1899=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19002026/10/20 10:59:38 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]1901=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1902=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19032026/10/20 10:59:38 WARN Authentication failed token_preview=eyJhbGciOi...2WSgUTH0ww token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1904=== CONT TestService_RequireScope_OIDC/builder_may_write1905--- PASS: TestService_AuthMiddleware_OIDC (0.55s)1906 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1907 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1908 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1909 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)19102026/10/20 10:59:38 INFO Received complete push request method=POST path=/api/pushes/2/complete19112026/10/20 10:59:38 WARN Failed to register uploaded object key=zhv8w7hid5f13mxc20sm5majdddh69rx.narinfo error="server returned 404: 404 page not found\n"1912=== CONT TestService_RequireScope_OIDC/reader_may_read1913=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1914=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19152026/10/20 10:59:38 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]1916=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1917=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1918=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1919=== CONT TestService_RequireScope_OIDC/writer_implies_read1920=== CONT TestService_RequireScope_OIDC/reader_may_not_write1921=== CONT TestService_RequireScope_OIDC/ops_may_admin1922=== CONT TestService_RequireScope_OIDC/static_token_may_write1923=== CONT TestService_RequireScope_OIDC/ops_may_not_write1924=== CONT TestService_RequireScope_OIDC/static_token_may_admin1925=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1926=== CONT TestIsValidCachePath/narinfo1927=== CONT TestIsValidCachePath/index.html1928=== CONT TestIsValidCachePath/short_hash1929=== CONT TestIsValidCachePath/wrong_extension1930=== CONT TestIsValidCachePath/leading_slash1931=== CONT TestIsValidCachePath/empty1932=== CONT TestIsValidCachePath/nar_uncompressed1933=== CONT TestIsValidCachePath/random_path1934=== CONT TestIsValidCachePath/nix-cache-info19352026/10/20 10:59:38 INFO Completed push id=2 objects=3 duration=44.049836ms1936=== CONT TestIsValidCachePath/invalid_char_u1937=== CONT TestIsValidCachePath/realisation1938=== CONT TestIsValidCachePath/invalid_char_e1939=== CONT TestIsValidCachePath/log1940=== CONT TestIsValidCachePath/traversal_parent1941=== CONT TestIsValidCachePath/ls1942=== CONT TestIsValidCachePath/nar_xz1943=== CONT TestIsValidCachePath/nar_zst1944=== CONT TestIsValidCachePath/nar_bz21945=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1946=== CONT TestIsValidCachePath/traversal_in_middle1947--- PASS: TestIsValidCachePath (0.00s)1948 --- PASS: TestIsValidCachePath/narinfo (0.00s)1949 --- PASS: TestIsValidCachePath/index.html (0.00s)1950 --- PASS: TestIsValidCachePath/short_hash (0.00s)1951 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1952 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1953 --- PASS: TestIsValidCachePath/empty (0.00s)1954 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1955 --- PASS: TestIsValidCachePath/random_path (0.00s)1956 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1957 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1958 --- PASS: TestIsValidCachePath/realisation (0.00s)1959 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1960 --- PASS: TestIsValidCachePath/log (0.00s)1961 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1962 --- PASS: TestIsValidCachePath/ls (0.00s)1963 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1964 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1965 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1966 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1967 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1968=== CONT TestParseSingleRange/none1969=== CONT TestParseSingleRange/start_past_EOF1970=== CONT TestParseSingleRange/single_byte1971=== CONT TestParseSingleRange/suffix_exceeds_size1972=== CONT TestParseSingleRange/suffix1973=== CONT TestParseSingleRange/end_clamped_to_size1974=== CONT TestParseSingleRange/open-ended1975=== CONT TestParseSingleRange/closed1976=== CONT TestParseSingleRange/start_far_past_EOF1977=== CONT TestParseSingleRange/malformed_end_before_start1978--- PASS: TestService_RequireScope_OIDC (0.40s)1979 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1980 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1981 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1982 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1983 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1984 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1985 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1986 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1987 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1988 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1989 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1990 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1991 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1992 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1993=== CONT TestParseSingleRange/multi-range_ignored1994=== CONT TestParseSingleRange/unknown_unit1995=== CONT TestParseSingleRange/malformed_no_dash1996=== CONT TestParseSingleRange/malformed_both_empty1997--- PASS: TestParseSingleRange (0.00s)1998 --- PASS: TestParseSingleRange/none (0.00s)1999 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2000 --- PASS: TestParseSingleRange/single_byte (0.00s)2001 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2002 --- PASS: TestParseSingleRange/suffix (0.00s)2003 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2004 --- PASS: TestParseSingleRange/open-ended (0.00s)2005 --- PASS: TestParseSingleRange/closed (0.00s)2006 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2007 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2008 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2009 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2010 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2011 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2012=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale20132026/10/20 10:59:38 INFO Upload complete. (94ms)20142026/10/20 10:59:38 INFO lead: acquired remote=192.0.2.1:123420152026/10/20 10:59:38 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/present2016--- PASS: TestReadProxyDisabled (0.27s)2017=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh2018=== NAME TestNARDeduplicationMetadataUploadBug2019 metadata_upload_test.go:76: Retrieved narinfo from S3:2020 StorePath: /build/TestNARDeduplicationMetadataUploadBug1936993995/001/store/zhv8w7hid5f13mxc20sm5majdddh69rx-file2.txt2021 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2022 Compression: zstd2023 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2024 NarSize: 1602025 References: 2026 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2027 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2028 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2029 {"version":1,"root":{"type":"regular","size":44}}2030--- PASS: TestDeleteClosuresRacingPins (1.63s)2031--- PASS: TestNARDeduplicationMetadataUploadBug (0.68s)20322026/10/20 10:59:38 INFO Received cleanup request method=DELETE path=/api/pending_closures20332026/10/20 10:59:38 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket87/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""20342026/10/20 10:59:38 INFO Aborted multipart uploads count=0 kept=120352026/10/20 10:59:38 INFO Received cleanup request method=DELETE path=/api/pending_closures20362026/10/20 10:59:38 INFO Aborted multipart uploads count=1 kept=02037--- PASS: TestMultipartCleanup (0.37s)20382026/10/20 10:59:38 INFO Aborted multipart uploads count=0 kept=020392026/10/20 10:59:38 WARN Force mode enabled - objects will be deleted immediately without grace period20402026/10/20 10:59:38 INFO Aborted multipart uploads count=0 kept=020412026/10/20 10:59:38 WARN Force mode enabled - objects will be deleted immediately without grace period20422026/10/20 10:59:38 INFO Received uploads request method=POST path=/api/pending_closures20432026/10/20 10:59:38 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:35389/bucket93/?delete=\": context canceled"2044--- PASS: TestGCEndsOnShutdown (0.00s)2045 --- PASS: TestGCEndsOnShutdown/before_the_run (0.28s)2046 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.32s)2047 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.31s)20482026/10/20 10:59:38 WARN Request failed, retrying attempt=2 backoff=199.907148ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20492026/10/20 10:59:38 INFO Received uploads request method=POST path=/api/pending_closures20502026/10/20 10:59:38 INFO Aborted multipart uploads count=0 kept=020512026/10/20 10:59:38 WARN Force mode enabled - objects will be deleted immediately without grace period20522026/10/20 10:59:38 INFO Received uploads request method=POST path=/api/pending_closures20532026/10/20 10:59:38 INFO Aborted multipart uploads count=0 kept=020542026/10/20 10:59:38 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=020552026/10/20 10:59:38 INFO Vacuumed table table=pending_closures20562026/10/20 10:59:38 INFO Vacuumed table table=pending_objects20572026/10/20 10:59:38 INFO Vacuumed table table=multipart_uploads20582026/10/20 10:59:38 INFO Vacuumed table table=closures20592026/10/20 10:59:38 WARN Force mode enabled - objects will be deleted immediately without grace period20602026/10/20 10:59:38 INFO Vacuumed table table=objects20612026/10/20 10:59:38 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=020622026/10/20 10:59:38 INFO Vacuumed table table=pending_closures20632026/10/20 10:59:38 INFO Vacuumed table table=pending_objects20642026/10/20 10:59:38 INFO Vacuumed table table=multipart_uploads20652026/10/20 10:59:38 INFO Vacuumed table table=closures20662026/10/20 10:59:38 INFO Vacuumed table table=objects2067--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2068 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.31s)2069 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.32s)20702026/10/20 10:59:39 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20712026/10/20 10:59:39 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20722026/10/20 10:59:39 WARN Request failed, retrying attempt=3 backoff=387.168397ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2073=== NAME TestOrphanedObjectsGCStressTest2074 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains20752026/10/20 10:59:39 WARN Request failed, retrying attempt=4 backoff=811.154921ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2076--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2077 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.68s)2078 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.69s)2079=== NAME TestOrphanedObjectsGCStressTest2080 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion2081--- PASS: TestUploadHandlersRejectOversizedBody (0.14s)2082 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)2083 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.05s)2084 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.94s)2085--- PASS: TestObjectStatsLargeCommit (1.10s)2086--- PASS: TestPendingClosureWriteTimeout (0.00s)2087 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2088 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2089 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2090 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.05s)20912026/10/20 10:59:39 INFO lead: released remote=192.0.2.1:12342092--- PASS: TestLeadElectsOneAndHandsOver (2.83s)20932026/10/20 10:59:39 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02094=== NAME TestClientIntegration2095 client_integration_test.go:323: Objects in database after GC:2096 client_integration_test.go:323: Successfully deleted all objects with GC --force2097--- PASS: TestClientIntegration (2.62s)2098=== NAME TestOrphanedObjectsGCStressTest2099 orphaned_objects_gc_test.go:503: Stress test completed successfully:2100 orphaned_objects_gc_test.go:504: - Active objects preserved: 202101 orphaned_objects_gc_test.go:505: - Objects deleted: 2102102 orphaned_objects_gc_test.go:506: - Total GC'd: 2102103--- PASS: TestOrphanedObjectsGCStressTest (2.20s)21042026/10/20 10:59:40 WARN Request failed, retrying attempt=5 backoff=1.7072068s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21052026/10/20 10:59:40 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=021062026/10/20 10:59:40 INFO Received create pin request method=POST path=/api/pins/myapp21072026/10/20 10:59:40 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3748756100/001/store/k6p478vkghb1i55nkn0h1ygql56plla9-pinned-file.txt narinfo_key=k6p478vkghb1i55nkn0h1ygql56plla9.narinfo21082026/10/20 10:59:40 INFO Starting cleanup of old closures method=DELETE path=/api/closures21092026/10/20 10:59:40 INFO Garbage collection started21102026/10/20 10:59:40 INFO Aborted multipart uploads count=0 kept=021112026/10/20 10:59:40 WARN Force mode enabled - objects will be deleted immediately without grace period21122026/10/20 10:59: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=021132026/10/20 10:59:40 INFO Vacuumed table table=pending_closures21142026/10/20 10:59:40 INFO Vacuumed table table=pending_objects21152026/10/20 10:59:40 INFO Vacuumed table table=multipart_uploads21162026/10/20 10:59:40 INFO Vacuumed table table=closures21172026/10/20 10:59:40 INFO Vacuumed table table=objects21182026/10/20 10:59:41 WARN Rate limiter enabled after throttle name=s3-test rate=521192026/10/20 10:59:41 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2120=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2121 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102122 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002123--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.39s)21242026/10/20 10:59:42 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-config21252026/10/20 10:59:42 WARN Request failed, retrying attempt=2 backoff=215.022637ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2126--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.51s)2127--- PASS: TestConnectWaitsForAPeerMigration (5.11s)21282026/10/20 10:59:42 WARN Request failed, retrying attempt=3 backoff=429.684783ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2129=== NAME TestPinProtectsFromGC2130 client_integration_test.go:840: Pin successfully protected closure from garbage collection2131--- PASS: TestPinProtectsFromGC (4.64s)21322026/10/20 10:59:42 WARN Request failed, retrying attempt=4 backoff=783.117715ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21332026/10/20 10:59:43 WARN Request failed, retrying attempt=5 backoff=1.664417372s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21342026/10/20 10:59:44 INFO Aborted multipart uploads count=1 kept=021352026/10/20 10:59:44 INFO Received cleanup request method=DELETE path=/api/pending_closures21362026/10/20 10:59:44 INFO Aborted multipart uploads count=1 kept=02137--- PASS: TestPendingCleanupUsesOneCutoff (6.40s)21382026/10/20 10:59:45 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"21392026/10/20 10:59: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-config21402026/10/20 10:59:45 WARN Request failed, retrying attempt=2 backoff=218.013055ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21412026/10/20 10:59:45 WARN Request failed, retrying attempt=3 backoff=432.709649ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21422026/10/20 10:59:46 WARN Request failed, retrying attempt=4 backoff=857.598448ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21432026/10/20 10:59:46 WARN Request failed, retrying attempt=5 backoff=1.479842031s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21442026/10/20 10:59:48 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_closures21452026/10/20 10:59:48 WARN Request failed, retrying attempt=2 backoff=201.852085ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21462026/10/20 10:59:48 WARN Request failed, retrying attempt=3 backoff=377.522196ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21472026/10/20 10:59:49 WARN Request failed, retrying attempt=4 backoff=775.435795ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21482026/10/20 10:59:49 WARN Request failed, retrying attempt=5 backoff=1.574373383s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2149--- PASS: TestClientErrorHandling (0.00s)2150 --- PASS: TestClientErrorHandling/InvalidStorePath (0.29s)2151 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.37s)2152 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.68s)2153PASS21542026-10-20 10:59:51.613 UTC [127] LOG: received smart shutdown request21552026-10-20 10:59:51.617 UTC [127] LOG: background worker "logical replication launcher" (PID 137) exited with exit code 121562026-10-20 10:59:51.629 UTC [132] LOG: shutting down21572026-10-20 10:59:51.629 UTC [132] LOG: checkpoint starting: shutdown immediate21582026-10-20 10:59:52.486 UTC [132] LOG: checkpoint complete: wrote 11485 buffers (70.1%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.176 s, sync=0.646 s, total=0.857 s; sync files=34046, longest=0.007 s, average=0.001 s; distance=531576 kB, estimate=531576 kB; lsn=0/21E83DF8, redo lsn=0/21E83DF821592026-10-20 10:59:52.558 UTC [127] LOG: database system is shut down2160Running OIDC tests...2161=== RUN TestAudienceForIssuer2162=== PAUSE TestAudienceForIssuer2163=== RUN TestGlobMatch2164=== PAUSE TestGlobMatch2165=== RUN TestValidateToken_ValidToken2166=== PAUSE TestValidateToken_ValidToken2167=== RUN TestValidateToken_WrongAudience2168=== PAUSE TestValidateToken_WrongAudience2169=== RUN TestValidateToken_Expired2170=== PAUSE TestValidateToken_Expired2171=== RUN TestValidateToken_BoundClaimsMismatch2172=== PAUSE TestValidateToken_BoundClaimsMismatch2173=== RUN TestValidateToken_BoundSubjectMismatch2174=== PAUSE TestValidateToken_BoundSubjectMismatch2175=== RUN TestValidateToken_MultipleProviders2176=== PAUSE TestValidateToken_MultipleProviders2177=== RUN TestValidateToken_NoMatchingProvider2178=== PAUSE TestValidateToken_NoMatchingProvider2179=== RUN TestValidateToken_KubernetesServiceAccount2180=== PAUSE TestValidateToken_KubernetesServiceAccount2181=== RUN TestNewValidator_KubernetesRequiresCA2182=== PAUSE TestNewValidator_KubernetesRequiresCA2183=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2184=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2185=== RUN TestPins_ReservedForMatchingRule2186=== PAUSE TestPins_ReservedForMatchingRule2187=== RUN TestPins_TopLevelShorthand2188=== PAUSE TestPins_TopLevelShorthand2189=== RUN TestPins_ConfigValidation2190=== PAUSE TestPins_ConfigValidation2191=== RUN TestScopes_LegacyProviderDefaultsToWrite2192=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2193=== RUN TestScopes_Rules2194=== PAUSE TestScopes_Rules2195=== RUN TestScopes_ConfigValidation2196=== PAUSE TestScopes_ConfigValidation2197=== CONT TestAudienceForIssuer2198=== CONT TestValidateToken_KubernetesServiceAccount2199=== CONT TestValidateToken_WrongAudience2200--- PASS: TestAudienceForIssuer (0.00s)2201=== CONT TestValidateToken_ValidToken2202=== CONT TestGlobMatch2203=== RUN TestGlobMatch/foo_foo2204=== PAUSE TestGlobMatch/foo_foo2205=== RUN TestGlobMatch/foo_bar2206=== PAUSE TestGlobMatch/foo_bar2207=== CONT TestPins_ConfigValidation2208=== CONT TestValidateToken_BoundClaimsMismatch2209=== CONT TestValidateToken_NoMatchingProvider2210=== CONT TestScopes_ConfigValidation2211--- PASS: TestPins_ConfigValidation (0.00s)2212=== CONT TestScopes_Rules2213=== CONT TestScopes_LegacyProviderDefaultsToWrite2214=== CONT TestValidateToken_MultipleProviders2215=== CONT TestValidateToken_Expired2216=== CONT TestValidateToken_BoundSubjectMismatch2217=== CONT TestPins_ReservedForMatchingRule2218=== CONT TestPins_TopLevelShorthand2219=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2220=== CONT TestNewValidator_KubernetesRequiresCA2221=== RUN TestGlobMatch/*_2222=== PAUSE TestGlobMatch/*_2223=== RUN TestGlobMatch/*_anything2224=== PAUSE TestGlobMatch/*_anything2225=== RUN TestGlobMatch/foo*_foo2226=== PAUSE TestGlobMatch/foo*_foo2227=== RUN TestGlobMatch/foo*_foobar2228=== PAUSE TestGlobMatch/foo*_foobar2229=== RUN TestGlobMatch/foo*_bar2230=== PAUSE TestGlobMatch/foo*_bar2231=== RUN TestGlobMatch/*bar_bar2232=== PAUSE TestGlobMatch/*bar_bar2233=== RUN TestGlobMatch/*bar_foobar2234=== PAUSE TestGlobMatch/*bar_foobar2235=== RUN TestGlobMatch/*bar_foo2236=== PAUSE TestGlobMatch/*bar_foo2237=== RUN TestGlobMatch/foo*bar_foobar2238=== PAUSE TestGlobMatch/foo*bar_foobar2239=== RUN TestGlobMatch/foo*bar_foo123bar2240=== PAUSE TestGlobMatch/foo*bar_foo123bar2241=== RUN TestGlobMatch/foo*bar_foobarbaz2242=== PAUSE TestGlobMatch/foo*bar_foobarbaz2243=== RUN TestGlobMatch/*/*_foo/bar2244=== PAUSE TestGlobMatch/*/*_foo/bar2245=== RUN TestGlobMatch/*/*_foo2246=== PAUSE TestGlobMatch/*/*_foo2247=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2248=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2249=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02250=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02251=== RUN TestGlobMatch/refs/*/main_refs/heads/main2252=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2253=== RUN TestGlobMatch/fo?_foo2254=== PAUSE TestGlobMatch/fo?_foo2255=== RUN TestGlobMatch/fo?_fo2256=== PAUSE TestGlobMatch/fo?_fo2257=== RUN TestGlobMatch/fo?_fooo2258=== PAUSE TestGlobMatch/fo?_fooo2259=== RUN TestGlobMatch/?oo_foo2260=== PAUSE TestGlobMatch/?oo_foo2261=== RUN TestGlobMatch/?oo_boo2262=== PAUSE TestGlobMatch/?oo_boo2263=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2264=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2265=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2266--- PASS: TestScopes_ConfigValidation (0.00s)2267=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2268=== CONT TestGlobMatch/foo_foo2269=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2270=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2271=== CONT TestGlobMatch/?oo_boo2272=== CONT TestGlobMatch/?oo_foo2273=== CONT TestGlobMatch/foo*bar_foobar2274=== CONT TestGlobMatch/*bar_foo2275=== CONT TestGlobMatch/*bar_foobar2276=== CONT TestGlobMatch/*bar_bar2277=== CONT TestGlobMatch/foo*_bar2278=== CONT TestGlobMatch/foo*_foobar2279=== CONT TestGlobMatch/foo*_foo2280=== CONT TestGlobMatch/*_anything2281=== CONT TestGlobMatch/*_2282=== CONT TestGlobMatch/fo?_fo2283=== CONT TestGlobMatch/foo*bar_foobarbaz2284=== CONT TestGlobMatch/fo?_fooo2285=== CONT TestGlobMatch/foo*bar_foo123bar2286=== CONT TestGlobMatch/foo_bar2287=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2288=== CONT TestGlobMatch/fo?_foo2289=== CONT TestGlobMatch/refs/*/main_refs/heads/main2290=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02291=== CONT TestGlobMatch/*/*_foo/bar2292=== CONT TestGlobMatch/*/*_foo2293--- PASS: TestGlobMatch (0.01s)2294 --- PASS: TestGlobMatch/foo_foo (0.00s)2295 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2296 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2297 --- PASS: TestGlobMatch/?oo_boo (0.00s)2298 --- PASS: TestGlobMatch/?oo_foo (0.00s)2299 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2300 --- PASS: TestGlobMatch/*bar_foo (0.00s)2301 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2302 --- PASS: TestGlobMatch/*bar_bar (0.00s)2303 --- PASS: TestGlobMatch/foo*_bar (0.00s)2304 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2305 --- PASS: TestGlobMatch/foo*_foo (0.00s)2306 --- PASS: TestGlobMatch/*_anything (0.00s)2307 --- PASS: TestGlobMatch/*_ (0.00s)2308 --- PASS: TestGlobMatch/fo?_fo (0.00s)2309 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2310 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2311 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2312 --- PASS: TestGlobMatch/foo_bar (0.00s)2313 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2314 --- PASS: TestGlobMatch/fo?_foo (0.00s)2315 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2316 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2317 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2318 --- PASS: TestGlobMatch/*/*_foo (0.00s)23192026/10/20 10:59:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44527/oidc23202026/10/20 10:59:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45953/oidc2321--- PASS: TestValidateToken_BoundSubjectMismatch (0.05s)2322--- PASS: TestValidateToken_ValidToken (0.05s)23232026/10/20 10:59:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38605/oidc2324--- PASS: TestValidateToken_BoundClaimsMismatch (0.07s)23252026/10/20 10:59:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36529/oidc2326--- PASS: TestValidateToken_WrongAudience (0.09s)23272026/10/20 10:59:54 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232328--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.10s)23292026/10/20 10:59:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33187/oidc2330--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.11s)23312026/10/20 10:59:54 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:39447/oidc23322026/10/20 10:59:54 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:42483/oidc2333--- PASS: TestValidateToken_MultipleProviders (0.11s)23342026/10/20 10:59:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44743/oidc2335--- PASS: TestValidateToken_Expired (0.12s)23362026/10/20 10:59:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32851/oidc2337--- PASS: TestPins_ReservedForMatchingRule (0.13s)23382026/10/20 10:59:54 http: TLS handshake error from 127.0.0.1:45658: remote error: tls: bad certificate2339--- PASS: TestNewValidator_KubernetesRequiresCA (0.13s)23402026/10/20 10:59:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36923/oidc2341--- PASS: TestScopes_Rules (0.16s)23422026/10/20 10:59:54 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:46659/oidc2343--- PASS: TestValidateToken_NoMatchingProvider (0.21s)23442026/10/20 10:59:54 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:411612345--- PASS: TestValidateToken_KubernetesServiceAccount (0.26s)23462026/10/20 10:59:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43533/oidc2347--- PASS: TestPins_TopLevelShorthand (0.40s)2348PASS2349Running hook tests...2350=== RUN TestSendPathsEmpty2351=== PAUSE TestSendPathsEmpty2352=== RUN TestQueueEnqueueAndFetch2353=== PAUSE TestQueueEnqueueAndFetch2354=== RUN TestQueueDeduplication2355=== PAUSE TestQueueDeduplication2356=== RUN TestQueueRemove2357=== PAUSE TestQueueRemove2358=== RUN TestQueueFetchBatchLimit2359=== PAUSE TestQueueFetchBatchLimit2360=== RUN TestQueueRetryMovesToBack2361=== PAUSE TestQueueRetryMovesToBack2362=== RUN TestQueueFetchRemoveLifecycle2363=== PAUSE TestQueueFetchRemoveLifecycle2364=== RUN TestQueueConcurrentWriters2365=== PAUSE TestQueueConcurrentWriters2366=== RUN TestQueueRemoveLargeClosure2367=== PAUSE TestQueueRemoveLargeClosure2368=== RUN TestServerClientIntegration2369--- PASS: TestServerClientIntegration (0.00s)2370=== RUN TestServerQueueError23712026/10/20 10:59:54 ERROR Failed to queue paths error="permission denied" count=12372--- PASS: TestServerQueueError (0.00s)2373=== RUN TestGetListenerSocketActivation2374 server_test.go:219: === RUN TestGetListenerSocketActivation2375 --- PASS: TestGetListenerSocketActivation (0.00s)2376 PASS2377 2378--- PASS: TestGetListenerSocketActivation (0.01s)2379=== RUN TestDrainIsolatesPoisonPath2380=== PAUSE TestDrainIsolatesPoisonPath2381=== RUN TestRunNotBlockedByPoisonHead2382=== PAUSE TestRunNotBlockedByPoisonHead2383=== RUN TestDrainGivesUpWhenServerDown2384=== PAUSE TestDrainGivesUpWhenServerDown2385=== RUN TestFailedPathPrunedByLaterClosure2386=== PAUSE TestFailedPathPrunedByLaterClosure2387=== RUN TestWorkerUploadsAndRemoves2388=== PAUSE TestWorkerUploadsAndRemoves2389=== RUN TestWorkerSkipsGCdPaths2390=== PAUSE TestWorkerSkipsGCdPaths2391=== RUN TestWorkerPrunesClosureDeps2392=== PAUSE TestWorkerPrunesClosureDeps2393=== RUN TestDrainTimeout2394=== PAUSE TestDrainTimeout2395=== CONT TestSendPathsEmpty2396=== CONT TestWorkerPrunesClosureDeps2397--- PASS: TestSendPathsEmpty (0.00s)2398=== CONT TestWorkerSkipsGCdPaths2399=== CONT TestWorkerUploadsAndRemoves2400=== CONT TestFailedPathPrunedByLaterClosure2401=== CONT TestQueueRetryMovesToBack2402=== CONT TestQueueFetchBatchLimit2403=== CONT TestQueueRemove2404=== CONT TestQueueDeduplication2405=== CONT TestQueueEnqueueAndFetch2406=== CONT TestDrainTimeout2407=== CONT TestDrainIsolatesPoisonPath2408=== CONT TestDrainGivesUpWhenServerDown2409=== CONT TestRunNotBlockedByPoisonHead2410=== CONT TestQueueConcurrentWriters2411=== CONT TestQueueFetchRemoveLifecycle2412=== CONT TestQueueRemoveLargeClosure24132026/10/20 10:59:54 INFO Uploading batch count=224142026/10/20 10:59:54 INFO Uploading batch count=224152026/10/20 10:59:54 ERROR Upload failed error="upload failed" count=224162026/10/20 10:59:54 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1809636727/002/a24172026/10/20 10:59:54 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1809636727/002/b24182026/10/20 10:59:54 INFO Upload queue status pending=224192026/10/20 10:59:54 INFO Upload queue status pending=324202026/10/20 10:59:54 INFO Uploading batch count=124212026/10/20 10:59:54 INFO Uploading batch count=124222026/10/20 10:59:54 ERROR Upload failed error="upload failed" count=12423--- PASS: TestQueueRemove (0.01s)24242026/10/20 10:59:54 INFO Uploading batch count=424252026/10/20 10:59:54 ERROR Upload failed error="upload failed" count=42426--- PASS: TestQueueRetryMovesToBack (0.02s)2427--- PASS: TestQueueFetchBatchLimit (0.02s)24282026/10/20 10:59:54 INFO Upload queue status pending=224292026/10/20 10:59:54 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths472549793/002/nonexistent24302026/10/20 10:59:54 INFO Uploading batch count=124312026/10/20 10:59:54 ERROR Upload failed error="upload failed" count=124322026/10/20 10:59:54 INFO Uploading batch count=224332026/10/20 10:59:54 ERROR Upload failed error="upload failed" count=224342026/10/20 10:59:54 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1809636727/002/c24352026/10/20 10:59:54 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2229022846/002/bbb24362026/10/20 10:59:54 INFO Upload queue status pending=22437--- PASS: TestQueueEnqueueAndFetch (0.02s)24382026/10/20 10:59:54 INFO Uploading batch count=224392026/10/20 10:59:54 INFO Uploading batch count=12440--- PASS: TestQueueDeduplication (0.02s)24412026/10/20 10:59:54 INFO Uploading batch count=12442--- PASS: TestQueueFetchRemoveLifecycle (0.02s)24432026/10/20 10:59:54 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1809636727/002/d24442026/10/20 10:59:54 INFO Uploading batch count=124452026/10/20 10:59:54 INFO Uploading batch count=224462026/10/20 10:59:54 ERROR Upload failed error="upload failed" count=224472026/10/20 10:59:54 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1809636727/002/e24482026/10/20 10:59:54 INFO Uploading batch count=124492026/10/20 10:59:54 ERROR Upload failed error="upload failed" count=124502026/10/20 10:59:54 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1809636727/002/f24512026/10/20 10:59:54 INFO Uploading batch count=124522026/10/20 10:59:54 ERROR Upload failed error="upload failed" count=124532026/10/20 10:59:54 ERROR Drain finished with paths left in queue remaining=102454--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)24552026/10/20 10:59:54 INFO Uploading batch count=124562026/10/20 10:59:54 ERROR Upload failed error="upload failed" count=124572026/10/20 10:59:54 ERROR Drain finished with paths left in queue remaining=12458--- PASS: TestDrainIsolatesPoisonPath (0.02s)2459--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2460--- PASS: TestWorkerPrunesClosureDeps (0.04s)2461--- PASS: TestWorkerSkipsGCdPaths (0.04s)2462--- PASS: TestWorkerUploadsAndRemoves (0.04s)2463--- PASS: TestQueueRemoveLargeClosure (0.08s)2464--- PASS: TestQueueConcurrentWriters (0.15s)24652026/10/20 10:59:54 ERROR Upload failed error="context deadline exceeded" count=224662026/10/20 10:59:54 ERROR Drain finished with paths left in queue remaining=42467--- PASS: TestDrainTimeout (0.21s)24682026/10/20 10:59:55 INFO Uploading batch count=124692026/10/20 10:59:55 INFO Uploading batch count=124702026/10/20 10:59:55 INFO Uploading batch count=124712026/10/20 10:59:55 ERROR Upload failed error="upload failed" count=124722026/10/20 10:59:55 INFO Uploading batch count=124732026/10/20 10:59:55 ERROR Upload failed error="upload failed" count=124742026/10/20 10:59:55 INFO Uploading batch count=124752026/10/20 10:59:55 ERROR Upload failed error="upload failed" count=124762026/10/20 10:59:55 INFO Uploading batch count=124772026/10/20 10:59:55 ERROR Upload failed error="upload failed" count=124782026/10/20 10:59:55 ERROR Drain finished with paths left in queue remaining=12479--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2480PASS2481Running signing tests...2482=== RUN TestExternalSigner2483=== PAUSE TestExternalSigner2484=== RUN TestExternalSignerWrongPublicKey2485=== PAUSE TestExternalSignerWrongPublicKey2486=== RUN TestExternalSignerErrors2487=== PAUSE TestExternalSignerErrors2488=== RUN TestExternalSignerRestartsAfterCrash2489=== PAUSE TestExternalSignerRestartsAfterCrash2490=== RUN TestExternalSignerProgramErrorKeepsProcess2491=== PAUSE TestExternalSignerProgramErrorKeepsProcess2492=== RUN TestExternalSignerClose2493=== PAUSE TestExternalSignerClose2494=== RUN TestExternalSignerRejectsInvalidPublicKey2495=== PAUSE TestExternalSignerRejectsInvalidPublicKey2496=== RUN TestExternalSignerCancellation2497=== PAUSE TestExternalSignerCancellation2498=== RUN TestGenerateFingerprint2499=== PAUSE TestGenerateFingerprint2500=== RUN TestParseSigningKey2501=== PAUSE TestParseSigningKey2502=== RUN TestSign2503=== PAUSE TestSign2504=== RUN TestSignBatch2505=== PAUSE TestSignBatch2506=== RUN TestNilKeyPublicKey2507=== PAUSE TestNilKeyPublicKey2508=== RUN TestSignErrors2509=== PAUSE TestSignErrors2510=== CONT TestExternalSigner2511=== CONT TestSignBatch2512=== CONT TestExternalSignerCancellation2513=== CONT TestExternalSignerProgramErrorKeepsProcess2514=== CONT TestExternalSignerRejectsInvalidPublicKey2515=== CONT TestSign2516=== CONT TestParseSigningKey2517=== RUN TestParseSigningKey/valid_32-byte_key2518=== CONT TestGenerateFingerprint2519=== CONT TestSignErrors2520=== CONT TestExternalSignerErrors2521=== CONT TestExternalSignerRestartsAfterCrash2522=== RUN TestExternalSignerErrors/too_few_signatures2523=== PAUSE TestExternalSignerErrors/too_few_signatures2524=== RUN TestExternalSignerErrors/invalid_JSON2525=== PAUSE TestExternalSignerErrors/invalid_JSON2526=== CONT TestNilKeyPublicKey2527--- PASS: TestNilKeyPublicKey (0.00s)2528=== CONT TestExternalSignerWrongPublicKey2529=== CONT TestExternalSignerClose2530=== RUN TestExternalSignerRejectsInvalidPublicKey/#002531=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002532=== PAUSE TestParseSigningKey/valid_32-byte_key2533=== RUN TestGenerateFingerprint/basic_with_references2534=== PAUSE TestGenerateFingerprint/basic_with_references2535=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2536=== RUN TestExternalSignerErrors/wrong_shape2537=== PAUSE TestExternalSignerErrors/wrong_shape2538=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2539=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2540=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2541=== RUN TestGenerateFingerprint/no_references2542=== PAUSE TestGenerateFingerprint/no_references2543=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2544=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2545=== RUN TestExternalSignerErrors/wrong_id2546=== RUN TestParseSigningKey/no_colon2547=== PAUSE TestExternalSignerErrors/wrong_id2548=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2549=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2550=== PAUSE TestParseSigningKey/no_colon2551=== RUN TestParseSigningKey/empty_name2552=== RUN TestExternalSignerErrors/missing_signature_name2553=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2554=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2555=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2556=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2557=== PAUSE TestParseSigningKey/empty_name2558=== RUN TestParseSigningKey/invalid_base642559=== PAUSE TestParseSigningKey/invalid_base642560=== RUN TestParseSigningKey/wrong_length2561=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2562=== PAUSE TestExternalSignerErrors/missing_signature_name2563=== RUN TestGenerateFingerprint/invalid_nar_hash_length2564=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2565=== RUN TestGenerateFingerprint/invalid_store_path_prefix2566=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2567=== RUN TestGenerateFingerprint/invalid_reference_prefix2568=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2569=== CONT TestGenerateFingerprint/basic_with_references2570=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2571=== CONT TestExternalSignerRejectsInvalidPublicKey/#002572=== CONT TestGenerateFingerprint/invalid_reference_prefix2573=== CONT TestGenerateFingerprint/invalid_store_path_prefix2574=== PAUSE TestParseSigningKey/wrong_length2575=== CONT TestParseSigningKey/valid_32-byte_key2576=== RUN TestSignErrors/nil_key2577=== PAUSE TestSignErrors/nil_key2578=== RUN TestSignErrors/nil_narinfo2579=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2580=== PAUSE TestSignErrors/nil_narinfo2581=== RUN TestSignErrors/invalid_narinfo2582=== PAUSE TestSignErrors/invalid_narinfo2583=== CONT TestParseSigningKey/invalid_base642584=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2585=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2586=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2587=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2588=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2589=== CONT TestGenerateFingerprint/invalid_nar_hash_length2590=== CONT TestGenerateFingerprint/no_references2591=== RUN TestExternalSignerErrors/invalid_signature_base642592=== PAUSE TestExternalSignerErrors/invalid_signature_base642593=== RUN TestExternalSignerErrors/program_error2594=== PAUSE TestExternalSignerErrors/program_error2595=== CONT TestParseSigningKey/wrong_length2596=== CONT TestParseSigningKey/empty_name2597=== CONT TestParseSigningKey/no_colon2598--- PASS: TestSign (0.00s)2599=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2600=== RUN TestSignErrors/canceled2601=== PAUSE TestSignErrors/canceled2602=== CONT TestSignErrors/nil_key2603--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2604 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2605 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2606 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2607 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2608 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2609--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2610=== CONT TestSignErrors/invalid_narinfo2611=== RUN TestExternalSignerErrors/exit_at_startup2612=== PAUSE TestExternalSignerErrors/exit_at_startup2613=== RUN TestExternalSignerErrors/exit_on_request2614=== CONT TestSignErrors/canceled2615=== CONT TestSignErrors/nil_narinfo2616--- PASS: TestGenerateFingerprint (0.00s)2617 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2618 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2619 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2620 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2621 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2622 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2623 --- PASS: TestGenerateFingerprint/no_references (0.00s)2624--- PASS: TestSignBatch (0.00s)2625=== PAUSE TestExternalSignerErrors/exit_on_request2626=== RUN TestExternalSignerErrors/null_signatures2627=== PAUSE TestExternalSignerErrors/null_signatures2628=== RUN TestExternalSignerErrors/wrong_signatures_shape2629=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2630--- PASS: TestParseSigningKey (0.00s)2631 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2632 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2633 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2634 --- PASS: TestParseSigningKey/wrong_length (0.00s)2635 --- PASS: TestParseSigningKey/empty_name (0.00s)2636 --- PASS: TestParseSigningKey/no_colon (0.00s)2637--- PASS: TestExternalSignerClose (0.00s)2638=== RUN TestExternalSignerErrors/unrequested_key2639--- PASS: TestSignErrors (0.00s)2640 --- PASS: TestSignErrors/nil_key (0.00s)2641 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2642 --- PASS: TestSignErrors/canceled (0.00s)2643 --- PASS: TestSignErrors/nil_narinfo (0.00s)2644--- PASS: TestExternalSignerWrongPublicKey (0.00s)2645=== PAUSE TestExternalSignerErrors/unrequested_key2646=== RUN TestExternalSignerErrors/wrong_signature_length2647=== PAUSE TestExternalSignerErrors/wrong_signature_length2648=== RUN TestExternalSignerErrors/null2649=== PAUSE TestExternalSignerErrors/null2650=== RUN TestExternalSignerErrors/wrong_signature_name2651=== PAUSE TestExternalSignerErrors/wrong_signature_name2652=== RUN TestExternalSignerErrors/missing_signatures2653=== PAUSE TestExternalSignerErrors/missing_signatures2654=== CONT TestExternalSignerErrors/too_few_signatures2655=== CONT TestExternalSignerErrors/exit_on_request2656=== CONT TestExternalSignerErrors/invalid_JSON2657=== CONT TestExternalSignerErrors/wrong_id2658=== CONT TestExternalSignerErrors/exit_at_startup2659=== CONT TestExternalSignerErrors/program_error2660=== CONT TestExternalSignerErrors/invalid_signature_base642661=== CONT TestExternalSignerErrors/wrong_shape2662=== CONT TestExternalSignerErrors/wrong_signature_length2663=== CONT TestExternalSignerErrors/missing_signatures2664=== CONT TestExternalSignerErrors/wrong_signature_name2665=== CONT TestExternalSignerErrors/wrong_signatures_shape2666=== CONT TestExternalSignerErrors/null2667=== CONT TestExternalSignerErrors/unrequested_key2668=== CONT TestExternalSignerErrors/null_signatures2669=== CONT TestExternalSignerErrors/missing_signature_name2670--- PASS: TestExternalSigner (0.01s)2671--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2672--- PASS: TestExternalSignerErrors (0.00s)2673 --- PASS: TestExternalSignerErrors/too_few_signatures (0.00s)2674 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2675 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2676 --- PASS: TestExternalSignerErrors/program_error (0.00s)2677 --- PASS: TestExternalSignerErrors/wrong_id (0.00s)2678 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.00s)2679 --- PASS: TestExternalSignerErrors/invalid_JSON (0.00s)2680 --- PASS: TestExternalSignerErrors/unrequested_key (0.00s)2681 --- PASS: TestExternalSignerErrors/null (0.00s)2682 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.00s)2683 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2684 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2685 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2686 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2687 --- PASS: TestExternalSignerErrors/null_signatures (0.00s)2688 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)2689--- PASS: TestExternalSignerCancellation (0.02s)2690PASS2691Running OpenBao signer tests...2692=== RUN TestSign2693=== PAUSE TestSign2694=== RUN TestSignErrors2695=== PAUSE TestSignErrors2696=== RUN TestServe2697=== PAUSE TestServe2698=== RUN TestServeRejectsGarbage2699=== PAUSE TestServeRejectsGarbage2700=== CONT TestSign2701=== CONT TestServeRejectsGarbage2702=== CONT TestServe2703=== CONT TestSignErrors2704--- PASS: TestServeRejectsGarbage (0.00s)2705=== RUN TestSignErrors/http_error2706=== PAUSE TestSignErrors/http_error2707=== RUN TestSignErrors/invalid_json2708=== PAUSE TestSignErrors/invalid_json2709=== RUN TestSignErrors/no_prefix2710=== PAUSE TestSignErrors/no_prefix2711=== RUN TestSignErrors/invalid_base642712=== PAUSE TestSignErrors/invalid_base642713=== CONT TestSignErrors/http_error2714=== CONT TestSignErrors/no_prefix2715=== CONT TestSignErrors/invalid_base642716=== CONT TestSignErrors/invalid_json2717--- PASS: TestServe (0.00s)2718--- PASS: TestSign (0.00s)2719--- PASS: TestSignErrors (0.00s)2720 --- PASS: TestSignErrors/invalid_base64 (0.00s)2721 --- PASS: TestSignErrors/invalid_json (0.00s)2722 --- PASS: TestSignErrors/no_prefix (0.00s)2723 --- PASS: TestSignErrors/http_error (0.00s)2724PASS