niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #415
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestUploadMultipart_PartsInParallel18=== PAUSE TestUploadMultipart_PartsInParallel19=== RUN TestPartSizeForNAR20=== PAUSE TestPartSizeForNAR21=== RUN TestUploadMultipart_SupersededByPeer22=== PAUSE TestUploadMultipart_SupersededByPeer23=== RUN TestDumpPathCaseHackMatchesNix24--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)25=== RUN TestDumpPathCaseHackCollision26--- PASS: TestDumpPathCaseHackCollision (0.00s)27=== RUN TestSupersededNARStillUploadsListing28=== PAUSE TestSupersededNARStillUploadsListing29=== RUN TestDumpPathMatchesNix30=== PAUSE TestDumpPathMatchesNix31=== RUN TestDumpPathSingleFile32=== PAUSE TestDumpPathSingleFile33=== RUN TestDumpPathWriterError34=== PAUSE TestDumpPathWriterError35=== RUN TestEncodeNixBase3236=== PAUSE TestEncodeNixBase3237=== RUN TestEncodeNixBase32WithRealHash38=== PAUSE TestEncodeNixBase32WithRealHash39=== RUN TestConvertHashToNix3240=== PAUSE TestConvertHashToNix3241=== RUN TestGetStorePathHash42=== PAUSE TestGetStorePathHash43=== RUN TestPathInfoHashCompatibility44=== PAUSE TestPathInfoHashCompatibility45=== RUN TestParsePathInfoJSON46=== PAUSE TestParsePathInfoJSON47=== RUN TestParsePathInfoJSONMultiplePaths48=== PAUSE TestParsePathInfoJSONMultiplePaths49=== RUN TestPathInfoCACompatibility50=== PAUSE TestPathInfoCACompatibility51=== RUN TestRateLimiterFeedback52=== PAUSE TestRateLimiterFeedback53=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess54=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess55=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer56=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer57=== RUN TestResolveStorePath58=== PAUSE TestResolveStorePath59=== RUN TestDoWithRetry_BodyReplayedViaGetBody60=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody61=== RUN TestRetryTimeoutOutlastsMaxRetries62=== PAUSE TestRetryTimeoutOutlastsMaxRetries63=== RUN TestDoWithRetry_FinalResponseBodyReadable64=== PAUSE TestDoWithRetry_FinalResponseBodyReadable65=== RUN TestShellSplit66=== PAUSE TestShellSplit67=== RUN TestShellSplitErrors68=== PAUSE TestShellSplitErrors69=== RUN TestStreamPushReportsEveryPath70=== PAUSE TestStreamPushReportsEveryPath71=== RUN TestStreamPushBatchesUnderLoad72=== PAUSE TestStreamPushBatchesUnderLoad73=== RUN TestStreamPushIsolatesFailures74=== PAUSE TestStreamPushIsolatesFailures75=== RUN TestStreamPushGivesUpOnDeadServer76=== PAUSE TestStreamPushGivesUpOnDeadServer77=== RUN TestStreamPushRequestLine78=== PAUSE TestStreamPushRequestLine79=== RUN TestStreamPushReportsSignatures80=== PAUSE TestStreamPushReportsSignatures81=== RUN TestStreamPushReportsSkippedPaths82=== PAUSE TestStreamPushReportsSkippedPaths83=== RUN TestClientSignaturesByStorePath84=== PAUSE TestClientSignaturesByStorePath85=== RUN TestStreamPushStopsWhenCanceled86=== PAUSE TestStreamPushStopsWhenCanceled87=== RUN TestSetClientTLS88=== PAUSE TestSetClientTLS89=== RUN TestSetClientTLSDoesNotMutateDefaultTransport90=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport91=== RUN TestSetClientTLSErrors92=== PAUSE TestSetClientTLSErrors93=== RUN TestStaticToken94=== PAUSE TestStaticToken95=== RUN TestFileTokenReadsAndCaches96=== PAUSE TestFileTokenReadsAndCaches97=== RUN TestFileTokenMissing98=== PAUSE TestFileTokenMissing99=== RUN TestFileTokenEmpty100=== PAUSE TestFileTokenEmpty101=== RUN TestScriptTokenNoExpiryRerunsEveryCall102=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall103=== RUN TestScriptTokenCachesUntilRefresh104=== PAUSE TestScriptTokenCachesUntilRefresh105=== RUN TestScriptTokenEmptyToken106=== PAUSE TestScriptTokenEmptyToken107=== RUN TestScriptTokenBadJSON108=== PAUSE TestScriptTokenBadJSON109=== RUN TestScriptTokenScriptFails110=== PAUSE TestScriptTokenScriptFails111=== RUN TestScriptTokenEmptyCommand112=== PAUSE TestScriptTokenEmptyCommand113=== CONT TestDoServerRequestAttachesToken114=== CONT TestFileTokenEmpty115=== CONT TestPathInfoCACompatibility116=== RUN TestPathInfoCACompatibility/null_ca_field117=== PAUSE TestPathInfoCACompatibility/null_ca_field118=== RUN TestPathInfoCACompatibility/old_string_format_-_text119=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text120=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive121=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive122=== RUN TestPathInfoCACompatibility/new_structured_format_-_text123=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text124=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method125=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method126=== CONT TestSetClientTLSErrors127--- PASS: TestFileTokenEmpty (0.00s)128=== CONT TestStreamPushBatchesUnderLoad129=== CONT TestStreamPushIsolatesFailures1302026/10/14 16:44:49 ERROR Upload failed error="bad path" count=3131--- PASS: TestStreamPushIsolatesFailures (0.00s)132=== CONT TestStreamPushReportsEveryPath133--- PASS: TestStreamPushReportsEveryPath (0.00s)134=== CONT TestShellSplitErrors135--- PASS: TestShellSplitErrors (0.00s)136=== CONT TestShellSplit137--- PASS: TestShellSplit (0.00s)138=== CONT TestDoWithRetry_FinalResponseBodyReadable139=== CONT TestScriptTokenEmptyCommand140--- PASS: TestScriptTokenEmptyCommand (0.00s)141=== CONT TestRetryTimeoutOutlastsMaxRetries142=== CONT TestScriptTokenCachesUntilRefresh143=== CONT TestScriptTokenEmptyToken144=== CONT TestScriptTokenScriptFails145=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess146=== CONT TestScriptTokenNoExpiryRerunsEveryCall147=== CONT TestFileTokenMissing1482026/10/14 16:44:49 WARN Rate limiter enabled after throttle name=server-test rate=51492026/10/14 16:44:49 WARN Rate limiter enabled after throttle name=server-test rate=51502026/10/14 16:44:49 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:46759151=== CONT TestDumpPathSingleFile1522026/10/14 16:44:49 WARN Rate limiter backed off name=server-test rate=5153=== CONT TestFileTokenReadsAndCaches154=== CONT TestRateLimiterFeedback155=== RUN TestRateLimiterFeedback/429_enables_limiter156=== CONT TestStaticToken157=== CONT TestSetClientTLSDoesNotMutateDefaultTransport158=== CONT TestSetClientTLS159=== CONT TestStreamPushStopsWhenCanceled160=== CONT TestResolveStorePath1612026/10/14 16:44:49 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:46143162=== CONT TestStreamPushReportsSkippedPaths163=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer164=== CONT TestGetStorePathHash165=== CONT TestStreamPushReportsSignatures166=== CONT TestStreamPushRequestLine167=== CONT TestStreamPushGivesUpOnDeadServer168=== CONT TestScriptTokenBadJSON169=== RUN TestSetClientTLSErrors/missing_cert_file170--- PASS: TestFileTokenMissing (0.00s)171--- PASS: TestDoServerRequestAttachesToken (0.01s)172=== CONT TestDoWithRetry_BodyReplayedViaGetBody173=== CONT TestClientSignaturesByStorePath174=== CONT TestFilterOversizedClosures175=== RUN TestGetStorePathHash/valid_store_path176=== PAUSE TestRateLimiterFeedback/429_enables_limiter177=== CONT TestParsePathInfoJSONMultiplePaths178=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths179=== RUN TestRateLimiterFeedback/503_enables_limiter180=== PAUSE TestRateLimiterFeedback/503_enables_limiter181=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter182=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter183=== CONT TestParsePathInfoJSON1842026/10/14 16:44:49 ERROR Upload failed error=boom count=1185=== CONT TestSupersededNARStillUploadsListing186=== RUN TestSupersededNARStillUploadsListing/small_NAR187=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths188=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths189=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths190=== RUN TestParsePathInfoJSON/Nix_format1912026/10/14 16:44:49 ERROR Upload failed error=boom count=1192=== PAUSE TestParsePathInfoJSON/Nix_format193=== RUN TestFilterOversizedClosures/no_limit_keeps_everything194=== CONT TestDumpPathMatchesNix1952026/10/14 16:44:49 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:46143196--- PASS: TestStaticToken (0.00s)197=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter198=== PAUSE TestSetClientTLSErrors/missing_cert_file199=== PAUSE TestSupersededNARStillUploadsListing/small_NAR2002026/10/14 16:44:49 ERROR Upload failed error="connection refused" count=20201--- PASS: TestStreamPushStopsWhenCanceled (0.00s)202=== CONT TestPathInfoHashCompatibility2032026/10/14 16:44:49 ERROR Server seems unavailable, giving up on batch untried=17204=== RUN TestSetClientTLSErrors/missing_key_file205=== PAUSE TestGetStorePathHash/valid_store_path206=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)207=== RUN TestParsePathInfoJSON/Lix_format208--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.00s)209--- PASS: TestScriptTokenScriptFails (0.00s)210--- PASS: TestStreamPushReportsSkippedPaths (0.00s)211=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything212=== RUN TestSupersededNARStillUploadsListing/dump_cut_short213=== PAUSE TestParsePathInfoJSON/Lix_format214=== RUN TestGetStorePathHash/basename_without_hyphen_should_error215=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error216=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error217=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error218=== CONT TestUploadMultipart_SupersededByPeer219=== CONT TestEncodeNixBase32WithRealHash2202026/10/14 16:44:49 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:46143221=== CONT TestPartSizeForNAR222=== CONT TestUploadMultipart_PartsInParallel223=== RUN TestPartSizeForNAR/zero_stays_at_minimum224=== PAUSE TestSetClientTLSErrors/missing_key_file225=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)226=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter227--- PASS: TestFileTokenReadsAndCaches (0.00s)228--- PASS: TestStreamPushReportsSignatures (0.00s)229--- PASS: TestClientSignaturesByStorePath (0.00s)230=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2312026/10/14 16:44:49 WARN Rate limiter enabled after throttle name=server-test rate=52322026/10/14 16:44:49 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:34569233=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short234=== RUN TestParsePathInfoJSON/empty_input235=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails236=== PAUSE TestParsePathInfoJSON/empty_input237=== RUN TestUploadMultipart_SupersededByPeer/exists238=== CONT TestConvertHashToNix32239=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error240=== RUN TestSetClientTLSErrors/missing_ca_file2412026/10/14 16:44:49 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:46143242--- PASS: TestResolveStorePath (0.00s)243=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica244=== RUN TestConvertHashToNix32/SRI_format_to_Nix322452026/10/14 16:44:49 WARN Rate limiter backed off name=server-test rate=5246=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum2472026/10/14 16:44:49 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:34569248=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon249=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped250=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails251=== RUN TestFilterOversizedClosures/all_closures_skipped252=== CONT TestRegisterUploadedObjectReusesConnections253=== CONT TestCaseHackSuffix254=== PAUSE TestSetClientTLSErrors/missing_ca_file255--- PASS: TestScriptTokenEmptyToken (0.01s)256=== PAUSE TestUploadMultipart_SupersededByPeer/exists257=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error258=== RUN TestParsePathInfoJSON/whitespace_only259=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32260=== RUN TestSetClientTLS/rejects_connection_without_client_cert261=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun262=== RUN TestSetClientTLSErrors/invalid_ca_file263=== RUN TestPartSizeForNAR/small_stays_at_minimum264=== PAUSE TestParsePathInfoJSON/whitespace_only2652026/10/14 16:44:49 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:46143266=== RUN TestParsePathInfoJSON/invalid_JSON267=== PAUSE TestParsePathInfoJSON/invalid_JSON268--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)269--- PASS: TestEncodeNixBase32WithRealHash (0.00s)270--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)271--- PASS: TestScriptTokenBadJSON (0.01s)272--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)273--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)274=== CONT TestPathInfoCACompatibility/null_ca_field275=== CONT TestDumpPathWriterError276=== CONT TestPathInfoCACompatibility/new_structured_format_-_text2772026/10/14 16:44:49 INFO Garbage collection started2782026/10/14 16:44:49 INFO Garbage collection started279=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method280--- PASS: TestDumpPathSingleFile (0.04s)281=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive282=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths283--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)284=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2852026/10/14 16:44:49 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:46143286--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)287 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)288 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)289=== CONT TestPathInfoCACompatibility/old_string_format_-_text290--- PASS: TestPathInfoCACompatibility (0.00s)291 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)292 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)293 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)294 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)295 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)296=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter297=== CONT TestRateLimiterFeedback/429_enables_limiter298=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter299=== RUN TestUploadMultipart_SupersededByPeer/missing300=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry301=== PAUSE TestSetClientTLSErrors/invalid_ca_file302=== RUN TestConvertHashToNix32/already_Nix32_format3032026/10/14 16:44:49 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=0304=== PAUSE TestPartSizeForNAR/small_stays_at_minimum305=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert306=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon307=== CONT TestEncodeNixBase32308=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum309=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum310=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts311=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts312=== RUN TestPartSizeForNAR/1_TiB313=== PAUSE TestPartSizeForNAR/1_TiB314=== RUN TestPartSizeForNAR/5_TiB_S3_max_object3152026/10/14 16:44:49 WARN Rate limiter enabled after throttle name=server-test rate=5316=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object317=== RUN TestPartSizeForNAR/capped_at_5_GiB3182026/10/14 16:44:49 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:46261319=== PAUSE TestPartSizeForNAR/capped_at_5_GiB3202026/10/14 16:44:49 WARN Rate limiter backed off name=server-test rate=5321=== CONT TestRateLimiterFeedback/503_enables_limiter3222026/10/14 16:44:49 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:46143323=== CONT TestGetStorePathHash/valid_store_path3242026/10/14 16:44:49 WARN Rate limiter enabled after throttle name=server-test rate=5325=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error3262026/10/14 16:44:49 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:34853327=== CONT TestGetStorePathHash/basename_without_hyphen_should_error3282026/10/14 16:44:49 WARN Garbage collection finished on another replica. Its statistics are not available here329--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)3302026/10/14 16:44:49 WARN Rate limiter backed off name=server-test rate=5331=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails332=== PAUSE TestUploadMultipart_SupersededByPeer/missing333=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA334=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI335=== PAUSE TestConvertHashToNix32/already_Nix32_format336=== CONT TestSupersededNARStillUploadsListing/small_NAR337=== RUN TestEncodeNixBase32/test_string_hash338=== CONT TestSupersededNARStillUploadsListing/dump_cut_short339=== PAUSE TestEncodeNixBase32/test_string_hash3402026/10/14 16:44:49 WARN Rate limiter enabled after throttle name=s3-test rate=5341=== RUN TestEncodeNixBase32/empty_input3422026/10/14 16:44:49 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:41905343=== PAUSE TestFilterOversizedClosures/all_closures_skipped3442026/10/14 16:44:49 INFO Uploading abc-hello (1.0GB)345=== CONT TestParsePathInfoJSON/Nix_format3462026/10/14 16:44:49 INFO Uploading abc-hello (1.0GB)347--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.04s)348=== CONT TestParsePathInfoJSON/empty_input349=== CONT TestParsePathInfoJSON/invalid_JSON350=== CONT TestParsePathInfoJSON/whitespace_only351=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA352=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI353=== RUN TestConvertHashToNix32/invalid_format354=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error355=== PAUSE TestEncodeNixBase32/empty_input3562026/10/14 16:44:49 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:46143357--- PASS: TestRateLimiterFeedback (0.01s)358 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)359 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)360 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)361 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)362--- PASS: TestGetStorePathHash (0.04s)363 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)364 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)365 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)366 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)367=== CONT TestParsePathInfoJSON/Lix_format368=== CONT TestSetClientTLSErrors/invalid_ca_file369=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512370=== RUN TestSetClientTLS/preserves_debug_logging_transport371=== CONT TestSetClientTLSErrors/missing_ca_file372=== CONT TestSetClientTLSErrors/missing_cert_file373=== CONT TestSetClientTLSErrors/missing_key_file374--- PASS: TestStreamPushBatchesUnderLoad (0.11s)375=== CONT TestPartSizeForNAR/zero_stays_at_minimum376=== CONT TestPartSizeForNAR/1_TiB377=== CONT TestPartSizeForNAR/capped_at_5_GiB378=== CONT TestPartSizeForNAR/5_TiB_S3_max_object379=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum380=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts381=== CONT TestPartSizeForNAR/small_stays_at_minimum382=== CONT TestUploadMultipart_SupersededByPeer/exists383=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512384=== CONT TestUploadMultipart_SupersededByPeer/missing385=== PAUSE TestSetClientTLS/preserves_debug_logging_transport386=== CONT TestFilterOversizedClosures/no_limit_keeps_everything387=== PAUSE TestConvertHashToNix32/invalid_format388=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3892026/10/14 16:44:49 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=2000390--- PASS: TestPartSizeForNAR (0.30s)391 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)392 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)393 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)394 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)395 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)396 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)397 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)398=== CONT TestEncodeNixBase32/test_string_hash399=== CONT TestEncodeNixBase32/empty_input400=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA401--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.32s)4022026/10/14 16:44:49 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:46143403--- PASS: TestCaseHackSuffix (0.33s)404=== CONT TestSetClientTLS/rejects_connection_without_client_cert405=== CONT TestFilterOversizedClosures/all_closures_skipped406=== CONT TestSetClientTLS/preserves_debug_logging_transport4072026/10/14 16:44:49 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=50408--- PASS: TestUploadMultipart_SupersededByPeer (0.04s)409 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.26s)410 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)4112026/10/14 16:44:49 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:46143412=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)413=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon414=== CONT TestConvertHashToNix32/already_Nix32_format415--- PASS: TestParsePathInfoJSON (0.04s)416 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)417 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)418 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)419 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)420 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)421=== CONT TestConvertHashToNix32/SRI_format_to_Nix32422=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI423=== CONT TestConvertHashToNix32/invalid_format424=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512425--- PASS: TestFilterOversizedClosures (0.05s)426 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)427 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)428 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)429--- PASS: TestEncodeNixBase32 (0.01s)430 --- PASS: TestEncodeNixBase32/empty_input (0.00s)431 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)432--- PASS: TestConvertHashToNix32 (0.36s)433 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)434 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)435 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)436--- PASS: TestPathInfoHashCompatibility (0.36s)437 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)438 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)439 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)440 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)4412026/10/14 16:44:49 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:46143442--- PASS: TestSetClientTLSErrors (0.05s)443 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)444 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)445 --- PASS: TestSetClientTLSErrors/missing_key_file (0.31s)446 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)4472026/10/14 16:44:49 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:461434482026/10/14 16:44:49 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:461434492026/10/14 16:44:49 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:461434502026/10/14 16:44:49 http: TLS handshake error from 127.0.0.1:51094: remote error: tls: bad certificate4512026/10/14 16:44:49 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:46143452--- PASS: TestSetClientTLS (0.36s)453 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)454 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)455 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)4562026/10/14 16:44:49 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:46143457--- PASS: TestStreamPushRequestLine (0.38s)4582026/10/14 16:44:49 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:461434592026/10/14 16:44:49 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:461434602026/10/14 16:44:49 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:46143461--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.39s)462--- PASS: TestRegisterUploadedObjectReusesConnections (0.35s)4632026/10/14 16:44:49 INFO Uploading abc-hello (1.0GB)464--- PASS: TestDumpPathWriterError (0.37s)465--- PASS: TestDumpPathMatchesNix (0.43s)4662026/10/14 16:44:49 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:37763/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:37763/part/24672026/10/14 16:44:49 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:37763/part/3\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:37763/part/34682026/10/14 16:44:49 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"469--- PASS: TestSupersededNARStillUploadsListing (0.04s)470 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.33s)471 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.33s)472 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.88s)473--- PASS: TestUploadMultipart_PartsInParallel (0.96s)474--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)4752026/10/14 16:44:50 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:41387/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:41387/api/uploads/complete4762026/10/14 16:44:50 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4772026/10/14 16:44:50 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:41387/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:41387/api/uploads/complete4782026/10/14 16:44:50 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4792026/10/14 16:44:50 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:41387/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:41387/api/uploads/complete4802026/10/14 16:44:50 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"481--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)482PASS483Running server tests...484The files belonging to this database system will be owned by user "nixbld".485This user must also own the server process.486487The database cluster will be initialized with locale "C".488The default database encoding has accordingly been set to "SQL_ASCII".489The default text search configuration will be set to "english".490491Data page checksums are enabled.492493creating directory /build/postgres3265131390/data ... ok494creating subdirectories ... ok495selecting dynamic shared memory implementation ... posix496selecting default "max_connections" ... 100497selecting default "shared_buffers" ... 128MB498selecting default time zone ... UTC499creating configuration files ... ok500running bootstrap script ... ok501performing post-bootstrap initialization ... ok502syncing data to disk ... ok503504initdb: warning: enabling "trust" authentication for local connections505initdb: 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.506507Success. You can now start the database server using:508509 pg_ctl -D /build/postgres3265131390/data -l logfile start510511/build/postgres3265131390:5432 - no response5122026-10-14 16:44:51.288 UTC [128] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit5132026-10-14 16:44:51.289 UTC [128] LOG: listening on Unix socket "/build/postgres3265131390/.s.PGSQL.5432"5142026-10-14 16:44:51.294 UTC [135] LOG: database system was shut down at 2026-10-14 16:44:50 UTC5152026-10-14 16:44:51.297 UTC [128] LOG: database system is ready to accept connections516/build/postgres3265131390:5432 - accepting connections517{"timestamp":"2026-10-14T16:44:51.696403161Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"ddb4422b-8c3a-4b5a-ac13-2f7c0901591c","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":1,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(392)"}518=== RUN TestService_AuthMiddleware519=== PAUSE TestService_AuthMiddleware520=== RUN TestService_AuthMiddleware_MTLSProxyHeader521=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader522=== RUN TestService_AuthMiddleware_MTLSBoundSubjects523=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects524=== RUN TestService_ReadAuthMiddleware525=== PAUSE TestService_ReadAuthMiddleware526=== RUN TestService_AuthMiddleware_OIDC527=== PAUSE TestService_AuthMiddleware_OIDC528=== RUN TestService_RequireScope_OIDC529=== PAUSE TestService_RequireScope_OIDC530=== RUN TestService_ReadScope_PublicByDefault531=== PAUSE TestService_ReadScope_PublicByDefault532=== RUN TestCacheConfigHandler533=== PAUSE TestCacheConfigHandler534=== RUN TestCacheStatsHandler535=== PAUSE TestCacheStatsHandler536=== RUN TestClientCADerivations537=== PAUSE TestClientCADerivations538=== RUN TestClientErrorHandling539=== PAUSE TestClientErrorHandling540=== RUN TestClientIntegration541=== PAUSE TestClientIntegration542=== RUN TestClientMultipleUploads543=== PAUSE TestClientMultipleUploads544=== RUN TestClientWithDependencies545=== PAUSE TestClientWithDependencies546=== RUN TestClientSharedPathCommittedMidPush547=== PAUSE TestClientSharedPathCommittedMidPush548=== RUN TestPinProtectsFromGC549=== PAUSE TestPinProtectsFromGC550=== RUN TestClientPushesUseOnePush551=== PAUSE TestClientPushesUseOnePush552=== RUN TestClientFallsBackToClosures553=== PAUSE TestClientFallsBackToClosures554=== RUN TestDeleteClosuresRacingPins555=== PAUSE TestDeleteClosuresRacingPins556=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock557=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock558=== RUN TestResolveDBConnectionString559=== PAUSE TestResolveDBConnectionString560=== RUN TestConnectWaitsForAPeerMigration561=== PAUSE TestConnectWaitsForAPeerMigration562=== RUN TestLeadElectsOneAndHandsOver563=== PAUSE TestLeadElectsOneAndHandsOver564=== RUN TestLeadIncumbentWinsAfterRestart5652026/10/14 16:44:51 INFO lead: acquired remote=192.0.2.1:12345662026/10/14 16:44:52 INFO lead: released remote=192.0.2.1:12345672026/10/14 16:44:52 INFO lead: acquired remote=192.0.2.1:12345682026/10/14 16:44:53 INFO lead: released remote=192.0.2.1:1234569--- PASS: TestLeadIncumbentWinsAfterRestart (1.84s)570=== RUN TestLeadIncumbentAnnouncesAtOnce571=== PAUSE TestLeadIncumbentAnnouncesAtOnce572=== RUN TestLeadEndsOnShutdown573=== PAUSE TestLeadEndsOnShutdown574=== RUN TestLeadEndsWhenItsConnectionHangs5752026/10/14 16:44:53 INFO lead: acquired remote=192.0.2.1:12345762026-10-14 16:44:55.155 UTC [574] FATAL: terminating connection due to administrator command5772026/10/14 16:44:55 INFO lead: acquired remote=192.0.2.1:12345782026/10/14 16:44:56 WARN lead: lock connection lost error="timeout: context deadline exceeded"5792026/10/14 16:44:56 INFO lead: released remote=192.0.2.1:12345802026/10/14 16:44:56 INFO lead: released remote=192.0.2.1:1234581--- PASS: TestLeadEndsWhenItsConnectionHangs (2.91s)582=== RUN TestGCAdvisoryLockBlocksConcurrentRun583=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun584=== RUN TestGCBugBareHashReferences585=== PAUSE TestGCBugBareHashReferences586=== RUN TestGCMetrics587=== PAUSE TestGCMetrics588=== RUN TestPushDedupSurvivesConcurrentGC589=== PAUSE TestPushDedupSurvivesConcurrentGC590=== RUN TestDeduplicatedObjectsRecordedAsPending591=== PAUSE TestDeduplicatedObjectsRecordedAsPending592=== RUN TestGCSweepSkipsPendingObjects593=== PAUSE TestGCSweepSkipsPendingObjects594=== RUN TestTombstonedObjectOfferedWithoutWaiting595=== PAUSE TestTombstonedObjectOfferedWithoutWaiting596=== RUN TestGCSweepDeliversEachKeyOnce597=== PAUSE TestGCSweepDeliversEachKeyOnce598=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection599=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection600=== RUN TestForceGCDuringPushOffersSweptObject601=== PAUSE TestForceGCDuringPushOffersSweptObject602=== RUN TestFailedS3DeleteKeepsTombstone603=== PAUSE TestFailedS3DeleteKeepsTombstone604=== RUN TestSweepSkipsRowsLockedByPush605=== PAUSE TestSweepSkipsRowsLockedByPush606=== RUN TestRegisterCompletedObjectNeedsPendingRow607=== PAUSE TestRegisterCompletedObjectNeedsPendingRow608=== RUN TestGetExistingObjectsLocksRows609=== PAUSE TestGetExistingObjectsLocksRows610=== RUN TestSweepRechecksPendingAfterLocking611=== PAUSE TestSweepRechecksPendingAfterLocking612=== RUN TestPushWaitsForSweepHoldingRow613=== PAUSE TestPushWaitsForSweepHoldingRow614=== RUN TestCommitRacingPendingCleanupKeepsObjects615=== PAUSE TestCommitRacingPendingCleanupKeepsObjects616=== RUN TestGCEndsOnShutdown617=== PAUSE TestGCEndsOnShutdown618=== RUN TestGCTaskStore_StartNew619=== PAUSE TestGCTaskStore_StartNew620=== RUN TestGCTaskStore_DeduplicateSameParams621=== PAUSE TestGCTaskStore_DeduplicateSameParams622=== RUN TestGCTaskStore_ConflictDifferentParams623=== PAUSE TestGCTaskStore_ConflictDifferentParams624=== RUN TestGCTaskStore_GetEmpty625=== PAUSE TestGCTaskStore_GetEmpty626=== RUN TestGCTaskStore_GetReturnsLatest627=== PAUSE TestGCTaskStore_GetReturnsLatest628=== RUN TestGCTaskStore_CompletedAllowsNewTask629=== PAUSE TestGCTaskStore_CompletedAllowsNewTask630=== RUN TestGCTaskStore_PhaseUpdates631=== PAUSE TestGCTaskStore_PhaseUpdates632=== RUN TestGCTaskStore_Fail633=== PAUSE TestGCTaskStore_Fail634=== RUN TestGracefulShutdownDrainsInflight635=== PAUSE TestGracefulShutdownDrainsInflight636=== RUN TestService_healthCheckHandler637=== PAUSE TestService_healthCheckHandler638=== RUN TestService_readinessHandler639=== PAUSE TestService_readinessHandler640=== RUN TestGenerateLandingPage641=== PAUSE TestGenerateLandingPage642=== RUN TestCacheConfigHandlerMaxNarSize643=== PAUSE TestCacheConfigHandlerMaxNarSize644=== RUN TestCreatePendingClosureRejectsOversizedNAR645=== PAUSE TestCreatePendingClosureRejectsOversizedNAR646=== RUN TestNARDeduplicationMetadataUploadBug647=== PAUSE TestNARDeduplicationMetadataUploadBug648=== RUN TestMetricsInventory649=== PAUSE TestMetricsInventory650=== RUN TestMetricsCommit651=== PAUSE TestMetricsCommit652=== RUN TestService_NativeMTLS653=== PAUSE TestService_NativeMTLS654=== RUN TestServerTLSConfig655=== PAUSE TestServerTLSConfig656=== RUN TestMultipartCleanup657=== PAUSE TestMultipartCleanup658=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded659=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded660=== RUN TestPendingCleanupUsesOneCutoff661=== PAUSE TestPendingCleanupUsesOneCutoff662=== RUN TestObjectStatsTrigger663=== PAUSE TestObjectStatsTrigger664=== RUN TestObjectStatsLargeCommit665=== PAUSE TestObjectStatsLargeCommit666=== RUN TestOrphanedObjectsGC667=== PAUSE TestOrphanedObjectsGC668=== RUN TestOrphanedObjectsGCStressTest669=== PAUSE TestOrphanedObjectsGCStressTest670=== RUN TestCreatePin_ReservedPins671=== PAUSE TestCreatePin_ReservedPins672=== RUN TestPresentReportsOnlyClosureRoots673=== PAUSE TestPresentReportsOnlyClosureRoots674=== RUN TestPresentRefreshesOnlyStaleClosures675=== PAUSE TestPresentRefreshesOnlyStaleClosures676=== RUN TestPresentNotReportedWhileGCDeletesClosure677=== PAUSE TestPresentNotReportedWhileGCDeletesClosure678=== RUN TestParseSingleRange679=== PAUSE TestParseSingleRange680=== RUN TestProxyHeadersOnlyTrustedOnSocket6812026/10/14 16:44:56 INFO Starting HTTP server address=127.0.0.1:418356822026/10/14 16:44:56 INFO Starting HTTP server address=proxy.sock6832026/10/14 16:44:56 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6842026/10/14 16:44:56 INFO Shutdown signal received, draining in-flight requests timeout=10s685--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.10s)686=== RUN TestIsValidCachePath687=== PAUSE TestIsValidCachePath688=== RUN TestReadProxyNarinfo689=== PAUSE TestReadProxyNarinfo690=== RUN TestReadProxyNarinfoAlreadyDecompressed691=== PAUSE TestReadProxyNarinfoAlreadyDecompressed692=== RUN TestReadProxyContentNegotiation693=== PAUSE TestReadProxyContentNegotiation694=== RUN TestReadProxyNarStreaming695=== PAUSE TestReadProxyNarStreaming696=== RUN TestReadProxy404697=== PAUSE TestReadProxy404698=== RUN TestReadProxyInvalidPath699=== PAUSE TestReadProxyInvalidPath700=== RUN TestReadProxyHead701=== PAUSE TestReadProxyHead702=== RUN TestReadProxyOutlastsServerWriteTimeout703=== PAUSE TestReadProxyOutlastsServerWriteTimeout704=== RUN TestReadProxyConditionalGet705=== PAUSE TestReadProxyConditionalGet706=== RUN TestReadProxyRootRedirectsToIndexHTML707=== PAUSE TestReadProxyRootRedirectsToIndexHTML708=== RUN TestReadProxyDisabled709=== PAUSE TestReadProxyDisabled710=== RUN TestReadRedirectNar711=== PAUSE TestReadRedirectNar712=== RUN TestReadRedirectKeepsNarinfoProxied713=== PAUSE TestReadRedirectKeepsNarinfoProxied714=== RUN TestReadProxyRangeRequest715=== PAUSE TestReadProxyRangeRequest716=== RUN TestReadRedirectUsesPublicS3URL717=== PAUSE TestReadRedirectUsesPublicS3URL718=== RUN TestPush_OverlappingRootsStoreOneRowPerKey719=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey720=== RUN TestPush_CompleteCommitsEveryRoot721=== PAUSE TestPush_CompleteCommitsEveryRoot722=== RUN TestPush_RepeatedRootCommitsOnce723=== PAUSE TestPush_RepeatedRootCommitsOnce724=== RUN TestPush_CompleteWaitsForCleanupOfThePush725=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush726=== RUN TestPush_RootsAreLockedInByteOrder727=== PAUSE TestPush_RootsAreLockedInByteOrder728=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit729=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit730=== RUN TestPush_RejectsBadRequests731=== PAUSE TestPush_RejectsBadRequests732=== RUN TestPush_SignsNarinfosOfItsPendingObjects733=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects734=== RUN TestRedundantMultipartUpload735=== PAUSE TestRedundantMultipartUpload736=== RUN TestCompleteMultipartUpload_ErrorButObjectExists737=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists738=== RUN TestCompletedNarNotReofferedAcrossClosures739=== PAUSE TestCompletedNarNotReofferedAcrossClosures740=== RUN TestPresignedUploadRegisteredBeforeCommit741=== PAUSE TestPresignedUploadRegisteredBeforeCommit742=== RUN TestService_Rustfstest743=== PAUSE TestService_Rustfstest744=== RUN TestParseSize745=== PAUSE TestParseSize746=== RUN TestSkippedUploadsHandler747=== PAUSE TestSkippedUploadsHandler748=== RUN TestSystemdListenerNotActivated749--- PASS: TestSystemdListenerNotActivated (0.00s)750=== RUN TestWatchdogBeatsWhenHealthy751--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)752=== RUN TestWatchdogSkipsWhenUnhealthy7532026/10/14 16:44:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7542026/10/14 16:44:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7552026/10/14 16:44:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7562026/10/14 16:44:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7572026/10/14 16:44:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7582026/10/14 16:44:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7592026/10/14 16:44:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7602026/10/14 16:44:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7612026/10/14 16:44:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7622026/10/14 16:44:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"763--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)764=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle765=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle766=== RUN TestProxyWriteTimeout767=== PAUSE TestProxyWriteTimeout768=== RUN TestPendingClosureWriteTimeout769=== PAUSE TestPendingClosureWriteTimeout770=== RUN TestIsValidUploadKey771=== PAUSE TestIsValidUploadKey772=== RUN TestUploadHandlersRejectInvalidKeys773=== PAUSE TestUploadHandlersRejectInvalidKeys774=== RUN TestUploadHandlersRejectOversizedBody775=== PAUSE TestUploadHandlersRejectOversizedBody776=== RUN TestService_cleanupPendingClosuresHandler777=== PAUSE TestService_cleanupPendingClosuresHandler778=== RUN TestService_createPendingClosureHandler779=== PAUSE TestService_createPendingClosureHandler780=== RUN TestService_verifyS3Integrity781=== PAUSE TestService_verifyS3Integrity782=== RUN TestCompleteMultipartUnregistered783=== PAUSE TestCompleteMultipartUnregistered784=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT785=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT786=== CONT TestService_AuthMiddleware787=== CONT TestIsValidUploadKey788=== CONT TestProxyWriteTimeout789=== RUN TestProxyWriteTimeout/narinfo790=== CONT TestPush_OverlappingRootsStoreOneRowPerKey791=== CONT TestReadProxyHead792=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT793=== CONT TestCompleteMultipartUnregistered794=== CONT TestService_verifyS3Integrity795=== CONT TestService_createPendingClosureHandler796=== CONT TestService_cleanupPendingClosuresHandler797=== CONT TestUploadHandlersRejectOversizedBody798=== CONT TestUploadHandlersRejectInvalidKeys799=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info800=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info801=== CONT TestPendingClosureWriteTimeout802=== CONT TestReadRedirectUsesPublicS3URL803=== CONT TestReadProxyRangeRequest804=== CONT TestReadRedirectKeepsNarinfoProxied805=== CONT TestReadRedirectNar806=== CONT TestReadProxyDisabled807=== CONT TestReadProxyRootRedirectsToIndexHTML808=== CONT TestReadProxyConditionalGet809=== CONT TestReadProxyOutlastsServerWriteTimeout810=== CONT TestReadProxyNarinfoAlreadyDecompressed811=== CONT TestReadProxyInvalidPath812=== RUN TestIsValidUploadKey/narinfo813=== CONT TestPresentRefreshesOnlyStaleClosures814=== PAUSE TestProxyWriteTimeout/narinfo815=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal816=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal817=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key818=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key819=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key820=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key821=== RUN TestProxyWriteTimeout/1_GiB_nar822=== PAUSE TestProxyWriteTimeout/1_GiB_nar823=== RUN TestProxyWriteTimeout/10_GiB_nar824=== PAUSE TestProxyWriteTimeout/10_GiB_nar825=== RUN TestProxyWriteTimeout/unknown_size826=== PAUSE TestProxyWriteTimeout/unknown_size827=== RUN TestPendingClosureWriteTimeout/empty828=== PAUSE TestPendingClosureWriteTimeout/empty829=== RUN TestPendingClosureWriteTimeout/400_objects830=== PAUSE TestPendingClosureWriteTimeout/400_objects831=== RUN TestPendingClosureWriteTimeout/670k_objects832=== PAUSE TestPendingClosureWriteTimeout/670k_objects833=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline834=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline835=== CONT TestReadProxy404836=== CONT TestReadProxyNarStreaming837=== CONT TestReadProxyContentNegotiation838=== PAUSE TestIsValidUploadKey/narinfo839=== RUN TestIsValidUploadKey/nar_zst840=== PAUSE TestIsValidUploadKey/nar_zst841=== RUN TestIsValidUploadKey/nar_xz842=== PAUSE TestIsValidUploadKey/nar_xz843=== RUN TestIsValidUploadKey/nar_plain844=== PAUSE TestIsValidUploadKey/nar_plain845=== RUN TestIsValidUploadKey/listing846=== PAUSE TestIsValidUploadKey/listing847=== RUN TestIsValidUploadKey/build_log848=== PAUSE TestIsValidUploadKey/build_log849=== RUN TestIsValidUploadKey/build_log_home-manager_file850=== PAUSE TestIsValidUploadKey/build_log_home-manager_file851=== RUN TestIsValidUploadKey/build_log_plus_in_name852=== PAUSE TestIsValidUploadKey/build_log_plus_in_name853=== RUN TestIsValidUploadKey/build_log_question_mark854=== PAUSE TestIsValidUploadKey/build_log_question_mark855=== RUN TestIsValidUploadKey/build_log_equals856=== PAUSE TestIsValidUploadKey/build_log_equals857=== RUN TestIsValidUploadKey/realisation858=== PAUSE TestIsValidUploadKey/realisation859=== RUN TestIsValidUploadKey/realisation_plus_in_output860=== PAUSE TestIsValidUploadKey/realisation_plus_in_output861=== RUN TestIsValidUploadKey/nix-cache-info862=== PAUSE TestIsValidUploadKey/nix-cache-info863=== RUN TestIsValidUploadKey/index.html864=== PAUSE TestIsValidUploadKey/index.html865=== RUN TestIsValidUploadKey/narinfo_key,_nar_type866=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type867=== RUN TestIsValidUploadKey/nar_key,_narinfo_type868=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type869=== RUN TestIsValidUploadKey/listing_key,_narinfo_type870=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type871=== RUN TestIsValidUploadKey/traversal872=== PAUSE TestIsValidUploadKey/traversal873=== RUN TestIsValidUploadKey/traversal_nar874=== PAUSE TestIsValidUploadKey/traversal_nar875=== RUN TestIsValidUploadKey/absolute876=== PAUSE TestIsValidUploadKey/absolute877=== RUN TestIsValidUploadKey/empty_key878=== PAUSE TestIsValidUploadKey/empty_key879=== RUN TestIsValidUploadKey/unknown_type880=== PAUSE TestIsValidUploadKey/unknown_type881=== CONT TestIsValidCachePath882=== RUN TestIsValidCachePath/narinfo883=== PAUSE TestIsValidCachePath/narinfo884=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars885=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars886=== RUN TestIsValidCachePath/nar_zst887=== PAUSE TestIsValidCachePath/nar_zst888=== RUN TestIsValidCachePath/nar_xz889=== PAUSE TestIsValidCachePath/nar_xz890=== RUN TestIsValidCachePath/nar_bz2891=== PAUSE TestIsValidCachePath/nar_bz2892=== RUN TestIsValidCachePath/nar_uncompressed893=== PAUSE TestIsValidCachePath/nar_uncompressed894=== RUN TestIsValidCachePath/ls895=== PAUSE TestIsValidCachePath/ls896=== RUN TestIsValidCachePath/log897=== PAUSE TestIsValidCachePath/log898=== RUN TestIsValidCachePath/realisation899=== PAUSE TestIsValidCachePath/realisation900=== RUN TestIsValidCachePath/nix-cache-info901=== PAUSE TestIsValidCachePath/nix-cache-info902=== RUN TestIsValidCachePath/index.html903=== PAUSE TestIsValidCachePath/index.html904=== RUN TestIsValidCachePath/traversal_parent905=== PAUSE TestIsValidCachePath/traversal_parent906=== RUN TestIsValidCachePath/traversal_in_middle907=== PAUSE TestIsValidCachePath/traversal_in_middle908=== RUN TestIsValidCachePath/invalid_char_e909=== PAUSE TestIsValidCachePath/invalid_char_e910=== RUN TestIsValidCachePath/invalid_char_u911=== PAUSE TestIsValidCachePath/invalid_char_u912=== RUN TestIsValidCachePath/random_path913=== PAUSE TestIsValidCachePath/random_path914=== RUN TestIsValidCachePath/empty915=== PAUSE TestIsValidCachePath/empty916=== RUN TestIsValidCachePath/leading_slash917=== PAUSE TestIsValidCachePath/leading_slash918=== RUN TestIsValidCachePath/wrong_extension919=== PAUSE TestIsValidCachePath/wrong_extension920=== RUN TestIsValidCachePath/short_hash921=== PAUSE TestIsValidCachePath/short_hash922=== CONT TestReadProxyNarinfo923=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart924=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart925=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts926=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts927=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure928=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure929=== CONT TestSweepSkipsRowsLockedByPush9302026/10/14 16:44:57 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"931--- PASS: TestService_AuthMiddleware (0.49s)932=== CONT TestPresentReportsOnlyClosureRoots9332026/10/14 16:44:57 INFO Received uploads request method=POST path=/api/pending_closures9342026/10/14 16:44:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete935--- PASS: TestReadProxyHead (0.56s)936=== CONT TestCreatePin_ReservedPins9372026/10/14 16:44:57 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst938--- PASS: TestCompleteMultipartUnregistered (0.56s)939=== CONT TestOrphanedObjectsGCStressTest9402026/10/14 16:44:57 INFO Received uploads request method=POST path=/api/pending_closures9412026/10/14 16:44:57 INFO Received uploads request method=POST path=/api/pending_closures9422026/10/14 16:44:57 INFO Received uploads request method=POST path=/api/pending_closures9432026/10/14 16:44:57 INFO Received cleanup request method=DELETE path=/api/pending_closures9442026/10/14 16:44:57 INFO Aborted multipart uploads count=0 kept=09452026/10/14 16:44:57 INFO Received uploads request method=POST path=/api/pending_closures9462026/10/14 16:44:57 INFO Received cleanup request method=DELETE path=/api/pending_closures9472026/10/14 16:44:57 INFO Aborted multipart uploads count=1 kept=09482026/10/14 16:44:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36997/oidc9492026/10/14 16:44:57 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9502026-10-14 16:44:57.539 UTC [654] ERROR: Closure does not exist: id=19512026-10-14 16:44:57.539 UTC [654] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9522026-10-14 16:44:57.539 UTC [654] STATEMENT: -- name: CommitPendingClosure :one953 SELECT commit_pending_closure($1::bigint)::bigint954 955--- PASS: TestService_cleanupPendingClosuresHandler (0.64s)956=== CONT TestOrphanedObjectsGC9572026/10/14 16:44:57 INFO Received uploads request method=POST path=/api/pending_closures958--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.70s)959=== CONT TestObjectStatsLargeCommit960--- PASS: TestReadProxyRangeRequest (0.75s)961=== CONT TestObjectStatsTrigger962--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.77s)963=== CONT TestPendingCleanupUsesOneCutoff964--- PASS: TestReadRedirectUsesPublicS3URL (0.80s)965=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded9662026/10/14 16:44:57 INFO Received push request method=POST path=/api/pushes967--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.85s)968=== CONT TestMultipartCleanup969--- PASS: TestReadRedirectKeepsNarinfoProxied (0.85s)970=== CONT TestServerTLSConfig971=== RUN TestServerTLSConfig/no_client_CA972=== PAUSE TestServerTLSConfig/no_client_CA973=== RUN TestServerTLSConfig/missing_CA_file974=== PAUSE TestServerTLSConfig/missing_CA_file975=== RUN TestServerTLSConfig/not_a_PEM_file976=== PAUSE TestServerTLSConfig/not_a_PEM_file977=== CONT TestGCTaskStore_CompletedAllowsNewTask978--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)979=== CONT TestGCTaskStore_GetReturnsLatest980--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)981=== CONT TestGCTaskStore_GetEmpty982--- PASS: TestGCTaskStore_GetEmpty (0.00s)983=== CONT TestGCTaskStore_ConflictDifferentParams984--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)985=== CONT TestGCTaskStore_DeduplicateSameParams986--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)987=== CONT TestGCTaskStore_StartNew988--- PASS: TestGCTaskStore_StartNew (0.00s)989=== CONT TestGCEndsOnShutdown990=== RUN TestGCEndsOnShutdown/before_the_run991=== PAUSE TestGCEndsOnShutdown/before_the_run992=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete993=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete994=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark995=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark996=== CONT TestCommitRacingPendingCleanupKeepsObjects997--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.88s)998=== CONT TestPushWaitsForSweepHoldingRow999--- PASS: TestPresentRefreshesOnlyStaleClosures (0.92s)1000=== CONT TestSweepRechecksPendingAfterLocking1001--- PASS: TestReadProxy404 (0.96s)1002=== CONT TestGetExistingObjectsLocksRows1003--- PASS: TestReadProxyConditionalGet (0.90s)1004=== CONT TestRegisterCompletedObjectNeedsPendingRow1005--- PASS: TestReadRedirectNar (1.01s)1006=== CONT TestParseSingleRange1007=== RUN TestParseSingleRange/none1008=== PAUSE TestParseSingleRange/none1009=== RUN TestParseSingleRange/unknown_unit1010=== PAUSE TestParseSingleRange/unknown_unit1011=== RUN TestParseSingleRange/multi-range_ignored1012=== PAUSE TestParseSingleRange/multi-range_ignored1013=== RUN TestParseSingleRange/malformed_no_dash1014=== PAUSE TestParseSingleRange/malformed_no_dash1015=== RUN TestParseSingleRange/malformed_both_empty1016=== PAUSE TestParseSingleRange/malformed_both_empty1017=== RUN TestParseSingleRange/malformed_end_before_start1018=== PAUSE TestParseSingleRange/malformed_end_before_start1019=== RUN TestParseSingleRange/closed1020=== PAUSE TestParseSingleRange/closed1021=== RUN TestParseSingleRange/open-ended1022=== PAUSE TestParseSingleRange/open-ended1023=== RUN TestParseSingleRange/end_clamped_to_size1024=== PAUSE TestParseSingleRange/end_clamped_to_size1025=== RUN TestParseSingleRange/suffix1026=== PAUSE TestParseSingleRange/suffix1027=== RUN TestParseSingleRange/suffix_exceeds_size1028=== PAUSE TestParseSingleRange/suffix_exceeds_size1029=== RUN TestParseSingleRange/single_byte1030=== PAUSE TestParseSingleRange/single_byte1031=== RUN TestParseSingleRange/start_past_EOF1032=== PAUSE TestParseSingleRange/start_past_EOF1033=== RUN TestParseSingleRange/start_far_past_EOF1034=== PAUSE TestParseSingleRange/start_far_past_EOF1035=== CONT TestGCTaskStore_PhaseUpdates1036--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1037=== CONT TestCacheConfigHandlerMaxNarSize1038--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1039=== CONT TestService_NativeMTLS1040--- PASS: TestReadProxyInvalidPath (1.03s)1041=== CONT TestGenerateLandingPage1042--- PASS: TestGenerateLandingPage (0.00s)1043=== CONT TestMetricsCommit10442026/10/14 16:44:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10452026/10/14 16:44:57 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YjhlYjQyZmQtNmNhMS00MDI0LWI2MWYtYWViZGE2N2U3MTdhLmNlZjczMGZmLTlmN2YtNDBiZi1iMGQ0LTRkZjEyN2E5ZTNjZXgxNzkxOTk2Mjk3NDI5MDU3NDY0 parts=1010462026/10/14 16:44:57 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10472026/10/14 16:44:57 INFO Completed upload id=1 objects=2 duration=5.052526ms10482026/10/14 16:44:57 INFO Received uploads request method=POST path=/api/pending_closures10492026/10/14 16:44:57 INFO Received uploads request method=POST path=/api/pending_closures10502026/10/14 16:44:57 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10512026/10/14 16:44:57 WARN Found objects in DB but missing from S3, will re-upload count=11052--- PASS: TestService_verifyS3Integrity (1.10s)1053=== CONT TestService_readinessHandler10542026/10/14 16:44:58 INFO Aborted multipart uploads count=0 kept=010552026/10/14 16:44:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10562026/10/14 16:44:58 WARN Force mode enabled - objects will be deleted immediately without grace period10572026/10/14 16:44:58 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010582026/10/14 16:44:58 INFO Vacuumed table table=pending_closures10592026/10/14 16:44:58 INFO Vacuumed table table=pending_objects10602026/10/14 16:44:58 INFO Vacuumed table table=multipart_uploads10612026/10/14 16:44:58 INFO Vacuumed table table=closures10622026/10/14 16:44:58 INFO Vacuumed table table=objects10632026/10/14 16:44:58 INFO Aborted multipart uploads count=0 kept=010642026/10/14 16:44:58 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YjhlYjQyZmQtNmNhMS00MDI0LWI2MWYtYWViZGE2N2U3MTdhLmI3NjY0YWZlLTcyN2EtNDE2MS1iNTRiLTU2N2FlOTA5ZWNjYXgxNzkxOTk2Mjk3NDg2MTg5ODc3 parts=1010652026/10/14 16:44:58 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10662026/10/14 16:44:58 WARN Force mode enabled - objects will be deleted immediately without grace period10672026/10/14 16:44:58 INFO Completed upload id=1 objects=2 duration=4.357737ms10682026/10/14 16:44:58 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010692026/10/14 16:44:58 INFO Received uploads request method=POST path=/api/pending_closures10702026/10/14 16:44:58 INFO Starting cleanup of old closures method=DELETE path=/api/closures10712026/10/14 16:44:58 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=010722026/10/14 16:44:58 INFO Vacuumed table table=pending_closures10732026/10/14 16:44:58 INFO Vacuumed table table=pending_objects10742026/10/14 16:44:58 INFO Vacuumed table table=multipart_uploads10752026/10/14 16:44:58 INFO Vacuumed table table=closures1076--- PASS: TestReadProxyNarStreaming (1.08s)1077=== CONT TestMetricsInventory10782026/10/14 16:44:58 INFO Vacuumed table table=objects10792026/10/14 16:44:58 INFO Aborted multipart uploads count=0 kept=01080--- PASS: TestSweepSkipsRowsLockedByPush (1.01s)1081=== CONT TestService_healthCheckHandler10822026/10/14 16:44:58 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=010832026/10/14 16:44:58 INFO Vacuumed table table=pending_closures10842026/10/14 16:44:58 INFO Vacuumed table table=pending_objects10852026/10/14 16:44:58 INFO Vacuumed table table=multipart_uploads10862026/10/14 16:44:58 INFO Vacuumed table table=closures10872026/10/14 16:44:58 INFO Vacuumed table table=objects10882026/10/14 16:44:58 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1089--- PASS: TestReadProxyNarinfo (1.10s)1090=== CONT TestNARDeduplicationMetadataUploadBug1091--- PASS: TestReadProxyDisabled (1.11s)1092=== CONT TestGracefulShutdownDrainsInflight10932026/10/14 16:44:58 INFO Starting HTTP server address=127.0.0.1:4364910942026/10/14 16:44:58 INFO Shutdown signal received, draining in-flight requests timeout=10s10952026/10/14 16:44:58 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001096--- PASS: TestService_createPendingClosureHandler (1.20s)1097=== CONT TestCreatePendingClosureRejectsOversizedNAR10982026/10/14 16:44:58 INFO Received uploads request method=POST path=/api/pending_closures1099--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1100=== CONT TestPresentNotReportedWhileGCDeletesClosure1101=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1102=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1103=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1104=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1105=== CONT TestGCTaskStore_Fail1106--- PASS: TestGCTaskStore_Fail (0.00s)1107=== CONT TestDeleteClosuresRacingPins1108--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1109=== CONT TestGCBugBareHashReferences1110--- PASS: TestPresentReportsOnlyClosureRoots (0.77s)1111=== CONT TestGCAdvisoryLockBlocksConcurrentRun1112--- PASS: TestReadProxyContentNegotiation (1.20s)1113=== CONT TestGCMetrics11142026/10/14 16:44:58 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11152026/10/14 16:44:58 WARN Refused reserved pin name=worker-x86_64-linux11162026/10/14 16:44:58 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11172026/10/14 16:44:58 INFO Received create pin request method=POST path=/api/pins/my-app11182026/10/14 16:44:58 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1119--- PASS: TestCreatePin_ReservedPins (0.77s)1120=== CONT TestLeadEndsOnShutdown1121--- PASS: TestObjectStatsTrigger (0.68s)1122=== CONT TestFailedS3DeleteKeepsTombstone11232026/10/14 16:44:58 INFO Received uploads request method=POST path=/api/pending_closures11242026/10/14 16:44:58 INFO Received uploads request method=POST path=/api/pending_closures11252026/10/14 16:44:58 INFO Received cleanup request method=DELETE path=/api/pending_closures11262026/10/14 16:44:58 INFO Received uploads request method=POST path=/api/pending_closures1127--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.74s)1128=== CONT TestLeadIncumbentAnnouncesAtOnce11292026/10/14 16:44:58 INFO Received uploads request method=POST path=/api/pending_closures11302026/10/14 16:44:58 INFO Received uploads request method=POST path=/api/pending_closures11312026/10/14 16:44:58 INFO Aborted multipart uploads count=0 kept=011322026/10/14 16:44:58 WARN Force mode enabled - objects will be deleted immediately without grace period11332026/10/14 16:44:58 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=011342026/10/14 16:44:58 INFO Vacuumed table table=pending_closures11352026/10/14 16:44:58 INFO Vacuumed table table=pending_objects11362026/10/14 16:44:58 INFO Vacuumed table table=multipart_uploads11372026/10/14 16:44:58 INFO Vacuumed table table=closures11382026/10/14 16:44:58 INFO Vacuumed table table=objects1139--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.79s)1140=== CONT TestForceGCDuringPushOffersSweptObject1141=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1142=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1143=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1144=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1145=== CONT TestLeadElectsOneAndHandsOver11462026/10/14 16:44:58 INFO Aborted multipart uploads count=0 kept=011472026/10/14 16:44:58 WARN Force mode enabled - objects will be deleted immediately without grace period11482026/10/14 16:44:58 INFO Received cleanup request method=DELETE path=/api/pending_closures11492026/10/14 16:44:58 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=011502026/10/14 16:44:58 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket36/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""11512026/10/14 16:44:58 INFO Aborted multipart uploads count=0 kept=111522026/10/14 16:44:58 INFO Vacuumed table table=pending_closures11532026/10/14 16:44:58 INFO Vacuumed table table=pending_objects11542026/10/14 16:44:58 INFO Vacuumed table table=multipart_uploads11552026/10/14 16:44:58 INFO Vacuumed table table=closures11562026/10/14 16:44:58 INFO Vacuumed table table=objects11572026/10/14 16:44:58 INFO Received cleanup request method=DELETE path=/api/pending_closures1158--- PASS: TestSweepRechecksPendingAfterLocking (0.77s)1159=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection11602026/10/14 16:44:58 INFO Aborted multipart uploads count=1 kept=01161--- PASS: TestGetExistingObjectsLocksRows (0.72s)1162=== CONT TestConnectWaitsForAPeerMigration1163--- PASS: TestMultipartCleanup (0.85s)1164=== CONT TestGCSweepDeliversEachKeyOnce1165--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.73s)1166=== CONT TestResolveDBConnectionString1167=== RUN TestResolveDBConnectionString/flag_wins1168=== PAUSE TestResolveDBConnectionString/flag_wins1169=== RUN TestResolveDBConnectionString/file_when_flag_empty1170=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1171=== RUN TestResolveDBConnectionString/missing_file_is_an_error1172=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1173=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1174=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1175=== RUN TestResolveDBConnectionString/nothing_configured1176=== PAUSE TestResolveDBConnectionString/nothing_configured1177=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock11782026/10/14 16:44:58 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11792026/10/14 16:44:58 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1180--- PASS: TestService_NativeMTLS (0.73s)1181=== CONT TestClientCADerivations1182=== NAME TestOrphanedObjectsGC1183 orphaned_objects_gc_test.go:287: GC Test Summary:1184 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1185 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1186 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1187 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1188 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1189--- PASS: TestOrphanedObjectsGC (1.11s)1190=== CONT TestTombstonedObjectOfferedWithoutWaiting11912026/10/14 16:44:58 INFO Received push request method=POST path=/api/pushes11922026/10/14 16:44:58 INFO Received complete push request method=POST path=/api/pushes/1/complete11932026/10/14 16:44:58 WARN readiness check failed error="closed pool"1194--- PASS: TestService_readinessHandler (0.70s)1195=== CONT TestRedundantMultipartUpload11962026/10/14 16:44:58 INFO Completed push id=1 objects=4 duration=10.849543ms11972026/10/14 16:44:58 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11982026/10/14 16:44:58 INFO Completed upload id=2 objects=2 duration=1.969768ms1199--- PASS: TestMetricsCommit (0.78s)1200=== CONT TestGCSweepSkipsPendingObjects1201--- PASS: TestService_healthCheckHandler (0.67s)1202=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1203--- PASS: TestMetricsInventory (0.75s)1204=== CONT TestClientFallsBackToClosures1205=== NAME TestNARDeduplicationMetadataUploadBug1206 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1300931961/001/store/qpd5l57pl5fqp4xx31kyi4n60giam29f-file1.txt12072026/10/14 16:44:58 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"1208--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.73s)1209=== CONT TestClientPushesUseOnePush12102026/10/14 16:44:58 INFO Received push request method=POST path=/api/pushes12112026/10/14 16:44:58 INFO Aborted multipart uploads count=0 kept=012122026/10/14 16:44:58 WARN Force mode enabled - objects will be deleted immediately without grace period12132026/10/14 16:44:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12142026/10/14 16:44:58 INFO Uploading qpd5l57pl5fqp4xx31kyi4n60giam29f-file1.txt (160B)12152026/10/14 16:44:58 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=012162026/10/14 16:44:58 INFO Vacuumed table table=pending_closures12172026/10/14 16:44:58 INFO Vacuumed table table=pending_objects12182026/10/14 16:44:58 INFO Vacuumed table table=multipart_uploads12192026/10/14 16:44:58 INFO Vacuumed table table=closures12202026/10/14 16:44:58 INFO Vacuumed table table=objects12212026/10/14 16:44:58 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12222026/10/14 16:44:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12232026/10/14 16:44:58 WARN Failed to register uploaded object key=qpd5l57pl5fqp4xx31kyi4n60giam29f.ls error="server returned 404: 404 page not found\n"12242026/10/14 16:44:58 INFO Signed narinfos id=1 count=112252026/10/14 16:44:58 INFO Uploading 1 narinfos12262026/10/14 16:44:58 WARN Failed to register uploaded object key=qpd5l57pl5fqp4xx31kyi4n60giam29f.narinfo error="server returned 404: 404 page not found\n"12272026/10/14 16:44:58 INFO Received complete push request method=POST path=/api/pushes/1/complete1228--- PASS: TestGCMetrics (0.76s)1229=== CONT TestDeduplicatedObjectsRecordedAsPending12302026/10/14 16:44:58 INFO lead: acquired remote=192.0.2.1:123412312026/10/14 16:44:58 INFO Completed push id=1 objects=3 duration=10.175213ms12322026/10/14 16:44:58 INFO Upload complete. (71ms)1233=== NAME TestNARDeduplicationMetadataUploadBug1234 metadata_upload_test.go:54: Retrieved narinfo from S3:1235 StorePath: /build/TestNARDeduplicationMetadataUploadBug1300931961/001/store/qpd5l57pl5fqp4xx31kyi4n60giam29f-file1.txt1236 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1237 Compression: zstd1238 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1239 NarSize: 1601240 References: 1241 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1242 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1243 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1244 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12452026/10/14 16:44:58 INFO Received uploads request method=POST path=/api/pending_closures1246 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1300931961/001/store/zwwdnqfmvkksjcnacms8shs1ic4pvf1i-file2.txt12472026/10/14 16:44:58 INFO lead: acquired remote=192.0.2.1:123412482026/10/14 16:44:58 INFO lead: released remote=192.0.2.1:12341249--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.54s)1250=== CONT TestPinProtectsFromGC12512026/10/14 16:44:59 INFO Aborted multipart uploads count=0 kept=012522026/10/14 16:44:59 WARN Force mode enabled - objects will be deleted immediately without grace period1253--- PASS: TestPushWaitsForSweepHoldingRow (1.29s)1254=== CONT TestPushDedupSurvivesConcurrentGC12552026/10/14 16:44:59 INFO Received push request method=POST path=/api/pushes12562026/10/14 16:44:59 INFO lead: acquired remote=192.0.2.1:123412572026/10/14 16:44:59 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12582026/10/14 16:44:59 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12592026/10/14 16:44:59 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1260--- PASS: TestGCBugBareHashReferences (0.96s)1261=== CONT TestClientSharedPathCommittedMidPush12622026/10/14 16:44:59 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12632026/10/14 16:44:59 INFO Signed narinfos id=2 count=112642026/10/14 16:44:59 WARN Failed to register uploaded object key=zwwdnqfmvkksjcnacms8shs1ic4pvf1i.ls error="server returned 404: 404 page not found\n"12652026/10/14 16:44:59 INFO Uploading 1 narinfos1266--- PASS: TestFailedS3DeleteKeepsTombstone (0.79s)1267=== CONT TestClientWithDependencies12682026/10/14 16:44:59 INFO Received complete push request method=POST path=/api/pushes/2/complete12692026/10/14 16:44:59 WARN Failed to register uploaded object key=zwwdnqfmvkksjcnacms8shs1ic4pvf1i.narinfo error="server returned 404: 404 page not found\n"12702026/10/14 16:44:59 INFO Completed push id=2 objects=3 duration=3.847207ms12712026/10/14 16:44:59 INFO Upload complete. (101ms)1272=== NAME TestNARDeduplicationMetadataUploadBug1273 metadata_upload_test.go:76: Retrieved narinfo from S3:1274 StorePath: /build/TestNARDeduplicationMetadataUploadBug1300931961/001/store/zwwdnqfmvkksjcnacms8shs1ic4pvf1i-file2.txt1275 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1276 Compression: zstd1277 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1278 NarSize: 1601279 References: 1280 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1281--- PASS: TestObjectStatsLargeCommit (1.53s)1282=== CONT TestClientMultipleUploads1283=== NAME TestNARDeduplicationMetadataUploadBug1284 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1285 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1286 {"version":1,"root":{"type":"regular","size":44}}1287--- PASS: TestNARDeduplicationMetadataUploadBug (1.05s)1288=== CONT TestPush_RootsAreLockedInByteOrder12892026/10/14 16:44:59 INFO Received uploads request method=POST path=/api/pending_closures12902026/10/14 16:44:59 INFO Aborted multipart uploads count=0 kept=012912026/10/14 16:44:59 WARN Force mode enabled - objects will be deleted immediately without grace period12922026/10/14 16:44:59 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/14 16:44:59 INFO Vacuumed table table=pending_closures12942026/10/14 16:44:59 INFO Vacuumed table table=pending_objects12952026/10/14 16:44:59 INFO Vacuumed table table=multipart_uploads12962026/10/14 16:44:59 INFO Vacuumed table table=closures12972026/10/14 16:44:59 INFO Vacuumed table table=objects1298--- PASS: TestGCSweepDeliversEachKeyOnce (0.65s)1299=== CONT TestClientIntegration13002026/10/14 16:44:59 INFO Received uploads request method=POST path=/api/pending_closures1301--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.62s)1302=== CONT TestPush_SignsNarinfosOfItsPendingObjects13032026/10/14 16:44:59 INFO Received uploads request method=POST path=/api/pending_closures13042026/10/14 16:44:59 INFO Received uploads request method=POST path=/api/pending_closures1305=== NAME TestClientCADerivations1306 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations618881203/001/store/jzrj90j0l8v91rh1by9bhp14zqmgm0yh-ca-test13072026/10/14 16:44:59 INFO Received uploads request method=POST path=/api/pending_closures13082026/10/14 16:44:59 INFO Aborted multipart uploads count=0 kept=013092026/10/14 16:44:59 INFO Received uploads request method=POST path=/api/pending_closures13102026/10/14 16:44:59 WARN Force mode enabled - objects will be deleted immediately without grace period13112026/10/14 16:44:59 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=013122026/10/14 16:44:59 INFO Vacuumed table table=pending_closures13132026/10/14 16:44:59 INFO Vacuumed table table=pending_objects13142026/10/14 16:44:59 INFO Vacuumed table table=multipart_uploads13152026/10/14 16:44:59 INFO Vacuumed table table=closures13162026/10/14 16:44:59 INFO Vacuumed table table=objects1317--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.77s)1318=== CONT TestClientErrorHandling1319=== RUN TestClientErrorHandling/InvalidStorePath1320=== PAUSE TestClientErrorHandling/InvalidStorePath1321=== RUN TestClientErrorHandling/InvalidAuthToken1322=== PAUSE TestClientErrorHandling/InvalidAuthToken1323=== RUN TestClientErrorHandling/ServerNotAvailable1324=== PAUSE TestClientErrorHandling/ServerNotAvailable1325=== CONT TestSkippedUploadsHandler13262026/10/14 16:44:59 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001327=== NAME TestClientCADerivations1328 client_ca_test.go:139: Found 1 dependencies (including self)1329--- PASS: TestGCSweepSkipsPendingObjects (0.64s)1330=== CONT TestPush_RejectsBadRequests1331--- PASS: TestSkippedUploadsHandler (0.01s)1332=== CONT TestPush_RepeatedRootCommitsOnce13332026/10/14 16:44:59 INFO Received uploads request method=POST path=/api/pending_closures1334--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.50s)1335=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit13362026/10/14 16:44:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1337--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.84s)1338=== CONT TestPush_CompleteWaitsForCleanupOfThePush13392026/10/14 16:44:59 INFO Received push request method=POST path=/api/pushes13402026/10/14 16:44:59 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13412026/10/14 16:44:59 INFO Uploading jzrj90j0l8v91rh1by9bhp14zqmgm0yh-ca-test (144B)13422026/10/14 16:44:59 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13432026/10/14 16:44:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13442026/10/14 16:44:59 WARN Failed to register uploaded object key=log/cvjkvalbyjwv293fgkfw406h2g1126f1-ca-test.drv error="server returned 404: 404 page not found\n"13452026/10/14 16:44:59 WARN Failed to register uploaded object key=jzrj90j0l8v91rh1by9bhp14zqmgm0yh.ls error="server returned 404: 404 page not found\n"13462026/10/14 16:44:59 INFO Signed narinfos id=1 count=113472026/10/14 16:44:59 INFO Uploading 1 narinfos13482026/10/14 16:44:59 INFO Received complete push request method=POST path=/api/pushes/1/complete13492026/10/14 16:44:59 WARN Failed to register uploaded object key=jzrj90j0l8v91rh1by9bhp14zqmgm0yh.narinfo error="server returned 404: 404 page not found\n"13502026/10/14 16:44:59 INFO Completed push id=1 objects=4 duration=6.395506ms13512026/10/14 16:44:59 INFO Upload complete. (92ms)1352=== NAME TestClientCADerivations1353 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations618881203/001/store/jzrj90j0l8v91rh1by9bhp14zqmgm0yh-ca-test1354 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1355 Compression: zstd1356 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1357 NarSize: 1441358 References: 1359 Deriver: /build/TestClientCADerivations618881203/001/store/cvjkvalbyjwv293fgkfw406h2g1126f1-ca-test.drv1360 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1361 client_ca_test.go:185: Checking for realisation files in S3...1362 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1363 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache13642026/10/14 16:44:59 INFO Received uploads request method=POST path=/api/pending_closures1365=== NAME TestPinProtectsFromGC1366 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC696247832/001/store/2i4j3ykwmd7af978mkdh60jrx8s23ax3-pinned-file.txt1367 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC696247832/001/store/ka18b80avvwbbqf7whmli13aqbbp72w9-unpinned-file.txt13682026/10/14 16:44:59 INFO Aborted multipart uploads count=0 kept=013692026/10/14 16:44:59 INFO Received uploads request method=POST path=/api/pending_closures13702026/10/14 16:44:59 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=013712026/10/14 16:44:59 INFO Received uploads request method=POST path=/api/pending_closures13722026/10/14 16:44:59 INFO Vacuumed table table=pending_closures13732026/10/14 16:44:59 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13742026/10/14 16:44:59 INFO Uploading ppv3vs93mnj8fwrmkmnh17avzzwgw69d-shared-dep (136B)13752026/10/14 16:44:59 INFO Uploading s6vxblys9r621553nsr3mb1kz5kri0rg-a (216B)13762026/10/14 16:44:59 INFO Vacuumed table table=pending_objects13772026/10/14 16:44:59 INFO Vacuumed table table=multipart_uploads13782026/10/14 16:44:59 WARN Failed to register uploaded object key=kikshmmsmzxfl6kx3z506bzwh8dka5ca.ls error="server returned 404: 404 page not found\n"13792026/10/14 16:44:59 WARN Failed to register uploaded object key=s6vxblys9r621553nsr3mb1kz5kri0rg.ls error="server returned 404: 404 page not found\n"13802026/10/14 16:44:59 WARN Failed to register uploaded object key=nar/0q6wciik9rn4kph4l781zlrgbi1rkv543cxcjm254jr1kgsxxzza.nar.zst error="server returned 404: 404 page not found\n"13812026/10/14 16:44:59 WARN Failed to register uploaded object key=ppv3vs93mnj8fwrmkmnh17avzzwgw69d.ls error="server returned 404: 404 page not found\n"13822026/10/14 16:44:59 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13832026/10/14 16:44:59 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13842026/10/14 16:44:59 INFO Signed narinfos id=1 count=213852026/10/14 16:44:59 INFO Vacuumed table table=closures13862026/10/14 16:44:59 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13872026/10/14 16:44:59 INFO Signed narinfos id=2 count=213882026/10/14 16:44:59 INFO Uploading 4 narinfos13892026/10/14 16:44:59 INFO Vacuumed table table=objects13902026/10/14 16:44:59 WARN Failed to register uploaded object key=ppv3vs93mnj8fwrmkmnh17avzzwgw69d.narinfo error="server returned 404: 404 page not found\n"13912026/10/14 16:44:59 WARN Failed to register uploaded object key=kikshmmsmzxfl6kx3z506bzwh8dka5ca.narinfo error="server returned 404: 404 page not found\n"13922026/10/14 16:44:59 WARN Failed to register uploaded object key=s6vxblys9r621553nsr3mb1kz5kri0rg.narinfo error="server returned 404: 404 page not found\n"13932026/10/14 16:44:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13942026/10/14 16:44:59 WARN Failed to register uploaded object key=ppv3vs93mnj8fwrmkmnh17avzzwgw69d.narinfo error="server returned 404: 404 page not found\n"13952026/10/14 16:44:59 INFO Aborted multipart uploads count=0 kept=013962026/10/14 16:44:59 WARN Force mode enabled - objects will be deleted immediately without grace period13972026/10/14 16:44:59 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=013982026/10/14 16:44:59 INFO Completed upload id=1 objects=6 duration=3.313118ms13992026/10/14 16:44:59 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14002026/10/14 16:44:59 INFO Completed upload id=2 objects=6 duration=1.167059ms14012026/10/14 16:44:59 INFO Upload complete. (85ms)14022026/10/14 16:44:59 INFO Received push request method=POST path=/api/pushes14032026/10/14 16:44:59 INFO Vacuumed table table=pending_closures1404=== NAME TestClientFallsBackToClosures1405 client_pushes_test.go:112: Retrieved narinfo from S3:1406 StorePath: /build/TestClientFallsBackToClosures2324391985/001/store/ppv3vs93mnj8fwrmkmnh17avzzwgw69d-shared-dep1407 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1408 Compression: zstd1409 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821410 NarSize: 1361411 References: 1412 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n14132026/10/14 16:44:59 INFO Vacuumed table table=pending_objects1414 client_pushes_test.go:112: Retrieved narinfo from S3:1415 StorePath: /build/TestClientFallsBackToClosures2324391985/001/store/s6vxblys9r621553nsr3mb1kz5kri0rg-a1416 URL: nar/0q6wciik9rn4kph4l781zlrgbi1rkv543cxcjm254jr1kgsxxzza.nar.zst14172026/10/14 16:44:59 INFO Vacuumed table table=multipart_uploads1418 Compression: zstd1419 NarHash: sha256:0q6wciik9rn4kph4l781zlrgbi1rkv543cxcjm254jr1kgsxxzza1420 NarSize: 2161421 References: /build/TestClientFallsBackToClosures2324391985/001/store/ppv3vs93mnj8fwrmkmnh17avzzwgw69d-shared-dep1422 CA: text:sha256:15scksxqz5vxgp6apjzqnwpxjlfaiq3srssc0fl62prjw6js343x14232026/10/14 16:44:59 INFO Received push request method=POST path=/api/pushes14242026/10/14 16:44:59 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14252026/10/14 16:44:59 INFO Uploading 2i4j3ykwmd7af978mkdh60jrx8s23ax3-pinned-file.txt (128B)14262026/10/14 16:44:59 INFO Vacuumed table table=closures14272026/10/14 16:44:59 INFO Vacuumed table table=objects1428 client_pushes_test.go:112: Retrieved narinfo from S3:1429 StorePath: /build/TestClientFallsBackToClosures2324391985/001/store/kikshmmsmzxfl6kx3z506bzwh8dka5ca-b1430 URL: nar/0q6wciik9rn4kph4l781zlrgbi1rkv543cxcjm254jr1kgsxxzza.nar.zst1431 Compression: zstd1432 NarHash: sha256:0q6wciik9rn4kph4l781zlrgbi1rkv543cxcjm254jr1kgsxxzza1433 NarSize: 2161434 References: /build/TestClientFallsBackToClosures2324391985/001/store/ppv3vs93mnj8fwrmkmnh17avzzwgw69d-shared-dep1435 CA: text:sha256:15scksxqz5vxgp6apjzqnwpxjlfaiq3srssc0fl62prjw6js343x1436--- PASS: TestPushDedupSurvivesConcurrentGC (0.54s)1437=== CONT TestService_RequireScope_OIDC1438=== NAME TestClientCADerivations1439 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1440 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1441 error: binary cache 's3://bucket59?endpoint=http://localhost:33333®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations618881203/001/store'1442 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 114432026/10/14 16:44:59 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14442026/10/14 16:44:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14452026/10/14 16:44:59 WARN Failed to register uploaded object key=2i4j3ykwmd7af978mkdh60jrx8s23ax3.ls error="server returned 404: 404 page not found\n"14462026/10/14 16:44:59 INFO Signed narinfos id=1 count=114472026/10/14 16:44:59 INFO Uploading 1 narinfos14482026/10/14 16:44:59 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14492026/10/14 16:44:59 INFO Uploading gklv5pmxzsilrajqa2dgx002g1j534hf-a (208B)14502026/10/14 16:44:59 INFO Uploading ipy0xzahvnh5620a6flfpaqsglks0hx8-shared-dep (136B)1451--- PASS: TestClientFallsBackToClosures (0.81s)1452=== CONT TestCacheConfigHandler1453=== RUN TestCacheConfigHandler/full_config,_no_issuer1454=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1455=== RUN TestCacheConfigHandler/no_cache_url_configured1456=== PAUSE TestCacheConfigHandler/no_cache_url_configured1457=== RUN TestCacheConfigHandler/no_signing_keys1458=== PAUSE TestCacheConfigHandler/no_signing_keys1459=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1460=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1461=== CONT TestParseSize1462--- PASS: TestParseSize (0.00s)1463=== CONT TestService_ReadScope_PublicByDefault14642026/10/14 16:44:59 INFO Received complete push request method=POST path=/api/pushes/1/complete14652026/10/14 16:44:59 WARN Failed to register uploaded object key=2i4j3ykwmd7af978mkdh60jrx8s23ax3.narinfo error="server returned 404: 404 page not found\n"1466--- PASS: TestClientCADerivations (0.98s)1467=== CONT TestCacheStatsHandler14682026/10/14 16:44:59 WARN Failed to register uploaded object key=nar/0nf8m2gg1fhjnxv71il6rpk1ffnrp2i9ln201afzz258cn9arxai.nar.zst error="server returned 404: 404 page not found\n"14692026/10/14 16:44:59 WARN Failed to register uploaded object key=2cp41lds6brm7i0ag7fn8yp3npxr3nlm.ls error="server returned 404: 404 page not found\n"14702026/10/14 16:44:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14712026/10/14 16:44:59 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14722026/10/14 16:44:59 WARN Failed to register uploaded object key=ipy0xzahvnh5620a6flfpaqsglks0hx8.ls error="server returned 404: 404 page not found\n"14732026/10/14 16:44:59 WARN Failed to register uploaded object key=gklv5pmxzsilrajqa2dgx002g1j534hf.ls error="server returned 404: 404 page not found\n"14742026/10/14 16:44:59 INFO Signed narinfos id=1 count=314752026/10/14 16:44:59 INFO Uploading 3 narinfos14762026/10/14 16:44:59 INFO Received push request method=POST path=/api/pushes14772026/10/14 16:44:59 WARN Failed to register uploaded object key=ipy0xzahvnh5620a6flfpaqsglks0hx8.narinfo error="server returned 404: 404 page not found\n"14782026/10/14 16:44:59 WARN Failed to register uploaded object key=2cp41lds6brm7i0ag7fn8yp3npxr3nlm.narinfo error="server returned 404: 404 page not found\n"14792026/10/14 16:44:59 INFO Received complete push request method=POST path=/api/pushes/1/complete14802026/10/14 16:44:59 WARN Failed to register uploaded object key=gklv5pmxzsilrajqa2dgx002g1j534hf.narinfo error="server returned 404: 404 page not found\n"14812026/10/14 16:44:59 INFO Completed push id=1 objects=3 duration=6.240676ms14822026/10/14 16:44:59 INFO Upload complete. (52ms)14832026/10/14 16:44:59 INFO Completed push id=1 objects=8 duration=10.663943ms14842026/10/14 16:44:59 INFO Upload complete. (61ms)1485=== NAME TestClientPushesUseOnePush1486 client_pushes_test.go:97: Retrieved narinfo from S3:1487 StorePath: /build/TestClientPushesUseOnePush504170037/001/store/ipy0xzahvnh5620a6flfpaqsglks0hx8-shared-dep1488 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1489 Compression: zstd1490 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821491 NarSize: 1361492 References: 1493 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1494 client_pushes_test.go:97: Retrieved narinfo from S3:1495 StorePath: /build/TestClientPushesUseOnePush504170037/001/store/gklv5pmxzsilrajqa2dgx002g1j534hf-a1496 URL: nar/0nf8m2gg1fhjnxv71il6rpk1ffnrp2i9ln201afzz258cn9arxai.nar.zst1497 Compression: zstd1498 NarHash: sha256:0nf8m2gg1fhjnxv71il6rpk1ffnrp2i9ln201afzz258cn9arxai1499 NarSize: 2081500 References: /build/TestClientPushesUseOnePush504170037/001/store/ipy0xzahvnh5620a6flfpaqsglks0hx8-shared-dep1501 CA: text:sha256:1jijp2f706nm9wpgn05c32b09pxlq0ibmslhbj5xgwicp6afx6w31502=== NAME TestClientMultipleUploads1503 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads1724253531/001/store/kgg11sf6ibd5lvzfqy7yczk070srbaks-test-file-0.txt1504=== NAME TestClientPushesUseOnePush1505 client_pushes_test.go:97: Retrieved narinfo from S3:1506 StorePath: /build/TestClientPushesUseOnePush504170037/001/store/2cp41lds6brm7i0ag7fn8yp3npxr3nlm-b1507 URL: nar/0nf8m2gg1fhjnxv71il6rpk1ffnrp2i9ln201afzz258cn9arxai.nar.zst1508 Compression: zstd1509 NarHash: sha256:0nf8m2gg1fhjnxv71il6rpk1ffnrp2i9ln201afzz258cn9arxai1510 NarSize: 2081511 References: /build/TestClientPushesUseOnePush504170037/001/store/ipy0xzahvnh5620a6flfpaqsglks0hx8-shared-dep1512 CA: text:sha256:1jijp2f706nm9wpgn05c32b09pxlq0ibmslhbj5xgwicp6afx6w31513--- PASS: TestClientPushesUseOnePush (0.75s)1514=== CONT TestService_Rustfstest15152026/10/14 16:44:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33703/oidc1516=== NAME TestClientWithDependencies1517 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2164302774/001/store/j864ddxvgr8skbnzva1bisxilsn68ji9-test-script15182026-10-14 16:44:59.651 UTC [1671] ERROR: could not obtain lock on row in relation "closures"15192026-10-14 16:44:59.651 UTC [1671] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT15202026-10-14 16:44:59.652 UTC [1671] ERROR: could not obtain lock on row in relation "closures"15212026-10-14 16:44:59.652 UTC [1671] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT15222026-10-14 16:44:59.652 UTC [1671] ERROR: could not obtain lock on row in relation "closures"15232026-10-14 16:44:59.652 UTC [1671] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT15242026-10-14 16:44:59.652 UTC [1671] ERROR: could not obtain lock on row in relation "closures"15252026-10-14 16:44:59.652 UTC [1671] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT15262026-10-14 16:44:59.652 UTC [1671] ERROR: could not obtain lock on row in relation "closures"15272026-10-14 16:44:59.652 UTC [1671] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT15282026/10/14 16:44:59 INFO Received push request method=POST path=/api/pushes1529--- PASS: TestPush_RootsAreLockedInByteOrder (0.52s)1530=== CONT TestPush_CompleteCommitsEveryRoot15312026/10/14 16:44:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15322026/10/14 16:44:59 INFO Signed narinfos id=1 count=115332026/10/14 16:44:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15342026/10/14 16:44:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15352026/10/14 16:44:59 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"15362026/10/14 16:44:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15372026/10/14 16:44:59 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"15382026/10/14 16:44:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15392026/10/14 16:44:59 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=115402026/10/14 16:44:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15412026/10/14 16:44:59 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1542--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.40s)1543=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1544=== NAME TestClientMultipleUploads1545 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads1724253531/001/store/hlqxdvalnsak69z9290572v3hf7b6k57-test-file-1.txt15462026/10/14 16:44:59 INFO Received push request method=POST path=/api/pushes1547=== NAME TestClientIntegration1548 client_integration_test.go:286: Created store path: /build/TestClientIntegration4242598906/002/store/7ndpch9x6069g7fndv7242pi90fp27a8-test-file.txt1549=== NAME TestClientWithDependencies1550 client_integration_test.go:615: Found 1 dependencies (including self)1551=== RUN TestPush_RejectsBadRequests/no_roots1552=== PAUSE TestPush_RejectsBadRequests/no_roots1553=== RUN TestPush_RejectsBadRequests/no_objects1554=== PAUSE TestPush_RejectsBadRequests/no_objects1555=== RUN TestPush_RejectsBadRequests/bad_root1556=== PAUSE TestPush_RejectsBadRequests/bad_root1557=== RUN TestPush_RejectsBadRequests/root_not_in_objects1558=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1559=== CONT TestService_ReadAuthMiddleware15602026/10/14 16:44:59 INFO Received push request method=POST path=/api/pushes15612026/10/14 16:44:59 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)15622026/10/14 16:44:59 INFO Uploading j6vd7wlwmjkkqbk4mmxg8gr2mb3459hd-top (224B)15632026/10/14 16:44:59 INFO Uploading avg7dxcjrpz0ykj6w6s12k3yczmyzk2g-shared-dep (136B)15642026/10/14 16:44:59 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15652026/10/14 16:44:59 INFO Uploading ka18b80avvwbbqf7whmli13aqbbp72w9-unpinned-file.txt (128B)15662026/10/14 16:44:59 WARN Failed to register uploaded object key=avg7dxcjrpz0ykj6w6s12k3yczmyzk2g.ls error="server returned 404: 404 page not found\n"15672026/10/14 16:44:59 WARN Failed to register uploaded object key=j6vd7wlwmjkkqbk4mmxg8gr2mb3459hd.ls error="server returned 404: 404 page not found\n"15682026/10/14 16:44:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15692026/10/14 16:44:59 WARN Failed to register uploaded object key=nar/1wxrmjjamipcgpar2nf5dambd3ar6slfk1pvaqczby194hpwx2mi.nar.zst error="server returned 404: 404 page not found\n"15702026/10/14 16:44:59 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15712026/10/14 16:44:59 INFO Signed narinfos id=1 count=215722026/10/14 16:44:59 INFO Uploading 2 narinfos15732026/10/14 16:44:59 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15742026/10/14 16:44:59 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15752026/10/14 16:44:59 INFO Signed narinfos id=2 count=115762026/10/14 16:44:59 WARN Failed to register uploaded object key=ka18b80avvwbbqf7whmli13aqbbp72w9.ls error="server returned 404: 404 page not found\n"15772026/10/14 16:44:59 INFO Uploading 1 narinfos15782026/10/14 16:44:59 WARN Failed to register uploaded object key=j6vd7wlwmjkkqbk4mmxg8gr2mb3459hd.narinfo error="server returned 404: 404 page not found\n"15792026/10/14 16:44:59 INFO Received complete push request method=POST path=/api/pushes/1/complete15802026/10/14 16:44:59 WARN Failed to register uploaded object key=avg7dxcjrpz0ykj6w6s12k3yczmyzk2g.narinfo error="server returned 404: 404 page not found\n"15812026/10/14 16:44:59 INFO Received complete push request method=POST path=/api/pushes/2/complete15822026/10/14 16:44:59 WARN Failed to register uploaded object key=ka18b80avvwbbqf7whmli13aqbbp72w9.narinfo error="server returned 404: 404 page not found\n"15832026/10/14 16:44:59 INFO Received push request method=POST path=/api/pushes15842026/10/14 16:44:59 INFO Completed push id=2 objects=3 duration=4.479847ms15852026/10/14 16:44:59 INFO Upload complete. (52ms)15862026/10/14 16:44:59 INFO Completed push id=1 objects=6 duration=7.212655ms1587=== NAME TestClientMultipleUploads1588 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads1724253531/001/store/kzckzbsg6af6kwqndz9kkgc0764kqjfb-test-file-2.txt15892026/10/14 16:44:59 INFO Upload complete. (76ms)1590=== NAME TestClientSharedPathCommittedMidPush1591 client_integration_test.go:680: Retrieved narinfo from S3:1592 StorePath: /build/TestClientSharedPathCommittedMidPush3823322324/001/store/avg7dxcjrpz0ykj6w6s12k3yczmyzk2g-shared-dep1593 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1594 Compression: zstd1595 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821596 NarSize: 1361597 References: 1598 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1599 client_integration_test.go:680: Retrieved narinfo from S3:1600 StorePath: /build/TestClientSharedPathCommittedMidPush3823322324/001/store/j6vd7wlwmjkkqbk4mmxg8gr2mb3459hd-top1601 URL: nar/1wxrmjjamipcgpar2nf5dambd3ar6slfk1pvaqczby194hpwx2mi.nar.zst1602 Compression: zstd1603 NarHash: sha256:1wxrmjjamipcgpar2nf5dambd3ar6slfk1pvaqczby194hpwx2mi1604 NarSize: 2241605 References: /build/TestClientSharedPathCommittedMidPush3823322324/001/store/avg7dxcjrpz0ykj6w6s12k3yczmyzk2g-shared-dep1606 CA: text:sha256:1bi62hlamz7176n1d6a4s2cz0s5qq0yhvrm92g9vars37lxyyhi41607--- PASS: TestClientSharedPathCommittedMidPush (0.60s)1608=== CONT TestCompletedNarNotReofferedAcrossClosures16092026/10/14 16:44:59 INFO Received complete push request method=POST path=/api/pushes/1/complete16102026/10/14 16:44:59 INFO Received push request method=POST path=/api/pushes16112026/10/14 16:44:59 INFO Starting cleanup of old closures method=DELETE path=/api/closures16122026/10/14 16:44:59 INFO Garbage collection started16132026/10/14 16:44:59 INFO Received push request method=POST path=/api/pushes16142026/10/14 16:44:59 INFO Completed push id=1 objects=4 duration=25.017443ms16152026/10/14 16:44:59 INFO Received complete push request method=POST path=/api/pushes/1/complete1616--- PASS: TestPush_RepeatedRootCommitsOnce (0.38s)1617=== CONT TestService_AuthMiddleware_OIDC16182026/10/14 16:44:59 INFO Received push request method=POST path=/api/pushes16192026/10/14 16:44:59 INFO Received push request method=POST path=/api/pushes16202026/10/14 16:44:59 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16212026/10/14 16:44:59 INFO Uploading 7ndpch9x6069g7fndv7242pi90fp27a8-test-file.txt (152B)16222026/10/14 16:44:59 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16232026/10/14 16:44:59 INFO Uploading j864ddxvgr8skbnzva1bisxilsn68ji9-test-script (136B)16242026/10/14 16:44:59 INFO Aborted multipart uploads count=0 kept=016252026/10/14 16:44:59 INFO Completed push id=1 objects=4 duration=9.370654ms16262026/10/14 16:44:59 INFO Received push request method=POST path=/api/pushes16272026/10/14 16:44:59 WARN Failed to register uploaded object key=7ndpch9x6069g7fndv7242pi90fp27a8.ls error="server returned 404: 404 page not found\n"16282026/10/14 16:44:59 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"16292026/10/14 16:44:59 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"16302026/10/14 16:44:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16312026/10/14 16:44:59 WARN Failed to register uploaded object key=log/jp1yv06jznphpdfkb8mqw6h3pmgb15fq-test-script.drv error="server returned 404: 404 page not found\n"16322026/10/14 16:44:59 INFO Signed narinfos id=1 count=116332026/10/14 16:44:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16342026/10/14 16:44:59 INFO Uploading 1 narinfos16352026/10/14 16:44:59 WARN Failed to register uploaded object key=j864ddxvgr8skbnzva1bisxilsn68ji9.ls error="server returned 404: 404 page not found\n"16362026/10/14 16:44:59 INFO Signed narinfos id=1 count=116372026/10/14 16:44:59 INFO Uploading 1 narinfos16382026/10/14 16:44:59 INFO Received complete push request method=POST path=/api/pushes/1/complete16392026/10/14 16:44:59 INFO Received complete push request method=POST path=/api/pushes/1/complete16402026/10/14 16:44:59 WARN Failed to register uploaded object key=7ndpch9x6069g7fndv7242pi90fp27a8.narinfo error="server returned 404: 404 page not found\n"16412026/10/14 16:44:59 WARN Failed to register uploaded object key=j864ddxvgr8skbnzva1bisxilsn68ji9.narinfo error="server returned 404: 404 page not found\n"16422026/10/14 16:44:59 WARN Force mode enabled - objects will be deleted immediately without grace period16432026/10/14 16:44:59 INFO Completed push id=1 objects=3 duration=7.007345ms16442026/10/14 16:44:59 INFO Upload complete. (62ms)16452026/10/14 16:44:59 INFO Completed push id=1 objects=4 duration=9.693473ms16462026/10/14 16:44:59 INFO Upload complete. (68ms)1647=== NAME TestClientWithDependencies1648 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2164302774/001/store) requires matching store prefix1649--- PASS: TestClientWithDependencies (0.66s)1650=== CONT TestService_AuthMiddleware_MTLSBoundSubjects16512026/10/14 16:44:59 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=016522026/10/14 16:44:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16532026/10/14 16:44:59 INFO Vacuumed table table=pending_closures16542026/10/14 16:44:59 INFO Received push request method=POST path=/api/pushes16552026/10/14 16:44:59 INFO Vacuumed table table=pending_objects16562026/10/14 16:44:59 INFO Vacuumed table table=multipart_uploads16572026/10/14 16:44:59 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)16582026/10/14 16:44:59 INFO Uploading kzckzbsg6af6kwqndz9kkgc0764kqjfb-test-file-2.txt (160B)16592026/10/14 16:44:59 INFO Uploading hlqxdvalnsak69z9290572v3hf7b6k57-test-file-1.txt (160B)16602026/10/14 16:44:59 INFO Uploading kgg11sf6ibd5lvzfqy7yczk070srbaks-test-file-0.txt (160B)16612026/10/14 16:44:59 INFO Vacuumed table table=closures16622026/10/14 16:44:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40883/oidc16632026/10/14 16:44:59 INFO Vacuumed table table=objects16642026/10/14 16:44:59 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"16652026/10/14 16:44:59 WARN Failed to register uploaded object key=kgg11sf6ibd5lvzfqy7yczk070srbaks.ls error="server returned 404: 404 page not found\n"16662026/10/14 16:44:59 WARN Failed to register uploaded object key=kzckzbsg6af6kwqndz9kkgc0764kqjfb.ls error="server returned 404: 404 page not found\n"16672026/10/14 16:44:59 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"16682026/10/14 16:44:59 WARN Failed to register uploaded object key=hlqxdvalnsak69z9290572v3hf7b6k57.ls error="server returned 404: 404 page not found\n"16692026/10/14 16:44:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16702026/10/14 16:44:59 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"16712026/10/14 16:44:59 INFO Signed narinfos id=1 count=316722026/10/14 16:44:59 INFO Uploading 3 narinfos16732026/10/14 16:44:59 WARN Failed to register uploaded object key=kzckzbsg6af6kwqndz9kkgc0764kqjfb.narinfo error="server returned 404: 404 page not found\n"16742026/10/14 16:44:59 WARN Failed to register uploaded object key=kgg11sf6ibd5lvzfqy7yczk070srbaks.narinfo error="server returned 404: 404 page not found\n"16752026/10/14 16:44:59 INFO Received complete push request method=POST path=/api/pushes/1/complete16762026/10/14 16:44:59 WARN Failed to register uploaded object key=hlqxdvalnsak69z9290572v3hf7b6k57.narinfo error="server returned 404: 404 page not found\n"16772026/10/14 16:44:59 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YjhlYjQyZmQtNmNhMS00MDI0LWI2MWYtYWViZGE2N2U3MTdhLjI4ZTVkMWYxLWFmMjItNDhkYi1hMWUyLTE3Yzg4YjU4ZDdiYXgxNzkxOTk2Mjk5Mjk4ODQ3NjM5 parts=1216782026/10/14 16:44:59 INFO All 1 paths already cached16792026/10/14 16:44:59 INFO Received uploads request method=POST path=/api/pending_closures1680=== NAME TestClientIntegration1681 client_integration_test.go:312: Retrieved narinfo from S3:1682 StorePath: /build/TestClientIntegration4242598906/002/store/7ndpch9x6069g7fndv7242pi90fp27a8-test-file.txt1683 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1684 Compression: zstd1685 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11686 NarSize: 1521687 References: 1688 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11689 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1690 client_integration_test.go:313: Decompressed .ls content (64 bytes):1691 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1692 client_integration_test.go:316: Testing garbage collection...16932026/10/14 16:44:59 INFO Completed push id=1 objects=9 duration=6.884305ms16942026/10/14 16:44:59 INFO Upload complete. (74ms)1695=== NAME TestClientMultipleUploads1696 client_integration_test.go:369: Uploaded 3 paths in 106.13569ms16972026/10/14 16:44:59 INFO Received uploads request method=POST path=/api/pending_closures16982026/10/14 16:44:59 INFO Aborted multipart uploads count=0 kept=01699--- PASS: TestClientMultipleUploads (0.69s)1700=== CONT TestService_AuthMiddleware_MTLSProxyHeader17012026/10/14 16:44:59 WARN Force mode enabled - objects will be deleted immediately without grace period1702--- PASS: TestCacheStatsHandler (0.22s)1703=== CONT TestPresignedUploadRegisteredBeforeCommit17042026/10/14 16:44:59 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=01705--- PASS: TestService_ReadScope_PublicByDefault (0.22s)1706=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17072026/10/14 16:44:59 INFO Received uploads request method=POST path=/1708=== CONT TestProxyWriteTimeout/narinfo1709=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17102026/10/14 16:44:59 INFO Received uploads request method=POST path=/1711=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17122026/10/14 16:44:59 INFO Received request for more parts method=POST path=/1713=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17142026/10/14 16:44:59 INFO Received complete multipart upload request method=POST path=/1715--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1716 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1717 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1718 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1719 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1720=== CONT TestPendingClosureWriteTimeout/empty1721=== CONT TestProxyWriteTimeout/unknown_size1722=== CONT TestProxyWriteTimeout/10_GiB_nar1723=== CONT TestProxyWriteTimeout/1_GiB_nar1724--- PASS: TestProxyWriteTimeout (0.01s)1725 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1726 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1727 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1728 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1729=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline17302026/10/14 16:44:59 INFO Vacuumed table table=pending_closures17312026/10/14 16:44:59 INFO Vacuumed table table=pending_objects17322026/10/14 16:44:59 INFO Vacuumed table table=multipart_uploads17332026/10/14 16:44:59 INFO Starting cleanup of old closures method=DELETE path=/api/closures17342026/10/14 16:44:59 INFO Garbage collection started17352026/10/14 16:44:59 INFO Vacuumed table table=closures17362026/10/14 16:44:59 INFO Vacuumed table table=objects17372026/10/14 16:44:59 INFO Received complete push request method=POST path=/api/pushes/2/complete17382026/10/14 16:44:59 INFO Aborted multipart uploads count=0 kept=017392026/10/14 16:44:59 INFO Completed push id=2 objects=4 duration=5.281346ms1740--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.42s)1741=== CONT TestPendingClosureWriteTimeout/670k_objects1742=== CONT TestPendingClosureWriteTimeout/400_objects1743=== CONT TestIsValidUploadKey/narinfo1744=== CONT TestIsValidUploadKey/realisation_plus_in_output1745=== CONT TestIsValidUploadKey/unknown_type1746=== CONT TestIsValidUploadKey/empty_key1747=== CONT TestIsValidUploadKey/absolute1748=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1749=== CONT TestIsValidUploadKey/index.html1750=== CONT TestIsValidUploadKey/nix-cache-info1751=== CONT TestIsValidUploadKey/traversal1752=== CONT TestIsValidUploadKey/traversal_nar1753=== CONT TestIsValidUploadKey/build_log_home-manager_file1754=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1755=== CONT TestIsValidUploadKey/realisation1756=== CONT TestIsValidUploadKey/build_log_equals1757=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1758=== CONT TestIsValidUploadKey/build_log_question_mark1759=== CONT TestIsValidUploadKey/build_log_plus_in_name1760=== CONT TestIsValidUploadKey/nar_plain1761=== CONT TestIsValidUploadKey/nar_xz1762=== CONT TestIsValidUploadKey/build_log1763=== CONT TestIsValidUploadKey/listing1764=== CONT TestIsValidUploadKey/nar_zst1765--- PASS: TestIsValidUploadKey (0.08s)1766 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1767 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1768 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1769 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1770 --- PASS: TestIsValidUploadKey/absolute (0.00s)1771 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1772 --- PASS: TestIsValidUploadKey/index.html (0.00s)1773 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1774 --- PASS: TestIsValidUploadKey/traversal (0.00s)1775 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1776 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1777 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1778 --- PASS: TestIsValidUploadKey/realisation (0.00s)1779 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1780 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1781 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1782 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1783 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1784 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1785 --- PASS: TestIsValidUploadKey/build_log (0.00s)1786 --- PASS: TestIsValidUploadKey/listing (0.00s)1787 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1788=== CONT TestIsValidCachePath/narinfo1789=== CONT TestIsValidCachePath/index.html1790=== CONT TestIsValidCachePath/invalid_char_u1791=== CONT TestIsValidCachePath/invalid_char_e1792=== CONT TestIsValidCachePath/random_path1793=== CONT TestIsValidCachePath/traversal_in_middle1794=== CONT TestIsValidCachePath/short_hash1795=== CONT TestIsValidCachePath/traversal_parent1796=== CONT TestIsValidCachePath/wrong_extension1797=== CONT TestIsValidCachePath/empty1798=== CONT TestIsValidCachePath/leading_slash1799=== CONT TestIsValidCachePath/nar_uncompressed1800=== CONT TestIsValidCachePath/nix-cache-info1801=== CONT TestIsValidCachePath/nar_xz1802=== CONT TestIsValidCachePath/realisation1803=== CONT TestIsValidCachePath/nar_bz21804=== CONT TestIsValidCachePath/log1805=== CONT TestIsValidCachePath/ls1806=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1807=== CONT TestIsValidCachePath/nar_zst1808--- PASS: TestIsValidCachePath (0.00s)1809 --- PASS: TestIsValidCachePath/narinfo (0.00s)1810 --- PASS: TestIsValidCachePath/index.html (0.00s)1811 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1812 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1813 --- PASS: TestIsValidCachePath/random_path (0.00s)1814 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1815 --- PASS: TestIsValidCachePath/short_hash (0.00s)1816 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1817 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1818 --- PASS: TestIsValidCachePath/empty (0.00s)1819 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1820 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1821 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1822 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1823 --- PASS: TestIsValidCachePath/realisation (0.00s)1824 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1825 --- PASS: TestIsValidCachePath/log (0.00s)1826 --- PASS: TestIsValidCachePath/ls (0.00s)1827 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1828 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1829=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18302026/10/14 16:44:59 INFO Received complete multipart upload request method=POST path=/1831--- PASS: TestDeleteClosuresRacingPins (1.76s)1832=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18332026/10/14 16:44:59 INFO Received uploads request method=POST path=/18342026/10/14 16:44:59 WARN Force mode enabled - objects will be deleted immediately without grace period18352026/10/14 16:44:59 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=01836=== RUN TestService_RequireScope_OIDC/builder_may_write1837=== PAUSE TestService_RequireScope_OIDC/builder_may_write1838=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1839=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1840=== RUN TestService_RequireScope_OIDC/ops_may_admin1841=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1842=== RUN TestService_RequireScope_OIDC/ops_may_not_write1843=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1844=== RUN TestService_RequireScope_OIDC/reader_may_not_write1845=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1846=== RUN TestService_RequireScope_OIDC/static_token_may_admin1847=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1848=== RUN TestService_RequireScope_OIDC/static_token_may_write1849=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1850=== RUN TestService_RequireScope_OIDC/reader_may_read1851=== PAUSE TestService_RequireScope_OIDC/reader_may_read1852=== RUN TestService_RequireScope_OIDC/writer_implies_read1853=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1854=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1855=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1856=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1857=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1858=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1859=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1860=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1861=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1862=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1863=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1864=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18652026/10/14 16:44:59 INFO Received request for more parts method=POST path=/18662026/10/14 16:44:59 INFO Vacuumed table table=pending_closures18672026/10/14 16:44:59 INFO Vacuumed table table=pending_objects18682026/10/14 16:44:59 INFO Vacuumed table table=multipart_uploads1869--- PASS: TestService_Rustfstest (0.25s)1870=== CONT TestServerTLSConfig/no_client_CA1871=== CONT TestServerTLSConfig/not_a_PEM_file1872=== CONT TestServerTLSConfig/missing_CA_file1873--- PASS: TestServerTLSConfig (0.00s)1874 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1875 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1876 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1877=== CONT TestGCEndsOnShutdown/before_the_run18782026/10/14 16:44:59 INFO Vacuumed table table=closures18792026/10/14 16:44:59 INFO Vacuumed table table=objects18802026/10/14 16:44:59 INFO Received push request method=POST path=/api/pushes1881=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark18822026/10/14 16:44:59 INFO Received complete push request method=POST path=/api/pushes/1/complete18832026/10/14 16:44:59 INFO Completed push id=1 objects=6 duration=6.492126ms1884--- PASS: TestPush_CompleteCommitsEveryRoot (0.28s)1885=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1886=== CONT TestParseSingleRange/none1887=== CONT TestParseSingleRange/open-ended1888=== CONT TestParseSingleRange/start_far_past_EOF1889=== CONT TestParseSingleRange/start_past_EOF1890=== CONT TestParseSingleRange/single_byte1891=== CONT TestParseSingleRange/suffix_exceeds_size1892=== CONT TestParseSingleRange/suffix1893=== CONT TestParseSingleRange/end_clamped_to_size1894=== CONT TestParseSingleRange/malformed_both_empty1895=== CONT TestParseSingleRange/multi-range_ignored1896=== CONT TestParseSingleRange/closed1897=== CONT TestParseSingleRange/malformed_no_dash1898=== CONT TestParseSingleRange/malformed_end_before_start1899=== CONT TestParseSingleRange/unknown_unit1900--- PASS: TestParseSingleRange (0.00s)1901 --- PASS: TestParseSingleRange/none (0.00s)1902 --- PASS: TestParseSingleRange/open-ended (0.00s)1903 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1904 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1905 --- PASS: TestParseSingleRange/single_byte (0.00s)1906 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1907 --- PASS: TestParseSingleRange/suffix (0.00s)1908 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1909 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1910 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1911 --- PASS: TestParseSingleRange/closed (0.00s)1912 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1913 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1914 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1915=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale19162026/10/14 16:44:59 INFO Received uploads request method=POST path=/api/pending_closures1917--- PASS: TestService_ReadAuthMiddleware (0.30s)1918=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1919=== NAME TestOrphanedObjectsGCStressTest1920 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains19212026/10/14 16:44:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19222026/10/14 16:44:59 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YjhlYjQyZmQtNmNhMS00MDI0LWI2MWYtYWViZGE2N2U3MTdhLmUxY2MxYjVjLWQzZjUtNGRjZC05YzQ4LTFlN2FjNmZiMTVhZngxNzkxOTk2Mjk5OTUxNjAzNzcx19232026/10/14 16:44:59 INFO lead: released remote=192.0.2.1:12341924--- PASS: TestLeadEndsOnShutdown (1.77s)1925=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows19262026/10/14 16:45:00 INFO Received uploads request method=POST path=/api/pending_closures19272026/10/14 16:45:00 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YjhlYjQyZmQtNmNhMS00MDI0LWI2MWYtYWViZGE2N2U3MTdhLmUxY2MxYjVjLWQzZjUtNGRjZC05YzQ4LTFlN2FjNmZiMTVhZngxNzkxOTk2Mjk5OTUxNjAzNzcx parts=11928--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.35s)1929=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1930=== NAME TestOrphanedObjectsGCStressTest1931 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion19322026/10/14 16:45:00 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"19332026/10/14 16:45:00 WARN mTLS auth: bound subjects configured but subject DN unavailable19342026/10/14 16:45:00 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1935--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.26s)1936=== CONT TestResolveDBConnectionString/flag_wins1937=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1938=== CONT TestResolveDBConnectionString/nothing_configured1939=== CONT TestResolveDBConnectionString/missing_file_is_an_error1940=== CONT TestResolveDBConnectionString/file_when_flag_empty1941=== CONT TestClientErrorHandling/InvalidStorePath1942--- PASS: TestResolveDBConnectionString (0.00s)1943 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1944 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1945 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1946 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1947 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1948=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1949=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1950=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1951=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1952=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1953=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1954=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1955=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1956=== CONT TestClientErrorHandling/InvalidAuthToken19572026-10-14 16:45:00.083 UTC [1924] ERROR: Push does not exist: id=119582026-10-14 16:45:00.083 UTC [1924] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE19592026-10-14 16:45:00.083 UTC [1924] STATEMENT: SELECT commit_push($1)1960--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.63s)1961=== CONT TestClientErrorHandling/ServerNotAvailable1962--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.29s)1963=== CONT TestCacheConfigHandler/full_config,_no_issuer1964=== CONT TestCacheConfigHandler/no_signing_keys1965=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1966=== CONT TestCacheConfigHandler/no_cache_url_configured1967--- PASS: TestCacheConfigHandler (0.00s)1968 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1969 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1970 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1971 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1972=== CONT TestPush_RejectsBadRequests/no_roots19732026/10/14 16:45:00 INFO Received push request method=POST path=/api/pushes1974=== CONT TestPush_RejectsBadRequests/bad_root19752026/10/14 16:45:00 INFO Received push request method=POST path=/api/pushes1976=== CONT TestPush_RejectsBadRequests/root_not_in_objects19772026/10/14 16:45:00 INFO Received push request method=POST path=/api/pushes1978=== CONT TestPush_RejectsBadRequests/no_objects19792026/10/14 16:45:00 INFO Received push request method=POST path=/api/pushes1980=== CONT TestService_RequireScope_OIDC/builder_may_write1981--- PASS: TestPush_RejectsBadRequests (0.31s)1982 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1983 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1984 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1985 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1986=== CONT TestService_RequireScope_OIDC/reader_may_read1987=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1988=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19892026/10/14 16:45:00 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]1990=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1991=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1992=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1993=== CONT TestService_RequireScope_OIDC/writer_implies_read1994=== CONT TestService_RequireScope_OIDC/static_token_may_write1995=== CONT TestService_RequireScope_OIDC/reader_may_not_write1996=== CONT TestService_RequireScope_OIDC/ops_may_admin1997=== CONT TestService_RequireScope_OIDC/static_token_may_admin1998=== CONT TestService_RequireScope_OIDC/ops_may_not_write1999=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2000=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2001--- PASS: TestService_RequireScope_OIDC (0.27s)2002 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2003 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2004 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2005 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2006 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2007 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2008 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2009 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2010 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2011 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2012 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2013 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2014 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2015 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2016=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20172026/10/14 16:45:00 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]2018=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2019=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20202026/10/14 16:45:00 WARN Authentication failed token_preview=eyJhbGciOi...j8Vd8apTCQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2021--- PASS: TestService_AuthMiddleware_OIDC (0.32s)2022 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2023 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2024 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2025 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)20262026/10/14 16:45:00 INFO Received uploads request method=POST path=/api/pending_closures20272026/10/14 16:45:00 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/present20282026/10/14 16:45:00 INFO Received uploads request method=POST path=/api/pending_closures20292026/10/14 16:45:00 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst20302026/10/14 16:45:00 INFO Received uploads request method=POST path=/api/pending_closures2031--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.37s)20322026/10/14 16:45:00 INFO Aborted multipart uploads count=0 kept=020332026/10/14 16:45:00 WARN Force mode enabled - objects will be deleted immediately without grace period20342026/10/14 16:45:00 INFO Aborted multipart uploads count=0 kept=020352026/10/14 16:45:00 WARN Request failed, retrying attempt=2 backoff=180.708413ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20362026/10/14 16:45:00 WARN Force mode enabled - objects will be deleted immediately without grace period20372026/10/14 16:45:00 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:33333/bucket94/?delete=\": context canceled"2038--- PASS: TestGCEndsOnShutdown (0.00s)2039 --- PASS: TestGCEndsOnShutdown/before_the_run (0.33s)2040 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.34s)2041 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.34s)20422026/10/14 16:45:00 INFO lead: released remote=192.0.2.1:123420432026/10/14 16:45:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20442026/10/14 16:45:00 INFO Received uploads request method=POST path=/api/pending_closures20452026/10/14 16:45:00 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YjhlYjQyZmQtNmNhMS00MDI0LWI2MWYtYWViZGE2N2U3MTdhLmJiZjJjMDljLTNmMzUtNDY5NC04NDIwLTVjMTIxNWM5ZjM4YngxNzkxOTk2Mjk5ODIzNTQ0ODg1 error="Get \"http://127.0.0.1:1/bucket61/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"20462026/10/14 16:45:00 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YjhlYjQyZmQtNmNhMS00MDI0LWI2MWYtYWViZGE2N2U3MTdhLjk5MjgwMmUxLWZjNzgtNDE0OC1hNzAxLTJmODVlYzUxNjZkZXgxNzkxOTk2Mjk5ODA3NzUxOTM2 parts=1220472026/10/14 16:45:00 INFO Aborted multipart uploads count=0 kept=020482026/10/14 16:45:00 INFO Received cleanup request method=DELETE path=/api/pending_closures20492026/10/14 16:45:00 WARN Force mode enabled - objects will be deleted immediately without grace period20502026/10/14 16:45:00 INFO Aborted multipart uploads count=1 kept=020512026/10/14 16:45:00 INFO lead: acquired remote=192.0.2.1:12342052--- PASS: TestRedundantMultipartUpload (1.67s)20532026/10/14 16:45:00 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=020542026/10/14 16:45:00 INFO Vacuumed table table=pending_closures20552026/10/14 16:45:00 INFO Vacuumed table table=pending_objects20562026/10/14 16:45:00 INFO Vacuumed table table=multipart_uploads20572026/10/14 16:45:00 INFO Vacuumed table table=closures20582026/10/14 16:45:00 INFO Vacuumed table table=objects20592026/10/14 16:45:00 INFO Received uploads request method=POST path=/api/pending_closures20602026/10/14 16:45:00 INFO Aborted multipart uploads count=0 kept=020612026/10/14 16:45:00 WARN Force mode enabled - objects will be deleted immediately without grace period20622026/10/14 16:45:00 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=020632026/10/14 16:45:00 INFO Vacuumed table table=pending_closures20642026/10/14 16:45:00 INFO Vacuumed table table=pending_objects20652026/10/14 16:45:00 INFO Vacuumed table table=multipart_uploads20662026/10/14 16:45:00 INFO Vacuumed table table=closures20672026/10/14 16:45:00 INFO Vacuumed table table=objects2068--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2069 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.40s)2070 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.40s)20712026/10/14 16:45:00 WARN Request failed, retrying attempt=3 backoff=436.148746ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2072=== NAME TestOrphanedObjectsGCStressTest2073 orphaned_objects_gc_test.go:503: Stress test completed successfully:2074 orphaned_objects_gc_test.go:504: - Active objects preserved: 202075 orphaned_objects_gc_test.go:505: - Objects deleted: 2102076 orphaned_objects_gc_test.go:506: - Total GC'd: 2102077--- PASS: TestOrphanedObjectsGCStressTest (3.01s)2078--- PASS: TestUploadHandlersRejectOversizedBody (0.15s)2079 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)2080 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)2081 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.64s)20822026/10/14 16:45:00 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20832026/10/14 16:45:00 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20842026/10/14 16:45:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20852026/10/14 16:45:00 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YjhlYjQyZmQtNmNhMS00MDI0LWI2MWYtYWViZGE2N2U3MTdhLmI2Y2E1MTUwLTZhNTAtNDk2ZC04MTk2LWU0MGY1NTBkMGQ1ZngxNzkxOTk2MzAwMDE3MTEwMjc5 parts=1220862026/10/14 16:45:00 INFO Received uploads request method=POST path=/api/pending_closures2087--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.86s)2088--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2089 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.85s)2090 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.84s)20912026/10/14 16:45:00 WARN Request failed, retrying attempt=4 backoff=741.085919ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2092--- PASS: TestPendingClosureWriteTimeout (0.00s)2093 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2094 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2095 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2096 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.11s)20972026/10/14 16:45:01 INFO lead: released remote=192.0.2.1:12342098--- PASS: TestLeadElectsOneAndHandsOver (2.87s)20992026/10/14 16:45:01 WARN Request failed, retrying attempt=5 backoff=1.471736528s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21002026/10/14 16:45:01 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=021012026/10/14 16:45:01 INFO Received create pin request method=POST path=/api/pins/myapp21022026/10/14 16:45:01 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC696247832/001/store/2i4j3ykwmd7af978mkdh60jrx8s23ax3-pinned-file.txt narinfo_key=2i4j3ykwmd7af978mkdh60jrx8s23ax3.narinfo21032026/10/14 16:45:01 INFO Starting cleanup of old closures method=DELETE path=/api/closures21042026/10/14 16:45:01 INFO Garbage collection started21052026/10/14 16:45:01 INFO Aborted multipart uploads count=0 kept=021062026/10/14 16:45:01 WARN Force mode enabled - objects will be deleted immediately without grace period21072026/10/14 16:45:01 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=021082026/10/14 16:45:01 INFO Vacuumed table table=pending_closures21092026/10/14 16:45:01 INFO Vacuumed table table=pending_objects21102026/10/14 16:45:01 INFO Vacuumed table table=multipart_uploads21112026/10/14 16:45:01 INFO Vacuumed table table=closures21122026/10/14 16:45:01 INFO Vacuumed table table=objects21132026/10/14 16:45:01 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02114=== NAME TestClientIntegration2115 client_integration_test.go:323: Objects in database after GC:2116 client_integration_test.go:323: Successfully deleted all objects with GC --force2117--- PASS: TestClientIntegration (2.61s)2118--- PASS: TestReadProxyOutlastsServerWriteTimeout (5.25s)21192026/10/14 16:45:03 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-config21202026/10/14 16:45:03 WARN Request failed, retrying attempt=2 backoff=182.774876ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21212026/10/14 16:45:03 WARN Rate limiter enabled after throttle name=s3-test rate=521222026/10/14 16:45:03 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2123=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2124 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102125 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002126--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.63s)21272026/10/14 16:45:03 WARN Request failed, retrying attempt=3 backoff=389.750836ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2128=== NAME TestPinProtectsFromGC2129 client_integration_test.go:840: Pin successfully protected closure from garbage collection2130--- PASS: TestConnectWaitsForAPeerMigration (5.17s)2131--- PASS: TestPinProtectsFromGC (4.78s)21322026/10/14 16:45:03 WARN Request failed, retrying attempt=4 backoff=731.741361ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21332026/10/14 16:45:04 INFO Aborted multipart uploads count=1 kept=021342026/10/14 16:45:04 INFO Received cleanup request method=DELETE path=/api/pending_closures21352026/10/14 16:45:04 INFO Aborted multipart uploads count=1 kept=02136--- PASS: TestPendingCleanupUsesOneCutoff (6.74s)21372026/10/14 16:45:04 WARN Request failed, retrying attempt=5 backoff=1.737616715s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21382026/10/14 16:45:06 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/14 16:45:06 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/14 16:45:06 WARN Request failed, retrying attempt=2 backoff=197.812793ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21412026/10/14 16:45:06 WARN Request failed, retrying attempt=3 backoff=407.964018ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21422026/10/14 16:45:07 WARN Request failed, retrying attempt=4 backoff=777.874905ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21432026/10/14 16:45:07 WARN Request failed, retrying attempt=5 backoff=1.682147344s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21442026/10/14 16:45:09 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/14 16:45:09 WARN Request failed, retrying attempt=2 backoff=197.430933ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21462026/10/14 16:45:09 WARN Request failed, retrying attempt=3 backoff=401.832382ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21472026/10/14 16:45:10 WARN Request failed, retrying attempt=4 backoff=870.061544ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21482026/10/14 16:45:11 WARN Request failed, retrying attempt=5 backoff=1.676916283s 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.39s)2151 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.48s)2152 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.65s)2153PASS21542026-10-14 16:45:13.077 UTC [128] LOG: received smart shutdown request21552026-10-14 16:45:13.082 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 121562026-10-14 16:45:13.094 UTC [133] LOG: shutting down21572026-10-14 16:45:13.095 UTC [133] LOG: checkpoint starting: shutdown immediate21582026-10-14 16:45:13.662 UTC [133] LOG: checkpoint complete: wrote 11166 buffers (68.2%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.235 s, sync=0.284 s, total=0.568 s; sync files=34045, longest=0.056 s, average=0.001 s; distance=531524 kB, estimate=531524 kB; lsn=0/21E770C0, redo lsn=0/21E770C021592026-10-14 16:45:13.742 UTC [128] 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--- PASS: TestAudienceForIssuer (0.00s)2200=== CONT TestValidateToken_NoMatchingProvider2201=== CONT TestValidateToken_MultipleProviders2202=== CONT TestValidateToken_BoundSubjectMismatch2203=== CONT TestValidateToken_BoundClaimsMismatch2204=== CONT TestValidateToken_Expired2205=== CONT TestValidateToken_WrongAudience2206=== CONT TestValidateToken_ValidToken2207=== CONT TestGlobMatch2208=== RUN TestGlobMatch/foo_foo2209=== PAUSE TestGlobMatch/foo_foo2210=== CONT TestPins_ReservedForMatchingRule2211=== CONT TestPins_TopLevelShorthand2212=== CONT TestScopes_LegacyProviderDefaultsToWrite2213=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2214=== CONT TestNewValidator_KubernetesRequiresCA2215=== CONT TestPins_ConfigValidation2216=== CONT TestScopes_ConfigValidation2217=== CONT TestScopes_Rules2218=== RUN TestGlobMatch/foo_bar2219=== PAUSE TestGlobMatch/foo_bar2220=== RUN TestGlobMatch/*_2221=== PAUSE TestGlobMatch/*_2222=== RUN TestGlobMatch/*_anything2223=== PAUSE TestGlobMatch/*_anything2224=== RUN TestGlobMatch/foo*_foo2225=== PAUSE TestGlobMatch/foo*_foo2226=== RUN TestGlobMatch/foo*_foobar2227=== PAUSE TestGlobMatch/foo*_foobar2228=== RUN TestGlobMatch/foo*_bar2229=== PAUSE TestGlobMatch/foo*_bar2230=== RUN TestGlobMatch/*bar_bar2231=== PAUSE TestGlobMatch/*bar_bar2232=== RUN TestGlobMatch/*bar_foobar2233=== PAUSE TestGlobMatch/*bar_foobar2234=== RUN TestGlobMatch/*bar_foo2235=== PAUSE TestGlobMatch/*bar_foo2236=== RUN TestGlobMatch/foo*bar_foobar2237=== PAUSE TestGlobMatch/foo*bar_foobar2238=== RUN TestGlobMatch/foo*bar_foo123bar2239=== PAUSE TestGlobMatch/foo*bar_foo123bar2240=== RUN TestGlobMatch/foo*bar_foobarbaz2241=== PAUSE TestGlobMatch/foo*bar_foobarbaz2242=== RUN TestGlobMatch/*/*_foo/bar2243=== PAUSE TestGlobMatch/*/*_foo/bar2244=== RUN TestGlobMatch/*/*_foo2245=== PAUSE TestGlobMatch/*/*_foo2246=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2247=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2248=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02249=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02250=== RUN TestGlobMatch/refs/*/main_refs/heads/main2251=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2252=== RUN TestGlobMatch/fo?_foo2253=== PAUSE TestGlobMatch/fo?_foo2254=== RUN TestGlobMatch/fo?_fo2255=== PAUSE TestGlobMatch/fo?_fo2256--- PASS: TestPins_ConfigValidation (0.00s)2257=== RUN TestGlobMatch/fo?_fooo2258=== PAUSE TestGlobMatch/fo?_fooo2259--- PASS: TestScopes_ConfigValidation (0.00s)2260=== RUN TestGlobMatch/?oo_foo2261=== PAUSE TestGlobMatch/?oo_foo2262=== RUN TestGlobMatch/?oo_boo2263=== PAUSE TestGlobMatch/?oo_boo2264=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2265=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2266=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2267=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2268=== CONT TestGlobMatch/foo_foo2269=== CONT TestGlobMatch/*/*_foo/bar2270=== CONT TestGlobMatch/foo*bar_foobarbaz2271=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02272=== CONT TestGlobMatch/foo*bar_foo123bar2273=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2274=== CONT TestGlobMatch/*/*_foo2275=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2276=== CONT TestGlobMatch/foo*_foo2277=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2278=== CONT TestGlobMatch/foo*_bar2279=== CONT TestGlobMatch/foo*_foobar2280=== CONT TestGlobMatch/?oo_boo2281=== CONT TestGlobMatch/*bar_foobar2282=== CONT TestGlobMatch/*_anything2283=== CONT TestGlobMatch/*_2284=== CONT TestGlobMatch/fo?_fooo2285=== CONT TestGlobMatch/fo?_fo2286=== CONT TestGlobMatch/*bar_bar2287=== CONT TestGlobMatch/fo?_foo2288=== CONT TestGlobMatch/refs/*/main_refs/heads/main2289=== CONT TestGlobMatch/foo*bar_foobar2290=== CONT TestGlobMatch/*bar_foo2291=== CONT TestGlobMatch/foo_bar2292=== CONT TestGlobMatch/?oo_foo2293--- PASS: TestGlobMatch (0.01s)2294 --- PASS: TestGlobMatch/foo_foo (0.00s)2295 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2296 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2297 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2298 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2299 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2300 --- PASS: TestGlobMatch/*/*_foo (0.00s)2301 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2302 --- PASS: TestGlobMatch/foo*_foo (0.00s)2303 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2304 --- PASS: TestGlobMatch/foo*_bar (0.00s)2305 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2306 --- PASS: TestGlobMatch/?oo_boo (0.00s)2307 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2308 --- PASS: TestGlobMatch/*_anything (0.00s)2309 --- PASS: TestGlobMatch/*_ (0.00s)2310 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2311 --- PASS: TestGlobMatch/fo?_fo (0.00s)2312 --- PASS: TestGlobMatch/*bar_bar (0.00s)2313 --- PASS: TestGlobMatch/fo?_foo (0.00s)2314 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2315 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2316 --- PASS: TestGlobMatch/*bar_foo (0.00s)2317 --- PASS: TestGlobMatch/foo_bar (0.00s)2318 --- PASS: TestGlobMatch/?oo_foo (0.00s)23192026/10/14 16:45:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46725/oidc2320--- PASS: TestPins_ReservedForMatchingRule (0.04s)23212026/10/14 16:45:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42327/oidc2322--- PASS: TestValidateToken_WrongAudience (0.04s)23232026/10/14 16:45:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34773/oidc2324--- PASS: TestValidateToken_BoundClaimsMismatch (0.06s)23252026/10/14 16:45:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37525/oidc2326--- PASS: TestScopes_Rules (0.07s)23272026/10/14 16:45:15 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:45235/oidc23282026/10/14 16:45:15 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:45939/oidc23292026/10/14 16:45:15 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232330--- PASS: TestValidateToken_MultipleProviders (0.08s)23312026/10/14 16:45:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40573/oidc2332--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.08s)2333--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.08s)23342026/10/14 16:45:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44929/oidc2335--- PASS: TestValidateToken_BoundSubjectMismatch (0.09s)23362026/10/14 16:45:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45849/oidc2337--- PASS: TestPins_TopLevelShorthand (0.09s)23382026/10/14 16:45:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33905/oidc2339--- PASS: TestValidateToken_ValidToken (0.11s)23402026/10/14 16:45:16 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:378012341--- PASS: TestValidateToken_KubernetesServiceAccount (0.13s)23422026/10/14 16:45:16 http: TLS handshake error from 127.0.0.1:40344: remote error: tls: bad certificate2343--- PASS: TestNewValidator_KubernetesRequiresCA (0.15s)23442026/10/14 16:45:16 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:41531/oidc2345--- PASS: TestValidateToken_NoMatchingProvider (0.16s)23462026/10/14 16:45:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41885/oidc2347--- PASS: TestValidateToken_Expired (0.20s)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/14 16:45:16 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 TestWorkerSkipsGCdPaths2397--- PASS: TestSendPathsEmpty (0.00s)2398=== CONT TestDrainTimeout2399=== CONT TestWorkerPrunesClosureDeps2400=== CONT TestDrainIsolatesPoisonPath2401=== CONT TestQueueRemoveLargeClosure2402=== CONT TestQueueConcurrentWriters2403=== CONT TestQueueFetchRemoveLifecycle2404=== CONT TestQueueRetryMovesToBack2405=== CONT TestQueueFetchBatchLimit2406=== CONT TestQueueRemove2407=== CONT TestFailedPathPrunedByLaterClosure2408=== CONT TestQueueDeduplication2409=== CONT TestWorkerUploadsAndRemoves2410=== CONT TestQueueEnqueueAndFetch2411=== CONT TestRunNotBlockedByPoisonHead2412=== CONT TestDrainGivesUpWhenServerDown24132026/10/14 16:45:16 INFO Uploading batch count=424142026/10/14 16:45:16 ERROR Upload failed error="upload failed" count=42415--- PASS: TestQueueEnqueueAndFetch (0.01s)24162026/10/14 16:45:16 INFO Uploading batch count=124172026/10/14 16:45:16 ERROR Upload failed error="upload failed" count=124182026/10/14 16:45:16 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3245646703/002/bbb24192026/10/14 16:45:16 INFO Uploading batch count=224202026/10/14 16:45:16 INFO Upload queue status pending=224212026/10/14 16:45:16 INFO Uploading batch count=224222026/10/14 16:45:16 INFO Uploading batch count=224232026/10/14 16:45:16 ERROR Upload failed error="upload failed" count=224242026/10/14 16:45:16 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4290213011/002/a2425--- PASS: TestQueueFetchBatchLimit (0.02s)24262026/10/14 16:45:16 INFO Upload queue status pending=324272026/10/14 16:45:16 INFO Upload queue status pending=224282026/10/14 16:45:16 INFO Uploading batch count=124292026/10/14 16:45:16 ERROR Upload failed error="upload failed" count=12430--- PASS: TestQueueFetchRemoveLifecycle (0.02s)24312026/10/14 16:45:16 INFO Upload queue status pending=224322026/10/14 16:45:16 INFO Uploading batch count=124332026/10/14 16:45:16 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2833118452/002/nonexistent24342026/10/14 16:45:16 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4290213011/002/b24352026/10/14 16:45:16 INFO Uploading batch count=12436--- PASS: TestQueueRemove (0.02s)24372026/10/14 16:45:16 ERROR Upload failed error="upload failed" count=124382026/10/14 16:45:16 INFO Uploading batch count=124392026/10/14 16:45:16 INFO Uploading batch count=22440--- PASS: TestQueueDeduplication (0.02s)24412026/10/14 16:45:16 ERROR Upload failed error="upload failed" count=224422026/10/14 16:45:16 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4290213011/002/c2443--- PASS: TestQueueRetryMovesToBack (0.02s)24442026/10/14 16:45:16 INFO Uploading batch count=124452026/10/14 16:45:16 INFO Uploading batch count=124462026/10/14 16:45:16 ERROR Upload failed error="upload failed" count=124472026/10/14 16:45:16 INFO Uploading batch count=124482026/10/14 16:45:16 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4290213011/002/d24492026/10/14 16:45:16 INFO Uploading batch count=124502026/10/14 16:45:16 ERROR Upload failed error="upload failed" count=124512026/10/14 16:45:16 INFO Uploading batch count=224522026/10/14 16:45:16 ERROR Upload failed error="upload failed" count=224532026/10/14 16:45:16 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4290213011/002/e24542026/10/14 16:45:16 ERROR Drain finished with paths left in queue remaining=124552026/10/14 16:45:16 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4290213011/002/f24562026/10/14 16:45:16 ERROR Drain finished with paths left in queue remaining=102457--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)2458--- PASS: TestDrainIsolatesPoisonPath (0.02s)2459--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2460--- PASS: TestWorkerUploadsAndRemoves (0.04s)2461--- PASS: TestWorkerPrunesClosureDeps (0.04s)2462--- PASS: TestWorkerSkipsGCdPaths (0.04s)2463--- PASS: TestQueueRemoveLargeClosure (0.06s)24642026/10/14 16:45:16 ERROR Upload failed error="context deadline exceeded" count=224652026/10/14 16:45:16 ERROR Drain finished with paths left in queue remaining=42466--- PASS: TestDrainTimeout (0.22s)2467--- PASS: TestQueueConcurrentWriters (0.28s)24682026/10/14 16:45:17 INFO Uploading batch count=124692026/10/14 16:45:17 INFO Uploading batch count=124702026/10/14 16:45:17 INFO Uploading batch count=124712026/10/14 16:45:17 ERROR Upload failed error="upload failed" count=124722026/10/14 16:45:17 INFO Uploading batch count=124732026/10/14 16:45:17 ERROR Upload failed error="upload failed" count=124742026/10/14 16:45:17 INFO Uploading batch count=124752026/10/14 16:45:17 ERROR Upload failed error="upload failed" count=124762026/10/14 16:45:17 INFO Uploading batch count=124772026/10/14 16:45:17 ERROR Upload failed error="upload failed" count=124782026/10/14 16:45:17 ERROR Drain finished with paths left in queue remaining=12479--- PASS: TestRunNotBlockedByPoisonHead (1.04s)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 TestExternalSignerCancellation2512=== CONT TestExternalSignerProgramErrorKeepsProcess2513=== CONT TestExternalSignerRejectsInvalidPublicKey2514=== CONT TestExternalSignerClose2515=== CONT TestParseSigningKey2516=== RUN TestParseSigningKey/valid_32-byte_key2517=== PAUSE TestParseSigningKey/valid_32-byte_key2518=== CONT TestSign2519=== CONT TestSignErrors2520=== CONT TestGenerateFingerprint2521=== RUN TestGenerateFingerprint/basic_with_references2522=== PAUSE TestGenerateFingerprint/basic_with_references2523=== CONT TestExternalSignerErrors2524=== RUN TestExternalSignerErrors/exit_at_startup2525=== CONT TestExternalSignerRestartsAfterCrash2526=== CONT TestNilKeyPublicKey2527=== CONT TestExternalSignerWrongPublicKey2528=== CONT TestSignBatch2529=== RUN TestExternalSignerRejectsInvalidPublicKey/#002530=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2531=== RUN TestGenerateFingerprint/no_references2532=== PAUSE TestGenerateFingerprint/no_references2533--- PASS: TestNilKeyPublicKey (0.00s)2534=== PAUSE TestExternalSignerErrors/exit_at_startup2535=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2536=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2537=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2538=== RUN TestExternalSignerErrors/null2539=== PAUSE TestExternalSignerErrors/null2540=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002541=== RUN TestParseSigningKey/no_colon2542--- PASS: TestSign (0.00s)2543=== RUN TestSignErrors/nil_key2544=== PAUSE TestSignErrors/nil_key2545=== RUN TestSignErrors/nil_narinfo2546=== PAUSE TestSignErrors/nil_narinfo2547=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2548=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2549=== RUN TestGenerateFingerprint/invalid_nar_hash_length2550=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2551=== RUN TestGenerateFingerprint/invalid_store_path_prefix2552=== RUN TestExternalSignerErrors/wrong_id2553=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2554=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2555=== PAUSE TestParseSigningKey/no_colon2556--- PASS: TestSignBatch (0.00s)2557--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2558=== RUN TestSignErrors/invalid_narinfo2559=== PAUSE TestSignErrors/invalid_narinfo2560=== RUN TestSignErrors/canceled2561=== PAUSE TestSignErrors/canceled2562=== CONT TestSignErrors/nil_key2563=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2564=== RUN TestGenerateFingerprint/invalid_reference_prefix2565=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2566=== CONT TestGenerateFingerprint/basic_with_references2567=== CONT TestGenerateFingerprint/invalid_nar_hash_length2568=== PAUSE TestExternalSignerErrors/wrong_id2569=== RUN TestExternalSignerErrors/missing_signatures2570=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2571--- PASS: TestExternalSignerClose (0.00s)2572=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2573=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2574=== RUN TestParseSigningKey/empty_name2575=== PAUSE TestParseSigningKey/empty_name2576=== RUN TestParseSigningKey/invalid_base642577=== PAUSE TestParseSigningKey/invalid_base642578=== CONT TestSignErrors/nil_narinfo2579=== CONT TestSignErrors/invalid_narinfo2580=== CONT TestSignErrors/canceled2581=== CONT TestGenerateFingerprint/invalid_reference_prefix2582=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2583=== CONT TestGenerateFingerprint/no_references2584=== CONT TestGenerateFingerprint/invalid_store_path_prefix2585=== PAUSE TestExternalSignerErrors/missing_signatures2586=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2587=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2588=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2589=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2590=== CONT TestExternalSignerRejectsInvalidPublicKey/#002591=== RUN TestParseSigningKey/wrong_length2592=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2593=== PAUSE TestParseSigningKey/wrong_length2594=== CONT TestParseSigningKey/valid_32-byte_key2595=== RUN TestExternalSignerErrors/unrequested_key2596=== PAUSE TestExternalSignerErrors/unrequested_key2597=== RUN TestExternalSignerErrors/invalid_JSON2598=== PAUSE TestExternalSignerErrors/invalid_JSON2599=== RUN TestExternalSignerErrors/null_signatures2600=== PAUSE TestExternalSignerErrors/null_signatures2601=== RUN TestExternalSignerErrors/wrong_signatures_shape2602=== CONT TestParseSigningKey/invalid_base642603=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2604--- PASS: TestSignErrors (0.00s)2605 --- PASS: TestSignErrors/nil_key (0.00s)2606 --- PASS: TestSignErrors/nil_narinfo (0.00s)2607 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2608 --- PASS: TestSignErrors/canceled (0.00s)2609=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2610--- PASS: TestGenerateFingerprint (0.00s)2611 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2612 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2613 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2614 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2615 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2616 --- PASS: TestGenerateFingerprint/no_references (0.00s)2617 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2618=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2619=== CONT TestParseSigningKey/no_colon2620--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.01s)2621 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2622 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2623 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2624 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2625 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2626=== CONT TestParseSigningKey/empty_name2627=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2628=== CONT TestParseSigningKey/wrong_length2629=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2630=== RUN TestExternalSignerErrors/wrong_signature_length2631=== PAUSE TestExternalSignerErrors/wrong_signature_length2632=== RUN TestExternalSignerErrors/exit_on_request2633=== PAUSE TestExternalSignerErrors/exit_on_request2634=== RUN TestExternalSignerErrors/wrong_shape2635=== PAUSE TestExternalSignerErrors/wrong_shape2636--- PASS: TestExternalSignerWrongPublicKey (0.00s)2637=== RUN TestExternalSignerErrors/too_few_signatures2638--- PASS: TestParseSigningKey (0.01s)2639 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2640 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2641 --- PASS: TestParseSigningKey/no_colon (0.00s)2642 --- PASS: TestParseSigningKey/empty_name (0.00s)2643 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2644 --- PASS: TestParseSigningKey/wrong_length (0.00s)2645=== PAUSE TestExternalSignerErrors/too_few_signatures2646=== RUN TestExternalSignerErrors/missing_signature_name2647=== PAUSE TestExternalSignerErrors/missing_signature_name2648=== RUN TestExternalSignerErrors/invalid_signature_base642649=== PAUSE TestExternalSignerErrors/invalid_signature_base642650=== RUN TestExternalSignerErrors/program_error2651=== PAUSE TestExternalSignerErrors/program_error2652=== RUN TestExternalSignerErrors/wrong_signature_name2653=== PAUSE TestExternalSignerErrors/wrong_signature_name2654=== CONT TestExternalSignerErrors/exit_at_startup2655=== CONT TestExternalSignerErrors/missing_signature_name2656=== CONT TestExternalSignerErrors/unrequested_key2657=== CONT TestExternalSignerErrors/wrong_signature_name2658=== CONT TestExternalSignerErrors/program_error2659=== CONT TestExternalSignerErrors/invalid_signature_base642660=== CONT TestExternalSignerErrors/wrong_signatures_shape2661=== CONT TestExternalSignerErrors/null_signatures2662=== CONT TestExternalSignerErrors/invalid_JSON2663=== CONT TestExternalSignerErrors/wrong_id2664=== CONT TestExternalSignerErrors/missing_signatures2665=== CONT TestExternalSignerErrors/wrong_shape2666=== CONT TestExternalSignerErrors/too_few_signatures2667=== CONT TestExternalSignerErrors/exit_on_request2668=== CONT TestExternalSignerErrors/null2669=== CONT TestExternalSignerErrors/wrong_signature_length2670--- PASS: TestExternalSigner (0.01s)2671--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2672--- PASS: TestExternalSignerErrors (0.00s)2673 --- PASS: TestExternalSignerErrors/unrequested_key (0.00s)2674 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2675 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.00s)2676 --- PASS: TestExternalSignerErrors/program_error (0.00s)2677 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.00s)2678 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.00s)2679 --- PASS: TestExternalSignerErrors/null_signatures (0.00s)2680 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2681 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2682 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2683 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2684 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.00s)2685 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2686 --- PASS: TestExternalSignerErrors/null (0.00s)2687 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2688 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)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 TestSignErrors2702=== RUN TestSignErrors/http_error2703=== PAUSE TestSignErrors/http_error2704=== CONT TestServeRejectsGarbage2705=== CONT TestServe2706=== RUN TestSignErrors/invalid_json2707=== PAUSE TestSignErrors/invalid_json2708=== RUN TestSignErrors/no_prefix2709=== PAUSE TestSignErrors/no_prefix2710=== RUN TestSignErrors/invalid_base642711=== PAUSE TestSignErrors/invalid_base642712=== CONT TestSignErrors/http_error2713=== CONT TestSignErrors/no_prefix2714=== CONT TestSignErrors/invalid_base642715--- PASS: TestServeRejectsGarbage (0.00s)2716--- PASS: TestServe (0.00s)2717=== CONT TestSignErrors/invalid_json2718--- PASS: TestSign (0.01s)2719--- PASS: TestSignErrors (0.00s)2720 --- PASS: TestSignErrors/no_prefix (0.00s)2721 --- PASS: TestSignErrors/invalid_json (0.00s)2722 --- PASS: TestSignErrors/invalid_base64 (0.00s)2723 --- PASS: TestSignErrors/http_error (0.00s)2724PASS