niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #411
· 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.04s)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 TestEncodeNixBase32115=== CONT TestRetryTimeoutOutlastsMaxRetries116=== CONT TestStreamPushStopsWhenCanceled117--- PASS: TestStreamPushStopsWhenCanceled (0.00s)118=== CONT TestDumpPathWriterError119=== CONT TestClientSignaturesByStorePath120--- PASS: TestClientSignaturesByStorePath (0.00s)121=== CONT TestScriptTokenNoExpiryRerunsEveryCall122=== CONT TestStreamPushReportsSkippedPaths123=== CONT TestStreamPushReportsSignatures124=== CONT TestStreamPushRequestLine125=== CONT TestStreamPushGivesUpOnDeadServer126=== CONT TestSetClientTLS127=== CONT TestStreamPushIsolatesFailures128=== CONT TestScriptTokenEmptyCommand129--- PASS: TestScriptTokenEmptyCommand (0.00s)130=== CONT TestDumpPathSingleFile131=== CONT TestStreamPushBatchesUnderLoad132=== CONT TestScriptTokenScriptFails133=== CONT TestStreamPushReportsEveryPath134=== CONT TestScriptTokenBadJSON135=== CONT TestShellSplitErrors136=== CONT TestShellSplit1372026/10/11 05:55:06 ERROR Upload failed error="bad path" count=3138=== CONT TestDoWithRetry_FinalResponseBodyReadable1392026/10/11 05:55:06 ERROR Upload failed error="connection refused" count=20140=== CONT TestUploadMultipart_PartsInParallel141=== CONT TestScriptTokenEmptyToken142=== CONT TestRegisterUploadedObjectReusesConnections1432026/10/11 05:55:06 ERROR Server seems unavailable, giving up on batch untried=17144=== CONT TestScriptTokenCachesUntilRefresh145=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica146=== RUN TestEncodeNixBase32/test_string_hash147--- PASS: TestShellSplitErrors (0.00s)148--- PASS: TestStreamPushReportsSkippedPaths (0.00s)149=== CONT TestFileTokenEmpty150=== CONT TestDumpPathMatchesNix151--- PASS: TestStreamPushReportsEveryPath (0.00s)152=== CONT TestFileTokenMissing1532026/10/11 05:55:06 ERROR Upload failed error=boom count=1154--- PASS: TestShellSplit (0.00s)155=== CONT TestSupersededNARStillUploadsListing1562026/10/11 05:55:06 ERROR Upload failed error=boom count=1157=== RUN TestSupersededNARStillUploadsListing/small_NAR158--- PASS: TestScriptTokenScriptFails (0.00s)159=== CONT TestFileTokenReadsAndCaches160=== CONT TestStaticToken161--- PASS: TestStreamPushReportsSignatures (0.00s)162--- PASS: TestStaticToken (0.00s)163--- PASS: TestFileTokenEmpty (0.00s)164=== CONT TestSetClientTLSErrors165--- PASS: TestFileTokenReadsAndCaches (0.00s)166=== CONT TestUploadMultipart_SupersededByPeer167=== RUN TestUploadMultipart_SupersededByPeer/exists168=== CONT TestPartSizeForNAR169--- PASS: TestStreamPushIsolatesFailures (0.01s)170=== CONT TestSetClientTLSDoesNotMutateDefaultTransport171--- PASS: TestScriptTokenBadJSON (0.00s)172=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry173=== RUN TestSetClientTLSErrors/missing_cert_file174--- PASS: TestStreamPushGivesUpOnDeadServer (0.03s)175=== CONT TestFilterOversizedClosures176=== RUN TestFilterOversizedClosures/no_limit_keeps_everything177=== PAUSE TestEncodeNixBase32/test_string_hash178=== RUN TestEncodeNixBase32/empty_input179=== PAUSE TestEncodeNixBase32/empty_input1802026/10/11 05:55:06 WARN Rate limiter enabled after throttle name=server-test rate=5181=== PAUSE TestSupersededNARStillUploadsListing/small_NAR1822026/10/11 05:55:06 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:43153183=== CONT TestDoWithRetry_BodyReplayedViaGetBody1842026/10/11 05:55:06 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:458331852026/10/11 05:55:06 INFO Garbage collection started186=== RUN TestSupersededNARStillUploadsListing/dump_cut_short187=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short188=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails189=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails190=== CONT TestPathInfoCACompatibility191=== RUN TestPathInfoCACompatibility/null_ca_field192=== PAUSE TestPathInfoCACompatibility/null_ca_field193=== RUN TestPathInfoCACompatibility/old_string_format_-_text194=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text195=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive196=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive197=== RUN TestPathInfoCACompatibility/new_structured_format_-_text198=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text199=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method200=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method201=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer202--- PASS: TestFileTokenMissing (0.03s)203--- PASS: TestDoServerRequestAttachesToken (0.04s)204=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess205--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.03s)206=== CONT TestRateLimiterFeedback2072026/10/11 05:55:06 WARN Rate limiter backed off name=server-test rate=5208=== RUN TestRateLimiterFeedback/429_enables_limiter209=== PAUSE TestRateLimiterFeedback/429_enables_limiter210=== RUN TestRateLimiterFeedback/503_enables_limiter211=== PAUSE TestRateLimiterFeedback/503_enables_limiter212=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter213=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter214=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter215=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter216=== CONT TestResolveStorePath217--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.03s)218=== CONT TestPathInfoHashCompatibility219=== CONT TestCaseHackSuffix2202026/10/11 05:55:06 WARN Rate limiter enabled after throttle name=server-test rate=52212026/10/11 05:55:06 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=0222=== RUN TestPartSizeForNAR/zero_stays_at_minimum223=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum2242026/10/11 05:55:06 WARN Rate limiter enabled after throttle name=server-test rate=5225=== RUN TestPartSizeForNAR/small_stays_at_minimum2262026/10/11 05:55:06 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:44273227=== PAUSE TestPartSizeForNAR/small_stays_at_minimum228=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum229=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum230=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts231=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts232=== PAUSE TestSetClientTLSErrors/missing_cert_file233=== PAUSE TestUploadMultipart_SupersededByPeer/exists234=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)235=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)236=== RUN TestUploadMultipart_SupersededByPeer/missing2372026/10/11 05:55:06 WARN Rate limiter backed off name=server-test rate=5238=== PAUSE TestUploadMultipart_SupersededByPeer/missing2392026/10/11 05:55:06 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:44273240=== RUN TestSetClientTLSErrors/missing_key_file241=== PAUSE TestSetClientTLSErrors/missing_key_file242=== RUN TestSetClientTLSErrors/missing_ca_file243=== PAUSE TestSetClientTLSErrors/missing_ca_file244=== RUN TestSetClientTLSErrors/invalid_ca_file245=== PAUSE TestSetClientTLSErrors/invalid_ca_file246=== CONT TestConvertHashToNix32247=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything248=== RUN TestSetClientTLS/rejects_connection_without_client_cert249=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert250=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA251=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA252=== RUN TestSetClientTLS/preserves_debug_logging_transport253=== PAUSE TestSetClientTLS/preserves_debug_logging_transport254=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2552026/10/11 05:55:06 WARN Garbage collection finished on another replica. Its statistics are not available here256=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped257=== RUN TestFilterOversizedClosures/all_closures_skipped258=== PAUSE TestFilterOversizedClosures/all_closures_skipped259=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun260=== CONT TestEncodeNixBase32/empty_input261=== CONT TestSupersededNARStillUploadsListing/small_NAR262=== CONT TestGetStorePathHash263=== RUN TestGetStorePathHash/valid_store_path264=== PAUSE TestGetStorePathHash/valid_store_path265=== RUN TestGetStorePathHash/basename_without_hyphen_should_error266=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error267=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error268=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error2692026/10/11 05:55:06 WARN Rate limiter enabled after throttle name=s3-test rate=5270=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error2712026/10/11 05:55:06 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:46125272=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error273--- PASS: TestResolveStorePath (0.00s)274=== RUN TestConvertHashToNix32/SRI_format_to_Nix32275=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32276=== RUN TestConvertHashToNix32/already_Nix32_format277=== PAUSE TestConvertHashToNix32/already_Nix32_format278=== RUN TestConvertHashToNix32/invalid_format279=== PAUSE TestConvertHashToNix32/invalid_format280=== CONT TestParsePathInfoJSONMultiplePaths281=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths2822026/10/11 05:55:06 INFO Garbage collection started283=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths284=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths285=== CONT TestParsePathInfoJSON286=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon287=== CONT TestEncodeNixBase32WithRealHash288=== CONT TestSupersededNARStillUploadsListing/dump_cut_short289=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon290=== RUN TestPartSizeForNAR/1_TiB2912026/10/11 05:55:06 INFO Uploading abc-hello (1.0GB)292=== RUN TestParsePathInfoJSON/Nix_format293=== PAUSE TestParsePathInfoJSON/Nix_format294=== CONT TestPathInfoCACompatibility/null_ca_field295=== CONT TestPathInfoCACompatibility/old_string_format_-_text296=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method297=== PAUSE TestPartSizeForNAR/1_TiB298=== CONT TestPathInfoCACompatibility/new_structured_format_-_text299=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive300=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter301=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths302=== CONT TestRateLimiterFeedback/429_enables_limiter303=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter304=== RUN TestPartSizeForNAR/5_TiB_S3_max_object305=== CONT TestEncodeNixBase32/test_string_hash306--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)307=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails308=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI309=== RUN TestParsePathInfoJSON/Lix_format310--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.03s)311--- PASS: TestScriptTokenEmptyToken (0.03s)312--- PASS: TestEncodeNixBase32WithRealHash (0.00s)313--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.01s)314--- PASS: TestPathInfoCACompatibility (0.00s)315 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)316 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)317 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)318 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)319 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)320--- PASS: TestEncodeNixBase32 (0.04s)321 --- PASS: TestEncodeNixBase32/empty_input (0.00s)322 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)3232026/10/11 05:55:06 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:45833324=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI325=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512326=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha5123272026/10/11 05:55:06 INFO Uploading abc-hello (1.0GB)328=== PAUSE TestParsePathInfoJSON/Lix_format329=== CONT TestUploadMultipart_SupersededByPeer/missing3302026/10/11 05:55:06 WARN Rate limiter enabled after throttle name=server-test rate=5331=== CONT TestSetClientTLSErrors/invalid_ca_file3322026/10/11 05:55:06 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:37075333=== CONT TestSetClientTLSErrors/missing_key_file3342026/10/11 05:55:06 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:45833335=== CONT TestFilterOversizedClosures/no_limit_keeps_everything3362026/10/11 05:55:06 WARN Rate limiter backed off name=server-test rate=5337=== RUN TestParsePathInfoJSON/empty_input338=== CONT TestSetClientTLS/rejects_connection_without_client_cert339=== CONT TestUploadMultipart_SupersededByPeer/exists340=== CONT TestRateLimiterFeedback/503_enables_limiter3412026/10/11 05:55:06 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:45833342=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3432026/10/11 05:55:06 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=2000344=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object345=== RUN TestPartSizeForNAR/capped_at_5_GiB346=== PAUSE TestPartSizeForNAR/capped_at_5_GiB347=== CONT TestConvertHashToNix32/SRI_format_to_Nix32348=== CONT TestGetStorePathHash/basename_without_hyphen_should_error3492026/10/11 05:55:06 WARN Rate limiter enabled after throttle name=server-test rate=5350=== CONT TestConvertHashToNix32/invalid_format3512026/10/11 05:55:06 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:42817352=== CONT TestConvertHashToNix32/already_Nix32_format3532026/10/11 05:55:06 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:45833354=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error355=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths3562026/10/11 05:55:06 WARN Rate limiter backed off name=server-test rate=5357=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)358=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512359=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI360=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon361=== CONT TestPartSizeForNAR/zero_stays_at_minimum362=== CONT TestPartSizeForNAR/1_TiB363=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts364=== CONT TestPartSizeForNAR/small_stays_at_minimum365=== CONT TestPartSizeForNAR/5_TiB_S3_max_object366=== CONT TestPartSizeForNAR/capped_at_5_GiB367=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum368=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths3692026/10/11 05:55:06 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:45833370=== CONT TestSetClientTLSErrors/missing_ca_file371=== CONT TestSetClientTLS/preserves_debug_logging_transport372=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA373=== CONT TestFilterOversizedClosures/all_closures_skipped3742026/10/11 05:55:06 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=50375=== PAUSE TestParsePathInfoJSON/empty_input376=== RUN TestParsePathInfoJSON/whitespace_only377=== PAUSE TestParsePathInfoJSON/whitespace_only378=== RUN TestParsePathInfoJSON/invalid_JSON379=== PAUSE TestParsePathInfoJSON/invalid_JSON380=== CONT TestParsePathInfoJSON/Nix_format3812026/10/11 05:55:06 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:45833382=== CONT TestGetStorePathHash/valid_store_path383=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error384=== CONT TestSetClientTLSErrors/missing_cert_file385--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.14s)386--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.18s)387--- PASS: TestScriptTokenCachesUntilRefresh (0.18s)388=== CONT TestParsePathInfoJSON/Lix_format389=== CONT TestParsePathInfoJSON/whitespace_only390=== CONT TestParsePathInfoJSON/invalid_JSON391=== CONT TestParsePathInfoJSON/empty_input392--- PASS: TestDumpPathSingleFile (0.18s)393--- PASS: TestUploadMultipart_SupersededByPeer (0.03s)394 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)395 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)396--- PASS: TestCaseHackSuffix (0.15s)397--- PASS: TestConvertHashToNix32 (0.00s)398 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)399 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)400 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)401--- PASS: TestPathInfoHashCompatibility (0.15s)402 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)403 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)404 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)405 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)406--- PASS: TestRateLimiterFeedback (0.00s)407 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.14s)408 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.14s)409 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.14s)410 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)411--- PASS: TestPartSizeForNAR (0.15s)412 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)413 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)414 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)415 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)416 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)417 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)418 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)419--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)420 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)421 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)422--- PASS: TestGetStorePathHash (0.00s)423 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)424 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)425 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)426 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)4272026/10/11 05:55:06 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:45833428--- PASS: TestFilterOversizedClosures (0.00s)429 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)430 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)431 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)4322026/10/11 05:55:06 http: TLS handshake error from 127.0.0.1:53922: remote error: tls: bad certificate433--- PASS: TestParsePathInfoJSON (0.15s)434 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)435 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)436 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)437 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)438 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)439--- PASS: TestSetClientTLSErrors (0.03s)440 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)441 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)442 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)443 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)4442026/10/11 05:55:06 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:45833445--- PASS: TestSetClientTLS (0.04s)446 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)447 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)448 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)4492026/10/11 05:55:06 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:458334502026/10/11 05:55:06 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:458334512026/10/11 05:55:06 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:45833452--- PASS: TestStreamPushRequestLine (0.20s)4532026/10/11 05:55:06 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:458334542026/10/11 05:55:06 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:458334552026/10/11 05:55:06 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:458334562026/10/11 05:55:06 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:45833457--- PASS: TestRegisterUploadedObjectReusesConnections (0.20s)4582026/10/11 05:55:06 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:458334592026/10/11 05:55:06 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:458334602026/10/11 05:55:06 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:45833461--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.21s)462--- PASS: TestDumpPathWriterError (0.21s)4632026/10/11 05:55:06 INFO Uploading abc-hello (1.0GB)464--- PASS: TestStreamPushBatchesUnderLoad (0.23s)465--- PASS: TestDumpPathMatchesNix (0.26s)4662026/10/11 05:55:06 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:46435/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:46435/part/24672026/10/11 05:55:06 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"468--- PASS: TestSupersededNARStillUploadsListing (0.03s)469 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.15s)470 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.01s)471 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.73s)472--- PASS: TestUploadMultipart_PartsInParallel (0.80s)4732026/10/11 05:55:07 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:35527/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:35527/api/uploads/complete4742026/10/11 05:55:07 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4752026/10/11 05:55:07 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:35527/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:35527/api/uploads/complete4762026/10/11 05:55:07 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4772026/10/11 05:55:07 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:35527/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:35527/api/uploads/complete478--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)4792026/10/11 05:55:07 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"480--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)481PASS482Running server tests...483The files belonging to this database system will be owned by user "nixbld".484This user must also own the server process.485486The database cluster will be initialized with locale "C".487The default database encoding has accordingly been set to "SQL_ASCII".488The default text search configuration will be set to "english".489490Data page checksums are enabled.491492creating directory /build/postgres92876979/data ... ok493creating subdirectories ... ok494selecting dynamic shared memory implementation ... posix495selecting default "max_connections" ... 100496selecting default "shared_buffers" ... 128MB497selecting default time zone ... UTC498creating configuration files ... ok499running bootstrap script ... ok500performing post-bootstrap initialization ... ok501syncing data to disk ... ok502503initdb: warning: enabling "trust" authentication for local connections504initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.505506Success. You can now start the database server using:507508 pg_ctl -D /build/postgres92876979/data -l logfile start509510/build/postgres92876979:5432 - no response5112026-10-11 05:55:08.264 UTC [128] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit5122026-10-11 05:55:08.264 UTC [128] LOG: listening on Unix socket "/build/postgres92876979/.s.PGSQL.5432"5132026-10-11 05:55:08.269 UTC [135] LOG: database system was shut down at 2026-10-11 05:55:07 UTC5142026-10-11 05:55:08.273 UTC [128] LOG: database system is ready to accept connections515/build/postgres92876979:5432 - accepting connections516{"timestamp":"2026-10-11T05:55:08.576466591Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"508456e6-191b-4d2a-b1fb-145429529701","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":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(388)"}517=== RUN TestService_AuthMiddleware518=== PAUSE TestService_AuthMiddleware519=== RUN TestService_AuthMiddleware_MTLSProxyHeader520=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader521=== RUN TestService_AuthMiddleware_MTLSBoundSubjects522=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects523=== RUN TestService_ReadAuthMiddleware524=== PAUSE TestService_ReadAuthMiddleware525=== RUN TestService_AuthMiddleware_OIDC526=== PAUSE TestService_AuthMiddleware_OIDC527=== RUN TestService_RequireScope_OIDC528=== PAUSE TestService_RequireScope_OIDC529=== RUN TestService_ReadScope_PublicByDefault530=== PAUSE TestService_ReadScope_PublicByDefault531=== RUN TestCacheConfigHandler532=== PAUSE TestCacheConfigHandler533=== RUN TestCacheStatsHandler534=== PAUSE TestCacheStatsHandler535=== RUN TestClientCADerivations536=== PAUSE TestClientCADerivations537=== RUN TestClientErrorHandling538=== PAUSE TestClientErrorHandling539=== RUN TestClientIntegration540=== PAUSE TestClientIntegration541=== RUN TestClientMultipleUploads542=== PAUSE TestClientMultipleUploads543=== RUN TestClientWithDependencies544=== PAUSE TestClientWithDependencies545=== RUN TestClientSharedPathCommittedMidPush546=== PAUSE TestClientSharedPathCommittedMidPush547=== RUN TestPinProtectsFromGC548=== PAUSE TestPinProtectsFromGC549=== RUN TestClientPushesUseOnePush550=== PAUSE TestClientPushesUseOnePush551=== RUN TestClientFallsBackToClosures552=== PAUSE TestClientFallsBackToClosures553=== RUN TestDeleteClosuresRacingPins554=== PAUSE TestDeleteClosuresRacingPins555=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock556=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock557=== RUN TestResolveDBConnectionString558=== PAUSE TestResolveDBConnectionString559=== RUN TestConnectWaitsForAPeerMigration560=== PAUSE TestConnectWaitsForAPeerMigration561=== RUN TestLeadElectsOneAndHandsOver562=== PAUSE TestLeadElectsOneAndHandsOver563=== RUN TestLeadIncumbentWinsAfterRestart5642026/10/11 05:55:08 INFO lead: acquired remote=192.0.2.1:12345652026/10/11 05:55:09 INFO lead: released remote=192.0.2.1:12345662026/10/11 05:55:09 INFO lead: acquired remote=192.0.2.1:12345672026/10/11 05:55:10 INFO lead: released remote=192.0.2.1:1234568--- PASS: TestLeadIncumbentWinsAfterRestart (1.84s)569=== RUN TestLeadIncumbentAnnouncesAtOnce570=== PAUSE TestLeadIncumbentAnnouncesAtOnce571=== RUN TestLeadEndsOnShutdown572=== PAUSE TestLeadEndsOnShutdown573=== RUN TestLeadEndsWhenItsConnectionHangs5742026/10/11 05:55:10 INFO lead: acquired remote=192.0.2.1:12345752026-10-11 05:55:12.045 UTC [572] FATAL: terminating connection due to administrator command5762026/10/11 05:55:12 INFO lead: acquired remote=192.0.2.1:12345772026/10/11 05:55:13 WARN lead: lock connection lost error="timeout: context deadline exceeded"5782026/10/11 05:55:13 INFO lead: released remote=192.0.2.1:12345792026/10/11 05:55:13 INFO lead: released remote=192.0.2.1:1234580--- PASS: TestLeadEndsWhenItsConnectionHangs (2.92s)581=== RUN TestGCAdvisoryLockBlocksConcurrentRun582=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun583=== RUN TestGCBugBareHashReferences584=== PAUSE TestGCBugBareHashReferences585=== RUN TestGCMetrics586=== PAUSE TestGCMetrics587=== RUN TestPushDedupSurvivesConcurrentGC588=== PAUSE TestPushDedupSurvivesConcurrentGC589=== RUN TestDeduplicatedObjectsRecordedAsPending590=== PAUSE TestDeduplicatedObjectsRecordedAsPending591=== RUN TestGCSweepSkipsPendingObjects592=== PAUSE TestGCSweepSkipsPendingObjects593=== RUN TestTombstonedObjectOfferedWithoutWaiting594=== PAUSE TestTombstonedObjectOfferedWithoutWaiting595=== RUN TestGCSweepDeliversEachKeyOnce596=== PAUSE TestGCSweepDeliversEachKeyOnce597=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection598=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection599=== RUN TestForceGCDuringPushOffersSweptObject600=== PAUSE TestForceGCDuringPushOffersSweptObject601=== RUN TestFailedS3DeleteKeepsTombstone602=== PAUSE TestFailedS3DeleteKeepsTombstone603=== RUN TestSweepSkipsRowsLockedByPush604=== PAUSE TestSweepSkipsRowsLockedByPush605=== RUN TestRegisterCompletedObjectNeedsPendingRow606=== PAUSE TestRegisterCompletedObjectNeedsPendingRow607=== RUN TestGetExistingObjectsLocksRows608=== PAUSE TestGetExistingObjectsLocksRows609=== RUN TestSweepRechecksPendingAfterLocking610=== PAUSE TestSweepRechecksPendingAfterLocking611=== RUN TestPushWaitsForSweepHoldingRow612=== PAUSE TestPushWaitsForSweepHoldingRow613=== RUN TestCommitRacingPendingCleanupKeepsObjects614=== PAUSE TestCommitRacingPendingCleanupKeepsObjects615=== RUN TestGCEndsOnShutdown616=== PAUSE TestGCEndsOnShutdown617=== RUN TestGCTaskStore_StartNew618=== PAUSE TestGCTaskStore_StartNew619=== RUN TestGCTaskStore_DeduplicateSameParams620=== PAUSE TestGCTaskStore_DeduplicateSameParams621=== RUN TestGCTaskStore_ConflictDifferentParams622=== PAUSE TestGCTaskStore_ConflictDifferentParams623=== RUN TestGCTaskStore_GetEmpty624=== PAUSE TestGCTaskStore_GetEmpty625=== RUN TestGCTaskStore_GetReturnsLatest626=== PAUSE TestGCTaskStore_GetReturnsLatest627=== RUN TestGCTaskStore_CompletedAllowsNewTask628=== PAUSE TestGCTaskStore_CompletedAllowsNewTask629=== RUN TestGCTaskStore_PhaseUpdates630=== PAUSE TestGCTaskStore_PhaseUpdates631=== RUN TestGCTaskStore_Fail632=== PAUSE TestGCTaskStore_Fail633=== RUN TestGracefulShutdownDrainsInflight634=== PAUSE TestGracefulShutdownDrainsInflight635=== RUN TestService_healthCheckHandler636=== PAUSE TestService_healthCheckHandler637=== RUN TestService_readinessHandler638=== PAUSE TestService_readinessHandler639=== RUN TestGenerateLandingPage640=== PAUSE TestGenerateLandingPage641=== RUN TestCacheConfigHandlerMaxNarSize642=== PAUSE TestCacheConfigHandlerMaxNarSize643=== RUN TestCreatePendingClosureRejectsOversizedNAR644=== PAUSE TestCreatePendingClosureRejectsOversizedNAR645=== RUN TestNARDeduplicationMetadataUploadBug646=== PAUSE TestNARDeduplicationMetadataUploadBug647=== RUN TestMetricsInventory648=== PAUSE TestMetricsInventory649=== RUN TestMetricsCommit650=== PAUSE TestMetricsCommit651=== RUN TestService_NativeMTLS652=== PAUSE TestService_NativeMTLS653=== RUN TestServerTLSConfig654=== PAUSE TestServerTLSConfig655=== RUN TestMultipartCleanup656=== PAUSE TestMultipartCleanup657=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded658=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded659=== RUN TestPendingCleanupUsesOneCutoff660=== PAUSE TestPendingCleanupUsesOneCutoff661=== RUN TestObjectStatsTrigger662=== PAUSE TestObjectStatsTrigger663=== RUN TestObjectStatsLargeCommit664=== PAUSE TestObjectStatsLargeCommit665=== RUN TestOrphanedObjectsGC666=== PAUSE TestOrphanedObjectsGC667=== RUN TestOrphanedObjectsGCStressTest668=== PAUSE TestOrphanedObjectsGCStressTest669=== RUN TestCreatePin_ReservedPins670=== PAUSE TestCreatePin_ReservedPins671=== RUN TestPresentReportsOnlyClosureRoots672=== PAUSE TestPresentReportsOnlyClosureRoots673=== RUN TestPresentRefreshesOnlyStaleClosures674=== PAUSE TestPresentRefreshesOnlyStaleClosures675=== RUN TestPresentNotReportedWhileGCDeletesClosure676=== PAUSE TestPresentNotReportedWhileGCDeletesClosure677=== RUN TestParseSingleRange678=== PAUSE TestParseSingleRange679=== RUN TestProxyHeadersOnlyTrustedOnSocket6802026/10/11 05:55:13 INFO Starting HTTP server address=127.0.0.1:359416812026/10/11 05:55:13 INFO Starting HTTP server address=proxy.sock6822026/10/11 05:55:13 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6832026/10/11 05:55:13 INFO Shutdown signal received, draining in-flight requests timeout=10s684--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.11s)685=== RUN TestIsValidCachePath686=== PAUSE TestIsValidCachePath687=== RUN TestReadProxyNarinfo688=== PAUSE TestReadProxyNarinfo689=== RUN TestReadProxyNarinfoAlreadyDecompressed690=== PAUSE TestReadProxyNarinfoAlreadyDecompressed691=== RUN TestReadProxyContentNegotiation692=== PAUSE TestReadProxyContentNegotiation693=== RUN TestReadProxyNarStreaming694=== PAUSE TestReadProxyNarStreaming695=== RUN TestReadProxy404696=== PAUSE TestReadProxy404697=== RUN TestReadProxyInvalidPath698=== PAUSE TestReadProxyInvalidPath699=== RUN TestReadProxyHead700=== PAUSE TestReadProxyHead701=== RUN TestReadProxyOutlastsServerWriteTimeout702=== PAUSE TestReadProxyOutlastsServerWriteTimeout703=== RUN TestReadProxyConditionalGet704=== PAUSE TestReadProxyConditionalGet705=== RUN TestReadProxyRootRedirectsToIndexHTML706=== PAUSE TestReadProxyRootRedirectsToIndexHTML707=== RUN TestReadProxyDisabled708=== PAUSE TestReadProxyDisabled709=== RUN TestReadRedirectNar710=== PAUSE TestReadRedirectNar711=== RUN TestReadRedirectKeepsNarinfoProxied712=== PAUSE TestReadRedirectKeepsNarinfoProxied713=== RUN TestReadProxyRangeRequest714=== PAUSE TestReadProxyRangeRequest715=== RUN TestReadRedirectUsesPublicS3URL716=== PAUSE TestReadRedirectUsesPublicS3URL717=== RUN TestPush_OverlappingRootsStoreOneRowPerKey718=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey719=== RUN TestPush_CompleteCommitsEveryRoot720=== PAUSE TestPush_CompleteCommitsEveryRoot721=== RUN TestPush_RepeatedRootCommitsOnce722=== PAUSE TestPush_RepeatedRootCommitsOnce723=== RUN TestPush_CompleteWaitsForCleanupOfThePush724=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush725=== RUN TestPush_RootsAreLockedInByteOrder726=== PAUSE TestPush_RootsAreLockedInByteOrder727=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit728=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit729=== RUN TestPush_RejectsBadRequests730=== PAUSE TestPush_RejectsBadRequests731=== RUN TestPush_SignsNarinfosOfItsPendingObjects732=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects733=== RUN TestRedundantMultipartUpload734=== PAUSE TestRedundantMultipartUpload735=== RUN TestCompleteMultipartUpload_ErrorButObjectExists736=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists737=== RUN TestCompletedNarNotReofferedAcrossClosures738=== PAUSE TestCompletedNarNotReofferedAcrossClosures739=== RUN TestPresignedUploadRegisteredBeforeCommit740=== PAUSE TestPresignedUploadRegisteredBeforeCommit741=== RUN TestService_Rustfstest742=== PAUSE TestService_Rustfstest743=== RUN TestParseSize744=== PAUSE TestParseSize745=== RUN TestSkippedUploadsHandler746=== PAUSE TestSkippedUploadsHandler747=== RUN TestSystemdListenerNotActivated748--- PASS: TestSystemdListenerNotActivated (0.00s)749=== RUN TestWatchdogBeatsWhenHealthy750--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)751=== RUN TestWatchdogSkipsWhenUnhealthy7522026/10/11 05:55:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7532026/10/11 05:55:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7542026/10/11 05:55:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7552026/10/11 05:55:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7562026/10/11 05:55:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7572026/10/11 05:55:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7582026/10/11 05:55:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7592026/10/11 05:55:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7602026/10/11 05:55:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7612026/10/11 05:55:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"762--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)763=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle764=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle765=== RUN TestProxyWriteTimeout766=== PAUSE TestProxyWriteTimeout767=== RUN TestPendingClosureWriteTimeout768=== PAUSE TestPendingClosureWriteTimeout769=== RUN TestIsValidUploadKey770=== PAUSE TestIsValidUploadKey771=== RUN TestUploadHandlersRejectInvalidKeys772=== PAUSE TestUploadHandlersRejectInvalidKeys773=== RUN TestUploadHandlersRejectOversizedBody774=== PAUSE TestUploadHandlersRejectOversizedBody775=== RUN TestService_cleanupPendingClosuresHandler776=== PAUSE TestService_cleanupPendingClosuresHandler777=== RUN TestService_createPendingClosureHandler778=== PAUSE TestService_createPendingClosureHandler779=== RUN TestService_verifyS3Integrity780=== PAUSE TestService_verifyS3Integrity781=== RUN TestCompleteMultipartUnregistered782=== PAUSE TestCompleteMultipartUnregistered783=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT784=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT785=== CONT TestService_AuthMiddleware786=== CONT TestReadProxyInvalidPath787=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT788=== CONT TestCompleteMultipartUnregistered789=== CONT TestService_verifyS3Integrity790=== CONT TestService_createPendingClosureHandler791=== CONT TestService_cleanupPendingClosuresHandler792=== CONT TestUploadHandlersRejectOversizedBody793=== CONT TestUploadHandlersRejectInvalidKeys794=== CONT TestIsValidUploadKey795=== CONT TestPendingClosureWriteTimeout796=== RUN TestIsValidUploadKey/narinfo797=== CONT TestProxyWriteTimeout798=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle799=== CONT TestSkippedUploadsHandler800=== CONT TestParseSize801=== CONT TestService_Rustfstest802=== CONT TestPresignedUploadRegisteredBeforeCommit803=== CONT TestCompletedNarNotReofferedAcrossClosures804=== CONT TestCompleteMultipartUpload_ErrorButObjectExists805=== CONT TestRedundantMultipartUpload806=== CONT TestPush_SignsNarinfosOfItsPendingObjects807=== CONT TestPush_RejectsBadRequests808=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit809=== CONT TestPush_RootsAreLockedInByteOrder810=== RUN TestPendingClosureWriteTimeout/empty811=== RUN TestProxyWriteTimeout/narinfo812=== PAUSE TestIsValidUploadKey/narinfo813=== RUN TestIsValidUploadKey/nar_zst814--- PASS: TestParseSize (0.00s)8152026/10/11 05:55:13 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000816=== CONT TestPush_CompleteWaitsForCleanupOfThePush817=== PAUSE TestPendingClosureWriteTimeout/empty818=== PAUSE TestIsValidUploadKey/nar_zst819=== RUN TestIsValidUploadKey/nar_xz820=== RUN TestPendingClosureWriteTimeout/400_objects821=== PAUSE TestProxyWriteTimeout/narinfo822=== PAUSE TestPendingClosureWriteTimeout/400_objects823=== RUN TestPendingClosureWriteTimeout/670k_objects824=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info825=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info826=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal827=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal828=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key829=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key830=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key831=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key832=== CONT TestPush_RepeatedRootCommitsOnce833=== PAUSE TestPendingClosureWriteTimeout/670k_objects834=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline835=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline836=== CONT TestPush_CompleteCommitsEveryRoot837=== RUN TestProxyWriteTimeout/1_GiB_nar838=== PAUSE TestProxyWriteTimeout/1_GiB_nar839=== RUN TestProxyWriteTimeout/10_GiB_nar840=== PAUSE TestProxyWriteTimeout/10_GiB_nar841=== RUN TestProxyWriteTimeout/unknown_size842=== PAUSE TestProxyWriteTimeout/unknown_size843=== PAUSE TestIsValidUploadKey/nar_xz844=== RUN TestIsValidUploadKey/nar_plain845=== PAUSE TestIsValidUploadKey/nar_plain846=== RUN TestIsValidUploadKey/listing847=== PAUSE TestIsValidUploadKey/listing848=== RUN TestIsValidUploadKey/build_log849=== PAUSE TestIsValidUploadKey/build_log850=== RUN TestIsValidUploadKey/build_log_home-manager_file851=== PAUSE TestIsValidUploadKey/build_log_home-manager_file852=== RUN TestIsValidUploadKey/build_log_plus_in_name853=== PAUSE TestIsValidUploadKey/build_log_plus_in_name854=== RUN TestIsValidUploadKey/build_log_question_mark855=== PAUSE TestIsValidUploadKey/build_log_question_mark856=== CONT TestPush_OverlappingRootsStoreOneRowPerKey857=== RUN TestIsValidUploadKey/build_log_equals858=== PAUSE TestIsValidUploadKey/build_log_equals859=== RUN TestIsValidUploadKey/realisation860=== PAUSE TestIsValidUploadKey/realisation861=== RUN TestIsValidUploadKey/realisation_plus_in_output862=== PAUSE TestIsValidUploadKey/realisation_plus_in_output863=== RUN TestIsValidUploadKey/nix-cache-info864=== PAUSE TestIsValidUploadKey/nix-cache-info865=== RUN TestIsValidUploadKey/index.html866=== PAUSE TestIsValidUploadKey/index.html867=== RUN TestIsValidUploadKey/narinfo_key,_nar_type868=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type869=== RUN TestIsValidUploadKey/nar_key,_narinfo_type870=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type871=== RUN TestIsValidUploadKey/listing_key,_narinfo_type872=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type873=== RUN TestIsValidUploadKey/traversal874=== PAUSE TestIsValidUploadKey/traversal875=== RUN TestIsValidUploadKey/traversal_nar876=== PAUSE TestIsValidUploadKey/traversal_nar877=== RUN TestIsValidUploadKey/absolute878=== PAUSE TestIsValidUploadKey/absolute879=== RUN TestIsValidUploadKey/empty_key880=== PAUSE TestIsValidUploadKey/empty_key881=== RUN TestIsValidUploadKey/unknown_type882=== PAUSE TestIsValidUploadKey/unknown_type883=== CONT TestReadRedirectUsesPublicS3URL884--- PASS: TestSkippedUploadsHandler (0.11s)885=== CONT TestReadProxyRangeRequest886=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure887=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure888=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart889=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart890=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts891=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts892=== CONT TestReadRedirectKeepsNarinfoProxied8932026/10/11 05:55:14 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"894--- PASS: TestService_AuthMiddleware (0.33s)895=== CONT TestReadRedirectNar896--- PASS: TestReadProxyInvalidPath (0.35s)897=== CONT TestReadProxyDisabled8982026/10/11 05:55:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8992026/10/11 05:55:14 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst900--- PASS: TestCompleteMultipartUnregistered (0.37s)901=== CONT TestReadProxyRootRedirectsToIndexHTML9022026/10/11 05:55:14 INFO Received uploads request method=POST path=/api/pending_closures903--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.41s)904=== CONT TestReadProxyConditionalGet9052026/10/11 05:55:14 INFO Received uploads request method=POST path=/api/pending_closures9062026/10/11 05:55:14 INFO Received uploads request method=POST path=/api/pending_closures9072026/10/11 05:55:14 INFO Received uploads request method=POST path=/api/pending_closures9082026/10/11 05:55:14 INFO Received uploads request method=POST path=/api/pending_closures9092026/10/11 05:55:14 INFO Received cleanup request method=DELETE path=/api/pending_closures9102026/10/11 05:55:14 INFO Aborted multipart uploads count=0 kept=09112026/10/11 05:55:14 INFO Received uploads request method=POST path=/api/pending_closures9122026/10/11 05:55:14 INFO Received cleanup request method=DELETE path=/api/pending_closures9132026/10/11 05:55:14 INFO Aborted multipart uploads count=1 kept=09142026/10/11 05:55:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9152026-10-11 05:55:14.276 UTC [648] ERROR: Closure does not exist: id=19162026-10-11 05:55:14.276 UTC [648] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9172026-10-11 05:55:14.276 UTC [648] STATEMENT: -- name: CommitPendingClosure :one918 SELECT commit_pending_closure($1::bigint)::bigint919 920--- PASS: TestService_cleanupPendingClosuresHandler (0.48s)921=== CONT TestReadProxyOutlastsServerWriteTimeout9222026/10/11 05:55:14 INFO Received uploads request method=POST path=/api/pending_closures9232026/10/11 05:55:14 INFO Received uploads request method=POST path=/api/pending_closures9242026/10/11 05:55:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9252026/10/11 05:55:14 INFO Received push request method=POST path=/api/pushes9262026/10/11 05:55:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9272026/10/11 05:55:14 INFO Signed narinfos id=1 count=19282026/10/11 05:55:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9292026/10/11 05:55:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9302026/10/11 05:55:14 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"9312026/10/11 05:55:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9322026/10/11 05:55:14 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"9332026/10/11 05:55:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9342026/10/11 05:55:14 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=19352026/10/11 05:55:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9362026/10/11 05:55:14 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo937--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.54s)938=== CONT TestReadProxyHead9392026/10/11 05:55:14 INFO Received push request method=POST path=/api/pushes9402026/10/11 05:55:14 INFO Received push request method=POST path=/api/pushes9412026-10-11 05:55:14.404 UTC [698] ERROR: could not obtain lock on row in relation "closures"9422026-10-11 05:55:14.404 UTC [698] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9432026-10-11 05:55:14.405 UTC [698] ERROR: could not obtain lock on row in relation "closures"9442026-10-11 05:55:14.405 UTC [698] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9452026-10-11 05:55:14.405 UTC [698] ERROR: could not obtain lock on row in relation "closures"9462026-10-11 05:55:14.405 UTC [698] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9472026-10-11 05:55:14.405 UTC [698] ERROR: could not obtain lock on row in relation "closures"9482026-10-11 05:55:14.405 UTC [698] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9492026-10-11 05:55:14.405 UTC [698] ERROR: could not obtain lock on row in relation "closures"9502026-10-11 05:55:14.405 UTC [698] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT951--- PASS: TestPush_RootsAreLockedInByteOrder (0.60s)952=== CONT TestPushWaitsForSweepHoldingRow9532026/10/11 05:55:14 INFO Received complete push request method=POST path=/api/pushes/1/complete9542026/10/11 05:55:14 INFO Received push request method=POST path=/api/pushes9552026/10/11 05:55:14 INFO Completed push id=1 objects=4 duration=8.115324ms9562026/10/11 05:55:14 INFO Received push request method=POST path=/api/pushes9572026/10/11 05:55:14 INFO Received complete push request method=POST path=/api/pushes/1/complete9582026/10/11 05:55:14 INFO Received uploads request method=POST path=/api/pending_closures9592026/10/11 05:55:14 INFO Completed push id=1 objects=4 duration=8.259754ms960--- PASS: TestPush_RepeatedRootCommitsOnce (0.53s)961=== CONT TestReadProxy4049622026/10/11 05:55:14 INFO Received uploads request method=POST path=/api/pending_closures9632026/10/11 05:55:14 INFO Received push request method=POST path=/api/pushes9642026/10/11 05:55:14 INFO Aborted multipart uploads count=0 kept=09652026/10/11 05:55:14 WARN Force mode enabled - objects will be deleted immediately without grace period9662026/10/11 05:55:14 INFO Received complete push request method=POST path=/api/pushes/1/complete9672026/10/11 05:55:14 INFO Completed push id=1 objects=6 duration=8.785413ms968--- PASS: TestPush_CompleteCommitsEveryRoot (0.59s)969=== CONT TestReadProxyNarStreaming9702026/10/11 05:55:14 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=0971--- PASS: TestReadRedirectKeepsNarinfoProxied (0.51s)972=== CONT TestReadProxyContentNegotiation9732026/10/11 05:55:14 INFO Vacuumed table table=pending_closures9742026/10/11 05:55:14 INFO Vacuumed table table=pending_objects9752026/10/11 05:55:14 INFO Vacuumed table table=multipart_uploads9762026/10/11 05:55:14 INFO Vacuumed table table=closures9772026/10/11 05:55:14 INFO Received push request method=POST path=/api/pushes9782026/10/11 05:55:14 INFO Vacuumed table table=objects9792026/10/11 05:55:14 INFO Received complete push request method=POST path=/api/pushes/2/complete9802026/10/11 05:55:14 INFO Completed push id=2 objects=4 duration=4.748941ms981--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.72s)982=== CONT TestReadProxyNarinfoAlreadyDecompressed983=== RUN TestPush_RejectsBadRequests/no_roots984=== PAUSE TestPush_RejectsBadRequests/no_roots985=== RUN TestPush_RejectsBadRequests/no_objects986=== PAUSE TestPush_RejectsBadRequests/no_objects987=== RUN TestPush_RejectsBadRequests/bad_root988=== PAUSE TestPush_RejectsBadRequests/bad_root989=== RUN TestPush_RejectsBadRequests/root_not_in_objects990=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects991=== CONT TestReadProxyNarinfo9922026/10/11 05:55:14 INFO Received uploads request method=POST path=/api/pending_closures9932026/10/11 05:55:14 INFO Received uploads request method=POST path=/api/pending_closures9942026/10/11 05:55:14 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9952026/10/11 05:55:14 INFO Received uploads request method=POST path=/api/pending_closures996--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.72s)997=== CONT TestIsValidCachePath998=== RUN TestIsValidCachePath/narinfo999=== PAUSE TestIsValidCachePath/narinfo1000=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1001=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1002=== RUN TestIsValidCachePath/nar_zst1003=== PAUSE TestIsValidCachePath/nar_zst1004=== RUN TestIsValidCachePath/nar_xz1005=== PAUSE TestIsValidCachePath/nar_xz1006=== RUN TestIsValidCachePath/nar_bz21007=== PAUSE TestIsValidCachePath/nar_bz21008=== RUN TestIsValidCachePath/nar_uncompressed1009=== PAUSE TestIsValidCachePath/nar_uncompressed1010=== RUN TestIsValidCachePath/ls1011=== PAUSE TestIsValidCachePath/ls1012=== RUN TestIsValidCachePath/log1013=== PAUSE TestIsValidCachePath/log1014=== RUN TestIsValidCachePath/realisation1015=== PAUSE TestIsValidCachePath/realisation1016=== RUN TestIsValidCachePath/nix-cache-info1017=== PAUSE TestIsValidCachePath/nix-cache-info1018=== RUN TestIsValidCachePath/index.html1019=== PAUSE TestIsValidCachePath/index.html1020=== RUN TestIsValidCachePath/traversal_parent1021=== PAUSE TestIsValidCachePath/traversal_parent1022=== RUN TestIsValidCachePath/traversal_in_middle1023=== PAUSE TestIsValidCachePath/traversal_in_middle1024=== RUN TestIsValidCachePath/invalid_char_e1025=== PAUSE TestIsValidCachePath/invalid_char_e1026=== RUN TestIsValidCachePath/invalid_char_u1027=== PAUSE TestIsValidCachePath/invalid_char_u1028=== RUN TestIsValidCachePath/random_path1029=== PAUSE TestIsValidCachePath/random_path1030=== RUN TestIsValidCachePath/empty1031=== PAUSE TestIsValidCachePath/empty1032=== RUN TestIsValidCachePath/leading_slash1033=== PAUSE TestIsValidCachePath/leading_slash1034=== RUN TestIsValidCachePath/wrong_extension1035=== PAUSE TestIsValidCachePath/wrong_extension1036=== RUN TestIsValidCachePath/short_hash1037=== PAUSE TestIsValidCachePath/short_hash1038=== CONT TestParseSingleRange1039=== RUN TestParseSingleRange/none1040=== PAUSE TestParseSingleRange/none1041=== RUN TestParseSingleRange/unknown_unit1042=== PAUSE TestParseSingleRange/unknown_unit1043=== RUN TestParseSingleRange/multi-range_ignored1044=== PAUSE TestParseSingleRange/multi-range_ignored1045=== RUN TestParseSingleRange/malformed_no_dash1046=== PAUSE TestParseSingleRange/malformed_no_dash1047=== RUN TestParseSingleRange/malformed_both_empty1048=== PAUSE TestParseSingleRange/malformed_both_empty1049=== RUN TestParseSingleRange/malformed_end_before_start1050=== PAUSE TestParseSingleRange/malformed_end_before_start1051=== RUN TestParseSingleRange/closed1052=== PAUSE TestParseSingleRange/closed1053=== RUN TestParseSingleRange/open-ended1054=== PAUSE TestParseSingleRange/open-ended1055=== RUN TestParseSingleRange/end_clamped_to_size1056=== PAUSE TestParseSingleRange/end_clamped_to_size1057=== RUN TestParseSingleRange/suffix1058=== PAUSE TestParseSingleRange/suffix1059=== RUN TestParseSingleRange/suffix_exceeds_size1060=== PAUSE TestParseSingleRange/suffix_exceeds_size1061=== RUN TestParseSingleRange/single_byte1062=== PAUSE TestParseSingleRange/single_byte1063=== RUN TestParseSingleRange/start_past_EOF1064=== PAUSE TestParseSingleRange/start_past_EOF1065=== RUN TestParseSingleRange/start_far_past_EOF1066=== PAUSE TestParseSingleRange/start_far_past_EOF1067=== CONT TestPresentNotReportedWhileGCDeletesClosure1068=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1069=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1070=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1071=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1072=== CONT TestPresentRefreshesOnlyStaleClosures10732026/10/11 05:55:14 INFO Received push request method=POST path=/api/pushes10742026/10/11 05:55:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10752026/10/11 05:55:14 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MzdiNjc1ZTYtM2MxNS00MjE2LTgxNDMtNmUxMjQ3Y2JjMmIzLmJiMThkMzI5LWZiZDItNGNmOC04MTkwLTM2OGQyMmI0NWFkOXgxNzkxNjk4MTE0NjI5ODQyNjU21076--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.77s)1077=== CONT TestPresentReportsOnlyClosureRoots10782026/10/11 05:55:14 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MzdiNjc1ZTYtM2MxNS00MjE2LTgxNDMtNmUxMjQ3Y2JjMmIzLmJiMThkMzI5LWZiZDItNGNmOC04MTkwLTM2OGQyMmI0NWFkOXgxNzkxNjk4MTE0NjI5ODQyNjU2 parts=11079--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.77s)1080=== CONT TestCreatePin_ReservedPins1081--- PASS: TestService_Rustfstest (0.77s)1082=== CONT TestOrphanedObjectsGCStressTest10832026/10/11 05:55:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10842026/10/11 05:55:14 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MzdiNjc1ZTYtM2MxNS00MjE2LTgxNDMtNmUxMjQ3Y2JjMmIzLjExYTNiZGQ4LWI0ZjYtNDNmMy04Njc1LWIwYWQ3YmE3ZWE0NXgxNzkxNjk4MTE0MjE4MTM1MjM1 parts=1010852026/10/11 05:55:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10862026/10/11 05:55:14 INFO Completed upload id=1 objects=2 duration=5.271699ms10872026/10/11 05:55:14 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010882026/10/11 05:55:14 INFO Received uploads request method=POST path=/api/pending_closures10892026/10/11 05:55:14 INFO Starting cleanup of old closures method=DELETE path=/api/closures1090--- PASS: TestReadRedirectUsesPublicS3URL (0.82s)1091=== CONT TestOrphanedObjectsGC10922026/10/11 05:55:14 INFO Aborted multipart uploads count=0 kept=010932026/10/11 05:55:14 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=01094--- PASS: TestReadProxyRangeRequest (0.84s)1095=== CONT TestObjectStatsLargeCommit10962026/10/11 05:55:14 INFO Vacuumed table table=pending_closures10972026/10/11 05:55:14 INFO Vacuumed table table=pending_objects1098--- PASS: TestReadProxyDisabled (0.62s)1099=== CONT TestObjectStatsTrigger11002026/10/11 05:55:14 INFO Vacuumed table table=multipart_uploads11012026/10/11 05:55:14 INFO Vacuumed table table=closures11022026/10/11 05:55:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11032026/10/11 05:55:14 INFO Vacuumed table table=objects11042026/10/11 05:55:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41123/oidc11052026/10/11 05:55:14 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MzdiNjc1ZTYtM2MxNS00MjE2LTgxNDMtNmUxMjQ3Y2JjMmIzLjk0NjBhZTNjLWZkZDctNGFkMi1hNDZhLTkyOGU2MTg4MTA3N3gxNzkxNjk4MTE0Mjk5ODE2MDA3 parts=1011062026/10/11 05:55:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11072026/10/11 05:55:14 INFO Completed upload id=1 objects=2 duration=6.387897ms1108--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.64s)1109=== CONT TestPendingCleanupUsesOneCutoff11102026/10/11 05:55:14 INFO Received uploads request method=POST path=/api/pending_closures11112026/10/11 05:55:14 INFO Received uploads request method=POST path=/api/pending_closures11122026/10/11 05:55:14 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo11132026/10/11 05:55:14 WARN Found objects in DB but missing from S3, will re-upload count=11114--- PASS: TestService_verifyS3Integrity (1.03s)1115=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded11162026/10/11 05:55:14 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001117--- PASS: TestService_createPendingClosureHandler (1.03s)1118=== CONT TestMultipartCleanup1119--- PASS: TestReadRedirectNar (0.72s)1120=== CONT TestServerTLSConfig1121=== RUN TestServerTLSConfig/no_client_CA1122=== PAUSE TestServerTLSConfig/no_client_CA1123=== RUN TestServerTLSConfig/missing_CA_file1124=== PAUSE TestServerTLSConfig/missing_CA_file1125=== RUN TestServerTLSConfig/not_a_PEM_file1126=== PAUSE TestServerTLSConfig/not_a_PEM_file1127=== CONT TestService_NativeMTLS11282026-10-11 05:55:14.854 UTC [717] ERROR: Push does not exist: id=111292026-10-11 05:55:14.854 UTC [717] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE11302026-10-11 05:55:14.854 UTC [717] STATEMENT: SELECT commit_push($1)1131--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.95s)1132=== CONT TestMetricsCommit1133--- PASS: TestReadProxyConditionalGet (0.67s)1134=== CONT TestMetricsInventory11352026/10/11 05:55:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11362026/10/11 05:55:14 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MzdiNjc1ZTYtM2MxNS00MjE2LTgxNDMtNmUxMjQ3Y2JjMmIzLjAyZDcwZjIyLWJmNjktNDg1Yi1iYTMyLTFlYTk1MGZmOWI5YngxNzkxNjk4MTE0MzE3OTE5MTAy parts=1211372026/10/11 05:55:14 INFO Received uploads request method=POST path=/api/pending_closures1138--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.12s)1139=== CONT TestNARDeduplicationMetadataUploadBug1140--- PASS: TestReadProxyHead (0.58s)1141=== CONT TestCreatePendingClosureRejectsOversizedNAR11422026/10/11 05:55:14 INFO Received uploads request method=POST path=/api/pending_closures1143--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1144=== CONT TestCacheConfigHandlerMaxNarSize1145--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1146=== CONT TestGenerateLandingPage1147--- PASS: TestGenerateLandingPage (0.00s)1148=== CONT TestService_readinessHandler11492026/10/11 05:55:14 INFO Received uploads request method=POST path=/api/pending_closures1150--- PASS: TestReadProxy404 (0.57s)1151=== CONT TestService_healthCheckHandler1152--- PASS: TestReadProxyNarStreaming (0.52s)1153=== CONT TestGracefulShutdownDrainsInflight11542026/10/11 05:55:15 INFO Starting HTTP server address=127.0.0.1:3854711552026/10/11 05:55:15 INFO Shutdown signal received, draining in-flight requests timeout=10s11562026/10/11 05:55:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11572026/10/11 05:55:15 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MzdiNjc1ZTYtM2MxNS00MjE2LTgxNDMtNmUxMjQ3Y2JjMmIzLjk1MDg4MGEwLWY3OGMtNGQ1NS1iNzJmLWJkMDk1YWIxMzA3YngxNzkxNjk4MTE0NDQ5MjI4MjI3 parts=1211582026/10/11 05:55:15 INFO Received uploads request method=POST path=/api/pending_closures1159--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.55s)1160=== CONT TestGCTaskStore_Fail1161--- PASS: TestGCTaskStore_Fail (0.00s)1162=== CONT TestGCTaskStore_DeduplicateSameParams1163--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1164=== CONT TestGCTaskStore_StartNew1165--- PASS: TestGCTaskStore_StartNew (0.00s)1166=== CONT TestGCEndsOnShutdown1167=== RUN TestGCEndsOnShutdown/before_the_run1168=== PAUSE TestGCEndsOnShutdown/before_the_run1169=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1170=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1171=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1172=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1173=== CONT TestCommitRacingPendingCleanupKeepsObjects11742026/10/11 05:55:15 INFO Received uploads request method=POST path=/api/pending_closures1175--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1176=== CONT TestResolveDBConnectionString1177=== RUN TestResolveDBConnectionString/flag_wins1178=== PAUSE TestResolveDBConnectionString/flag_wins1179=== RUN TestResolveDBConnectionString/file_when_flag_empty1180=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1181=== RUN TestResolveDBConnectionString/missing_file_is_an_error1182=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1183=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1184=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1185=== RUN TestResolveDBConnectionString/nothing_configured1186=== PAUSE TestResolveDBConnectionString/nothing_configured1187=== CONT TestSweepRechecksPendingAfterLocking1188--- PASS: TestReadProxyContentNegotiation (0.63s)1189=== CONT TestGetExistingObjectsLocksRows1190--- PASS: TestPresentRefreshesOnlyStaleClosures (0.53s)1191=== CONT TestRegisterCompletedObjectNeedsPendingRow1192--- PASS: TestPresentReportsOnlyClosureRoots (0.51s)1193=== CONT TestSweepSkipsRowsLockedByPush11942026/10/11 05:55:15 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1195--- PASS: TestReadProxyNarinfo (0.67s)1196=== CONT TestFailedS3DeleteKeepsTombstone1197--- PASS: TestObjectStatsTrigger (0.57s)1198=== CONT TestForceGCDuringPushOffersSweptObject1199=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1200=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1201=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1202=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1203=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection12042026/10/11 05:55:15 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12052026/10/11 05:55:15 WARN Refused reserved pin name=worker-x86_64-linux12062026/10/11 05:55:15 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12072026/10/11 05:55:15 INFO Received create pin request method=POST path=/api/pins/my-app12082026/10/11 05:55:15 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1209--- PASS: TestCreatePin_ReservedPins (0.68s)1210=== CONT TestGCSweepDeliversEachKeyOnce12112026/10/11 05:55:15 INFO Received uploads request method=POST path=/api/pending_closures12122026/10/11 05:55:15 INFO Received uploads request method=POST path=/api/pending_closures12132026/10/11 05:55:15 INFO Received uploads request method=POST path=/api/pending_closures12142026/10/11 05:55:15 INFO Received cleanup request method=DELETE path=/api/pending_closures1215--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.61s)1216=== CONT TestTombstonedObjectOfferedWithoutWaiting12172026/10/11 05:55:15 INFO Received uploads request method=POST path=/api/pending_closures1218--- PASS: TestPushWaitsForSweepHoldingRow (1.06s)1219=== CONT TestGCSweepSkipsPendingObjects12202026/10/11 05:55:15 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12212026/10/11 05:55:15 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1222--- PASS: TestService_NativeMTLS (0.63s)1223=== CONT TestDeduplicatedObjectsRecordedAsPending12242026/10/11 05:55:15 INFO Received push request method=POST path=/api/pushes12252026/10/11 05:55:15 INFO Received complete push request method=POST path=/api/pushes/1/complete12262026/10/11 05:55:15 INFO Completed push id=1 objects=4 duration=9.91859ms12272026/10/11 05:55:15 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12282026/10/11 05:55:15 INFO Completed upload id=2 objects=2 duration=2.001306ms1229--- PASS: TestMetricsCommit (0.70s)1230=== CONT TestPushDedupSurvivesConcurrentGC12312026/10/11 05:55:15 INFO Received cleanup request method=DELETE path=/api/pending_closures12322026/10/11 05:55:15 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket49/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""12332026/10/11 05:55:15 INFO Aborted multipart uploads count=0 kept=11234--- PASS: TestMetricsInventory (0.69s)1235=== CONT TestGCMetrics12362026/10/11 05:55:15 INFO Received cleanup request method=DELETE path=/api/pending_closures12372026/10/11 05:55:15 INFO Aborted multipart uploads count=1 kept=01238--- PASS: TestMultipartCleanup (0.75s)1239=== CONT TestGCBugBareHashReferences12402026/10/11 05:55:15 WARN readiness check failed error="closed pool"1241--- PASS: TestService_readinessHandler (0.65s)1242=== CONT TestGCAdvisoryLockBlocksConcurrentRun1243=== NAME TestNARDeduplicationMetadataUploadBug1244 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2272745416/001/store/62p483yhf1nchs35s5g2scl26zshqk1h-file1.txt1245--- PASS: TestService_healthCheckHandler (0.61s)1246=== CONT TestLeadEndsOnShutdown1247=== NAME TestOrphanedObjectsGC1248 orphaned_objects_gc_test.go:287: GC Test Summary:1249 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1250 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1251 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1252 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1253 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1254--- PASS: TestOrphanedObjectsGC (0.91s)1255=== CONT TestLeadIncumbentAnnouncesAtOnce12562026/10/11 05:55:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12572026/10/11 05:55:15 INFO Received push request method=POST path=/api/pushes12582026/10/11 05:55:15 INFO Aborted multipart uploads count=0 kept=012592026/10/11 05:55:15 INFO Aborted multipart uploads count=0 kept=012602026/10/11 05:55:15 WARN Force mode enabled - objects will be deleted immediately without grace period12612026/10/11 05:55:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12622026/10/11 05:55:15 INFO Uploading 62p483yhf1nchs35s5g2scl26zshqk1h-file1.txt (160B)12632026/10/11 05:55:15 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MzdiNjc1ZTYtM2MxNS00MjE2LTgxNDMtNmUxMjQ3Y2JjMmIzLjRiYWEwYjAxLTRlN2QtNDI0OC05YjFlLTYyODhhMGJkZmZhOHgxNzkxNjk4MTE1MDkyNDQ1NTc4 error="Get \"http://127.0.0.1:1/bucket17/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"12642026/10/11 05:55:15 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MzdiNjc1ZTYtM2MxNS00MjE2LTgxNDMtNmUxMjQ3Y2JjMmIzLmQ2MzhjM2VkLTBmNTYtNGM4ZS04Nzc1LTFiNzQ3ODJjNDgxNHgxNzkxNjk4MTE1MDg1MjExNjYz parts=1212652026/10/11 05:55:15 WARN Force mode enabled - objects will be deleted immediately without grace period12662026/10/11 05:55:15 INFO Received cleanup request method=DELETE path=/api/pending_closures12672026/10/11 05:55:15 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=012682026/10/11 05:55:15 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12692026/10/11 05:55:15 WARN Failed to register uploaded object key=62p483yhf1nchs35s5g2scl26zshqk1h.ls error="server returned 404: 404 page not found\n"12702026/10/11 05:55:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12712026/10/11 05:55:15 INFO Aborted multipart uploads count=1 kept=012722026/10/11 05:55:15 INFO Signed narinfos id=1 count=112732026/10/11 05:55:15 INFO Vacuumed table table=pending_closures12742026/10/11 05:55:15 INFO Uploading 1 narinfos12752026/10/11 05:55:15 INFO Vacuumed table table=pending_objects12762026/10/11 05:55:15 INFO Vacuumed table table=multipart_uploads12772026/10/11 05:55:15 INFO Vacuumed table table=closures12782026/10/11 05:55:15 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=012792026/10/11 05:55:15 INFO Vacuumed table table=objects12802026/10/11 05:55:15 INFO Received complete push request method=POST path=/api/pushes/1/complete12812026/10/11 05:55:15 WARN Failed to register uploaded object key=62p483yhf1nchs35s5g2scl26zshqk1h.narinfo error="server returned 404: 404 page not found\n"1282--- PASS: TestGetExistingObjectsLocksRows (0.59s)1283=== CONT TestLeadElectsOneAndHandsOver1284--- PASS: TestRedundantMultipartUpload (1.82s)1285=== CONT TestConnectWaitsForAPeerMigration12862026/10/11 05:55:15 INFO Vacuumed table table=pending_closures12872026/10/11 05:55:15 INFO Vacuumed table table=pending_objects1288--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.65s)12892026/10/11 05:55:15 INFO Vacuumed table table=multipart_uploads1290=== CONT TestGCTaskStore_ConflictDifferentParams1291--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1292=== CONT TestGCTaskStore_CompletedAllowsNewTask1293--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)12942026/10/11 05:55:15 INFO Vacuumed table table=closures1295=== CONT TestGCTaskStore_GetReturnsLatest1296--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1297=== CONT TestGCTaskStore_PhaseUpdates1298--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1299=== CONT TestGCTaskStore_GetEmpty1300--- PASS: TestGCTaskStore_GetEmpty (0.00s)1301=== CONT TestClientErrorHandling1302=== RUN TestClientErrorHandling/InvalidStorePath1303=== PAUSE TestClientErrorHandling/InvalidStorePath1304=== RUN TestClientErrorHandling/InvalidAuthToken1305=== PAUSE TestClientErrorHandling/InvalidAuthToken1306=== RUN TestClientErrorHandling/ServerNotAvailable1307=== PAUSE TestClientErrorHandling/ServerNotAvailable1308=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock13092026/10/11 05:55:15 INFO Completed push id=1 objects=3 duration=10.00778ms13102026/10/11 05:55:15 INFO Upload complete. (78ms)13112026/10/11 05:55:15 INFO Vacuumed table table=objects1312--- PASS: TestSweepRechecksPendingAfterLocking (0.64s)1313=== NAME TestNARDeduplicationMetadataUploadBug1314 metadata_upload_test.go:54: Retrieved narinfo from S3:1315 StorePath: /build/TestNARDeduplicationMetadataUploadBug2272745416/001/store/62p483yhf1nchs35s5g2scl26zshqk1h-file1.txt1316 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1317 Compression: zstd1318 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1319 NarSize: 1601320 References: 1321 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1322=== CONT TestService_RequireScope_OIDC1323=== NAME TestNARDeduplicationMetadataUploadBug1324 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1325 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1326 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1327--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.58s)1328=== CONT TestDeleteClosuresRacingPins1329=== NAME TestNARDeduplicationMetadataUploadBug1330 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2272745416/001/store/lizlmxnrbld4mcchbxxvwf2hq75djk4i-file2.txt13312026/10/11 05:55:15 INFO Received uploads request method=POST path=/api/pending_closures13322026/10/11 05:55:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46013/oidc13332026/10/11 05:55:15 INFO Aborted multipart uploads count=0 kept=013342026/10/11 05:55:15 WARN Force mode enabled - objects will be deleted immediately without grace period13352026/10/11 05:55:15 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=013362026/10/11 05:55:15 INFO Vacuumed table table=pending_closures13372026/10/11 05:55:15 INFO Vacuumed table table=pending_objects13382026/10/11 05:55:15 INFO Vacuumed table table=multipart_uploads13392026/10/11 05:55:15 INFO Vacuumed table table=closures13402026/10/11 05:55:15 INFO Vacuumed table table=objects13412026/10/11 05:55:15 INFO Aborted multipart uploads count=0 kept=013422026/10/11 05:55:15 WARN Force mode enabled - objects will be deleted immediately without grace period13432026/10/11 05:55:15 INFO Received uploads request method=POST path=/api/pending_closures13442026/10/11 05:55:15 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=013452026/10/11 05:55:15 INFO Vacuumed table table=pending_closures13462026/10/11 05:55:15 INFO Vacuumed table table=pending_objects13472026/10/11 05:55:15 INFO Vacuumed table table=multipart_uploads13482026/10/11 05:55:15 INFO Vacuumed table table=closures13492026/10/11 05:55:15 INFO Vacuumed table table=objects1350--- PASS: TestSweepSkipsRowsLockedByPush (0.65s)1351=== CONT TestClientCADerivations13522026/10/11 05:55:15 INFO Received push request method=POST path=/api/pushes13532026/10/11 05:55:15 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13542026/10/11 05:55:15 WARN Failed to register uploaded object key=lizlmxnrbld4mcchbxxvwf2hq75djk4i.ls error="server returned 404: 404 page not found\n"13552026/10/11 05:55:15 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13562026/10/11 05:55:15 INFO Signed narinfos id=2 count=113572026/10/11 05:55:15 INFO Uploading 1 narinfos13582026/10/11 05:55:15 INFO Aborted multipart uploads count=0 kept=013592026/10/11 05:55:15 INFO Received complete push request method=POST path=/api/pushes/2/complete13602026/10/11 05:55:15 WARN Failed to register uploaded object key=lizlmxnrbld4mcchbxxvwf2hq75djk4i.narinfo error="server returned 404: 404 page not found\n"13612026/10/11 05:55:15 INFO Completed push id=2 objects=3 duration=3.074894ms13622026/10/11 05:55:15 INFO Upload complete. (63ms)13632026/10/11 05:55:15 WARN Force mode enabled - objects will be deleted immediately without grace period13642026/10/11 05:55:15 INFO Received uploads request method=POST path=/api/pending_closures1365=== NAME TestNARDeduplicationMetadataUploadBug1366 metadata_upload_test.go:76: Retrieved narinfo from S3:1367 StorePath: /build/TestNARDeduplicationMetadataUploadBug2272745416/001/store/lizlmxnrbld4mcchbxxvwf2hq75djk4i-file2.txt1368 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1369 Compression: zstd1370 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1371 NarSize: 1601372 References: 1373 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1374 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1375 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1376 {"version":1,"root":{"type":"regular","size":44}}1377--- PASS: TestNARDeduplicationMetadataUploadBug (0.96s)1378=== CONT TestClientFallsBackToClosures13792026/10/11 05:55:15 INFO Aborted multipart uploads count=0 kept=01380--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.46s)1381=== CONT TestCacheStatsHandler13822026/10/11 05:55:15 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."13832026/10/11 05:55:15 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1384--- PASS: TestFailedS3DeleteKeepsTombstone (0.67s)1385=== CONT TestCacheConfigHandler1386=== RUN TestCacheConfigHandler/full_config,_no_issuer1387=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1388=== RUN TestCacheConfigHandler/no_cache_url_configured1389=== PAUSE TestCacheConfigHandler/no_cache_url_configured1390=== RUN TestCacheConfigHandler/no_signing_keys1391=== PAUSE TestCacheConfigHandler/no_signing_keys1392=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1393=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1394=== CONT TestService_ReadScope_PublicByDefault13952026/10/11 05:55:15 WARN Force mode enabled - objects will be deleted immediately without grace period13962026/10/11 05:55:15 INFO Received uploads request method=POST path=/api/pending_closures13972026/10/11 05:55:15 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=013982026/10/11 05:55:15 INFO Vacuumed table table=pending_closures13992026/10/11 05:55:15 INFO Vacuumed table table=pending_objects14002026/10/11 05:55:15 INFO Vacuumed table table=multipart_uploads1401--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.44s)14022026/10/11 05:55:15 INFO Vacuumed table table=closures1403=== CONT TestClientPushesUseOnePush14042026/10/11 05:55:15 INFO Vacuumed table table=objects1405--- PASS: TestGCSweepDeliversEachKeyOnce (0.56s)1406=== CONT TestClientWithDependencies14072026/10/11 05:55:15 INFO Received uploads request method=POST path=/api/pending_closures14082026/10/11 05:55:15 INFO Aborted multipart uploads count=0 kept=014092026/10/11 05:55:15 WARN Force mode enabled - objects will be deleted immediately without grace period14102026/10/11 05:55:15 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=014112026/10/11 05:55:15 INFO Vacuumed table table=pending_closures14122026/10/11 05:55:15 INFO Received uploads request method=POST path=/api/pending_closures14132026/10/11 05:55:15 INFO Vacuumed table table=pending_objects14142026/10/11 05:55:15 INFO Vacuumed table table=multipart_uploads14152026/10/11 05:55:15 INFO Vacuumed table table=closures14162026/10/11 05:55:15 INFO Aborted multipart uploads count=0 kept=014172026/10/11 05:55:15 INFO Vacuumed table table=objects14182026/10/11 05:55:15 WARN Force mode enabled - objects will be deleted immediately without grace period14192026/10/11 05:55:16 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=014202026/10/11 05:55:16 INFO Vacuumed table table=pending_closures14212026/10/11 05:55:16 INFO Vacuumed table table=pending_objects14222026/10/11 05:55:16 INFO Vacuumed table table=multipart_uploads14232026/10/11 05:55:16 INFO Vacuumed table table=closures14242026/10/11 05:55:16 INFO Vacuumed table table=objects1425--- PASS: TestGCSweepSkipsPendingObjects (0.54s)1426=== CONT TestClientMultipleUploads1427--- PASS: TestGCMetrics (0.45s)1428=== CONT TestPinProtectsFromGC1429--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.70s)1430=== CONT TestClientIntegration14312026/10/11 05:55:16 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"1432--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.46s)1433=== CONT TestClientSharedPathCommittedMidPush14342026/10/11 05:55:16 INFO Aborted multipart uploads count=0 kept=014352026/10/11 05:55:16 INFO lead: acquired remote=192.0.2.1:123414362026/10/11 05:55:16 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=014372026/10/11 05:55:16 INFO Vacuumed table table=pending_closures14382026/10/11 05:55:16 INFO Vacuumed table table=pending_objects14392026/10/11 05:55:16 INFO Vacuumed table table=multipart_uploads14402026/10/11 05:55:16 INFO Vacuumed table table=closures14412026/10/11 05:55:16 INFO Vacuumed table table=objects14422026/10/11 05:55:16 INFO lead: acquired remote=192.0.2.1:123414432026/10/11 05:55:16 INFO lead: released remote=192.0.2.1:12341444--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.46s)1445=== CONT TestService_ReadAuthMiddleware14462026/10/11 05:55:16 INFO Aborted multipart uploads count=0 kept=014472026/10/11 05:55:16 WARN Force mode enabled - objects will be deleted immediately without grace period14482026/10/11 05:55:16 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=014492026/10/11 05:55:16 INFO Vacuumed table table=pending_closures14502026/10/11 05:55:16 INFO Vacuumed table table=pending_objects14512026/10/11 05:55:16 INFO Vacuumed table table=multipart_uploads14522026/10/11 05:55:16 INFO Vacuumed table table=closures14532026/10/11 05:55:16 INFO Vacuumed table table=objects1454--- PASS: TestPushDedupSurvivesConcurrentGC (0.56s)1455=== CONT TestService_AuthMiddleware_OIDC14562026/10/11 05:55:16 INFO lead: acquired remote=192.0.2.1:123414572026/10/11 05:55:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39683/oidc1458--- PASS: TestObjectStatsLargeCommit (1.48s)1459=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1460=== RUN TestService_RequireScope_OIDC/builder_may_write1461=== PAUSE TestService_RequireScope_OIDC/builder_may_write1462=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1463=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1464=== RUN TestService_RequireScope_OIDC/ops_may_admin1465=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1466=== RUN TestService_RequireScope_OIDC/ops_may_not_write1467=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1468=== RUN TestService_RequireScope_OIDC/reader_may_not_write1469=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1470=== RUN TestService_RequireScope_OIDC/static_token_may_admin1471=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1472=== RUN TestService_RequireScope_OIDC/static_token_may_write1473=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1474=== RUN TestService_RequireScope_OIDC/reader_may_read1475=== PAUSE TestService_RequireScope_OIDC/reader_may_read1476=== RUN TestService_RequireScope_OIDC/writer_implies_read1477=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1478=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1479=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1480=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1481=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1482=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1483=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1484=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1485=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1486=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1487=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1488=== CONT TestService_AuthMiddleware_MTLSProxyHeader1489--- PASS: TestGCBugBareHashReferences (0.67s)1490=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info14912026/10/11 05:55:16 INFO Received uploads request method=POST path=/1492=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key14932026/10/11 05:55:16 INFO Received complete multipart upload request method=POST path=/1494=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key14952026/10/11 05:55:16 INFO Received request for more parts method=POST path=/1496=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal14972026/10/11 05:55:16 INFO Received uploads request method=POST path=/1498--- PASS: TestUploadHandlersRejectInvalidKeys (0.11s)1499 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1500 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1501 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1502 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1503=== CONT TestPendingClosureWriteTimeout/empty1504=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1505--- PASS: TestService_ReadScope_PublicByDefault (0.41s)1506=== CONT TestPendingClosureWriteTimeout/670k_objects1507=== CONT TestPendingClosureWriteTimeout/400_objects1508=== CONT TestProxyWriteTimeout/narinfo1509=== CONT TestProxyWriteTimeout/unknown_size1510=== CONT TestProxyWriteTimeout/10_GiB_nar1511=== CONT TestProxyWriteTimeout/1_GiB_nar1512--- PASS: TestProxyWriteTimeout (0.11s)1513 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1514 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1515 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1516 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1517=== CONT TestIsValidUploadKey/narinfo1518=== CONT TestIsValidUploadKey/empty_key1519=== CONT TestIsValidUploadKey/absolute1520=== CONT TestIsValidUploadKey/traversal_nar1521=== CONT TestIsValidUploadKey/traversal1522=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1523=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1524=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1525=== CONT TestIsValidUploadKey/index.html1526=== CONT TestIsValidUploadKey/nix-cache-info1527=== CONT TestIsValidUploadKey/realisation_plus_in_output1528=== CONT TestIsValidUploadKey/realisation1529=== CONT TestIsValidUploadKey/build_log_equals1530=== CONT TestIsValidUploadKey/build_log_question_mark1531=== CONT TestIsValidUploadKey/build_log_plus_in_name1532=== CONT TestIsValidUploadKey/build_log_home-manager_file1533=== CONT TestIsValidUploadKey/unknown_type1534=== CONT TestIsValidUploadKey/build_log1535=== CONT TestIsValidUploadKey/listing1536=== CONT TestIsValidUploadKey/nar_plain1537=== CONT TestIsValidUploadKey/nar_xz1538=== CONT TestIsValidUploadKey/nar_zst1539--- PASS: TestIsValidUploadKey (0.11s)1540 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1541 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1542 --- PASS: TestIsValidUploadKey/absolute (0.00s)1543 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1544 --- PASS: TestIsValidUploadKey/traversal (0.00s)1545 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1546 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1547 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1548 --- PASS: TestIsValidUploadKey/index.html (0.00s)1549 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1550 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1551 --- PASS: TestIsValidUploadKey/realisation (0.00s)1552 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1553 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1554 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1555 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1556 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1557 --- PASS: TestIsValidUploadKey/build_log (0.00s)1558 --- PASS: TestIsValidUploadKey/listing (0.00s)1559 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1560 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1561 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1562=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure15632026/10/11 05:55:16 INFO Received uploads request method=POST path=/1564=== NAME TestClientCADerivations1565 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations4275305078/001/store/lxqy4a2qzaai3r7w8iqp0bma681q6i4q-ca-test1566--- PASS: TestCacheStatsHandler (0.47s)1567=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts15682026/10/11 05:55:16 INFO Received request for more parts method=POST path=/1569=== NAME TestClientCADerivations1570 client_ca_test.go:139: Found 1 dependencies (including self)1571--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.65s)1572=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart15732026/10/11 05:55:16 INFO Received complete multipart upload request method=POST path=/1574=== CONT TestPush_RejectsBadRequests/no_roots15752026/10/11 05:55:16 INFO Received push request method=POST path=/api/pushes1576=== CONT TestPush_RejectsBadRequests/bad_root15772026/10/11 05:55:16 INFO Received push request method=POST path=/api/pushes1578=== CONT TestPush_RejectsBadRequests/root_not_in_objects15792026/10/11 05:55:16 INFO Received push request method=POST path=/api/pushes1580=== CONT TestPush_RejectsBadRequests/no_objects15812026/10/11 05:55:16 INFO Received push request method=POST path=/api/pushes1582=== CONT TestIsValidCachePath/narinfo1583--- PASS: TestPush_RejectsBadRequests (0.65s)1584 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1585 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1586 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1587 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1588=== CONT TestIsValidCachePath/index.html1589=== CONT TestIsValidCachePath/nix-cache-info1590=== CONT TestIsValidCachePath/realisation1591=== CONT TestIsValidCachePath/log1592=== CONT TestIsValidCachePath/ls1593=== CONT TestIsValidCachePath/nar_uncompressed1594=== CONT TestIsValidCachePath/nar_bz21595=== CONT TestIsValidCachePath/nar_xz1596=== CONT TestIsValidCachePath/nar_zst1597=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1598=== CONT TestIsValidCachePath/empty1599=== CONT TestIsValidCachePath/traversal_parent1600=== CONT TestIsValidCachePath/random_path1601=== CONT TestIsValidCachePath/invalid_char_u1602=== CONT TestIsValidCachePath/invalid_char_e1603=== CONT TestIsValidCachePath/traversal_in_middle1604=== CONT TestIsValidCachePath/wrong_extension1605=== CONT TestIsValidCachePath/short_hash1606=== CONT TestIsValidCachePath/leading_slash1607--- PASS: TestIsValidCachePath (0.00s)1608 --- PASS: TestIsValidCachePath/narinfo (0.00s)1609 --- PASS: TestIsValidCachePath/index.html (0.00s)1610 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1611 --- PASS: TestIsValidCachePath/realisation (0.00s)1612 --- PASS: TestIsValidCachePath/log (0.00s)1613 --- PASS: TestIsValidCachePath/ls (0.00s)1614 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1615 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1616 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1617 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1618 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1619 --- PASS: TestIsValidCachePath/empty (0.00s)1620 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1621 --- PASS: TestIsValidCachePath/random_path (0.00s)1622 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1623 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1624 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1625 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1626 --- PASS: TestIsValidCachePath/short_hash (0.00s)1627 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1628=== CONT TestParseSingleRange/none1629=== CONT TestParseSingleRange/open-ended1630=== CONT TestParseSingleRange/start_far_past_EOF1631=== CONT TestParseSingleRange/start_past_EOF1632=== CONT TestParseSingleRange/single_byte1633=== CONT TestParseSingleRange/suffix_exceeds_size1634=== CONT TestParseSingleRange/suffix1635=== CONT TestParseSingleRange/end_clamped_to_size1636=== CONT TestParseSingleRange/malformed_both_empty1637=== CONT TestParseSingleRange/closed1638=== CONT TestParseSingleRange/malformed_end_before_start1639=== CONT TestParseSingleRange/multi-range_ignored1640=== CONT TestParseSingleRange/malformed_no_dash1641=== CONT TestParseSingleRange/unknown_unit1642--- PASS: TestParseSingleRange (0.00s)1643 --- PASS: TestParseSingleRange/none (0.00s)1644 --- PASS: TestParseSingleRange/open-ended (0.00s)1645 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1646 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1647 --- PASS: TestParseSingleRange/single_byte (0.00s)1648 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1649 --- PASS: TestParseSingleRange/suffix (0.00s)1650 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1651 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1652 --- PASS: TestParseSingleRange/closed (0.00s)1653 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1654 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1655 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1656 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1657=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1658=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1659=== NAME TestClientMultipleUploads1660 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads2002990845/001/store/czrskam9brw35a17maykkd88hb790fv8-test-file-0.txt1661=== NAME TestClientWithDependencies1662 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies3275652665/001/store/2wkbdir5il55z9vhfyp4hk6fn570k3kv-test-script16632026/10/11 05:55:16 INFO Received uploads request method=POST path=/api/pending_closures16642026/10/11 05:55:16 INFO Received uploads request method=POST path=/api/pending_closures16652026/10/11 05:55:16 INFO Received push request method=POST path=/api/pushes16662026/10/11 05:55:16 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16672026/10/11 05:55:16 INFO Uploading fnwqd77q83nmcw2lpspa6dr7q901n2rz-shared-dep (136B)1668=== NAME TestClientMultipleUploads16692026/10/11 05:55:16 INFO Uploading 5b43wypq26j4p3rk30fcpwa75ig8a6vl-b (216B)1670 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads2002990845/001/store/9hprw1nnkvjsm4yyqfb8nxdlpcnqn7sp-test-file-1.txt16712026/10/11 05:55:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16722026/10/11 05:55:16 INFO Uploading lxqy4a2qzaai3r7w8iqp0bma681q6i4q-ca-test (144B)16732026/10/11 05:55:16 WARN Failed to register uploaded object key=xs5gkl9i9lg6qq6r3bcp3bnq96w1hwx9.ls error="server returned 404: 404 page not found\n"16742026/10/11 05:55:16 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16752026/10/11 05:55:16 WARN Failed to register uploaded object key=nar/1pf3p5hq7ycgrx22nmjbdx5rrnizrjasg3khaabqc222bjr9b5ri.nar.zst error="server returned 404: 404 page not found\n"16762026/10/11 05:55:16 WARN Failed to register uploaded object key=5b43wypq26j4p3rk30fcpwa75ig8a6vl.ls error="server returned 404: 404 page not found\n"16772026/10/11 05:55:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16782026/10/11 05:55:16 WARN Failed to register uploaded object key=fnwqd77q83nmcw2lpspa6dr7q901n2rz.ls error="server returned 404: 404 page not found\n"16792026/10/11 05:55:16 INFO Signed narinfos id=1 count=216802026/10/11 05:55:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16812026/10/11 05:55:16 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16822026/10/11 05:55:16 INFO Signed narinfos id=2 count=216832026/10/11 05:55:16 WARN Failed to register uploaded object key=lxqy4a2qzaai3r7w8iqp0bma681q6i4q.ls error="server returned 404: 404 page not found\n"16842026/10/11 05:55:16 INFO Uploading 4 narinfos16852026/10/11 05:55:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16862026/10/11 05:55:16 WARN Failed to register uploaded object key=log/s9fz2vny9vvapnfhx7ji928qgkbp2rfa-ca-test.drv error="server returned 404: 404 page not found\n"1687=== NAME TestClientIntegration1688 client_integration_test.go:286: Created store path: /build/TestClientIntegration3121620348/002/store/lj0pd8vav8nn38lha221j9jbk6n4z7wd-test-file.txt16892026/10/11 05:55:16 INFO Signed narinfos id=1 count=116902026/10/11 05:55:16 INFO Uploading 1 narinfos16912026/10/11 05:55:16 WARN Failed to register uploaded object key=fnwqd77q83nmcw2lpspa6dr7q901n2rz.narinfo error="server returned 404: 404 page not found\n"16922026/10/11 05:55:16 INFO Received complete push request method=POST path=/api/pushes/1/complete16932026/10/11 05:55:16 WARN Failed to register uploaded object key=5b43wypq26j4p3rk30fcpwa75ig8a6vl.narinfo error="server returned 404: 404 page not found\n"16942026/10/11 05:55:16 WARN Failed to register uploaded object key=lxqy4a2qzaai3r7w8iqp0bma681q6i4q.narinfo error="server returned 404: 404 page not found\n"16952026/10/11 05:55:16 WARN Failed to register uploaded object key=xs5gkl9i9lg6qq6r3bcp3bnq96w1hwx9.narinfo error="server returned 404: 404 page not found\n"16962026/10/11 05:55:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16972026/10/11 05:55:16 WARN Failed to register uploaded object key=fnwqd77q83nmcw2lpspa6dr7q901n2rz.narinfo error="server returned 404: 404 page not found\n"1698--- PASS: TestService_ReadAuthMiddleware (0.40s)1699=== CONT TestServerTLSConfig/no_client_CA1700=== CONT TestServerTLSConfig/not_a_PEM_file1701=== CONT TestServerTLSConfig/missing_CA_file1702--- PASS: TestServerTLSConfig (0.00s)1703 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1704 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1705 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1706=== CONT TestGCEndsOnShutdown/before_the_run1707=== NAME TestClientWithDependencies1708 client_integration_test.go:615: Found 1 dependencies (including self)17092026/10/11 05:55:16 INFO Completed upload id=1 objects=6 duration=8.236674ms17102026/10/11 05:55:16 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17112026/10/11 05:55:16 INFO Completed push id=1 objects=4 duration=10.38816ms17122026/10/11 05:55:16 INFO Upload complete. (100ms)17132026/10/11 05:55:16 INFO Completed upload id=2 objects=6 duration=1.795486ms17142026/10/11 05:55:16 INFO Upload complete. (83ms)1715=== NAME TestClientFallsBackToClosures1716 client_pushes_test.go:112: Retrieved narinfo from S3:1717 StorePath: /build/TestClientFallsBackToClosures828735100/001/store/fnwqd77q83nmcw2lpspa6dr7q901n2rz-shared-dep1718 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1719 Compression: zstd1720 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821721 NarSize: 1361722 References: 1723 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1724=== NAME TestClientCADerivations1725 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations4275305078/001/store/lxqy4a2qzaai3r7w8iqp0bma681q6i4q-ca-test1726 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1727 Compression: zstd1728 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1729 NarSize: 1441730 References: 1731 Deriver: /build/TestClientCADerivations4275305078/001/store/s9fz2vny9vvapnfhx7ji928qgkbp2rfa-ca-test.drv1732 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1733 client_ca_test.go:185: Checking for realisation files in S3...1734=== NAME TestClientMultipleUploads1735 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads2002990845/001/store/sjyhnx028vx0617ghks50vkalbym1vkb-test-file-2.txt1736=== NAME TestClientCADerivations1737 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1738 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1739=== NAME TestClientFallsBackToClosures1740 client_pushes_test.go:112: Retrieved narinfo from S3:1741 StorePath: /build/TestClientFallsBackToClosures828735100/001/store/xs5gkl9i9lg6qq6r3bcp3bnq96w1hwx9-a1742 URL: nar/1pf3p5hq7ycgrx22nmjbdx5rrnizrjasg3khaabqc222bjr9b5ri.nar.zst1743 Compression: zstd1744 NarHash: sha256:1pf3p5hq7ycgrx22nmjbdx5rrnizrjasg3khaabqc222bjr9b5ri1745 NarSize: 2161746 References: /build/TestClientFallsBackToClosures828735100/001/store/fnwqd77q83nmcw2lpspa6dr7q901n2rz-shared-dep1747 CA: text:sha256:1ijpcsfppwphhxzi2hwqzin3z86kbylb4sddymrcsj20gl97sj0y1748 client_pushes_test.go:112: Retrieved narinfo from S3:1749 StorePath: /build/TestClientFallsBackToClosures828735100/001/store/5b43wypq26j4p3rk30fcpwa75ig8a6vl-b1750 URL: nar/1pf3p5hq7ycgrx22nmjbdx5rrnizrjasg3khaabqc222bjr9b5ri.nar.zst1751 Compression: zstd1752 NarHash: sha256:1pf3p5hq7ycgrx22nmjbdx5rrnizrjasg3khaabqc222bjr9b5ri1753 NarSize: 2161754 References: /build/TestClientFallsBackToClosures828735100/001/store/fnwqd77q83nmcw2lpspa6dr7q901n2rz-shared-dep1755 CA: text:sha256:1ijpcsfppwphhxzi2hwqzin3z86kbylb4sddymrcsj20gl97sj0y1756=== NAME TestPinProtectsFromGC1757 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC3236372972/001/store/1mnvkddckkkbsizj2s1smkscds8lm84j-pinned-file.txt1758 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC3236372972/001/store/fywx217wsvyj9q6bxzahngnl4f0d4lah-unpinned-file.txt1759--- PASS: TestClientFallsBackToClosures (0.63s)1760=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1761=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1762=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1763=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1764=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1765=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1766=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1767=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1768=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1769=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete17702026/10/11 05:55:16 INFO Received push request method=POST path=/api/pushes17712026/10/11 05:55:16 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17722026/10/11 05:55:16 WARN mTLS auth: bound subjects configured but subject DN unavailable17732026/10/11 05:55:16 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1774--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.32s)1775=== CONT TestResolveDBConnectionString/flag_wins1776=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1777=== CONT TestResolveDBConnectionString/nothing_configured1778=== CONT TestResolveDBConnectionString/missing_file_is_an_error1779=== CONT TestResolveDBConnectionString/file_when_flag_empty1780=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1781--- PASS: TestResolveDBConnectionString (0.00s)1782 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1783 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1784 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1785 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1786 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)17872026/10/11 05:55:16 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17882026/10/11 05:55:16 INFO Uploading bpynryzwyl2n5gg3yl4p1gx8k2706ifi-b (208B)17892026/10/11 05:55:16 INFO Uploading 2ppzhs8kd5sa2hcbpc7kl40xjs61x6vn-shared-dep (136B)17902026/10/11 05:55:16 WARN Failed to register uploaded object key=nar/1pk9bcfvy21j5c9gn8x6y9ngzikypbwjsrx39agvdfnfsq7s6msa.nar.zst error="server returned 404: 404 page not found\n"17912026/10/11 05:55:16 WARN Failed to register uploaded object key=0v2bkr68l9zhslb8zqhwsi4f91biy7zs.ls error="server returned 404: 404 page not found\n"17922026/10/11 05:55:16 WARN Failed to register uploaded object key=bpynryzwyl2n5gg3yl4p1gx8k2706ifi.ls error="server returned 404: 404 page not found\n"17932026/10/11 05:55:16 WARN Failed to register uploaded object key=2ppzhs8kd5sa2hcbpc7kl40xjs61x6vn.ls error="server returned 404: 404 page not found\n"17942026/10/11 05:55:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17952026/10/11 05:55:16 INFO Signed narinfos id=1 count=317962026/10/11 05:55:16 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17972026/10/11 05:55:16 INFO Uploading 3 narinfos17982026/10/11 05:55:16 WARN Failed to register uploaded object key=bpynryzwyl2n5gg3yl4p1gx8k2706ifi.narinfo error="server returned 404: 404 page not found\n"17992026/10/11 05:55:16 INFO Received push request method=POST path=/api/pushes18002026/10/11 05:55:16 WARN Failed to register uploaded object key=0v2bkr68l9zhslb8zqhwsi4f91biy7zs.narinfo error="server returned 404: 404 page not found\n"18012026/10/11 05:55:16 INFO Received complete push request method=POST path=/api/pushes/1/complete18022026/10/11 05:55:16 WARN Failed to register uploaded object key=2ppzhs8kd5sa2hcbpc7kl40xjs61x6vn.narinfo error="server returned 404: 404 page not found\n"1803--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.33s)1804=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check18052026/10/11 05:55:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18062026/10/11 05:55:16 INFO Uploading lj0pd8vav8nn38lha221j9jbk6n4z7wd-test-file.txt (152B)18072026/10/11 05:55:16 INFO Completed push id=1 objects=8 duration=6.673547ms18082026/10/11 05:55:16 INFO Upload complete. (70ms)1809=== NAME TestClientPushesUseOnePush1810 client_pushes_test.go:97: Retrieved narinfo from S3:1811 StorePath: /build/TestClientPushesUseOnePush971767441/001/store/2ppzhs8kd5sa2hcbpc7kl40xjs61x6vn-shared-dep1812 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1813 Compression: zstd1814 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821815 NarSize: 1361816 References: 1817 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n18182026/10/11 05:55:16 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"18192026/10/11 05:55:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18202026/10/11 05:55:16 WARN Failed to register uploaded object key=lj0pd8vav8nn38lha221j9jbk6n4z7wd.ls error="server returned 404: 404 page not found\n"18212026/10/11 05:55:16 INFO Signed narinfos id=1 count=118222026/10/11 05:55:16 INFO Uploading 1 narinfos1823 client_pushes_test.go:97: Retrieved narinfo from S3:1824 StorePath: /build/TestClientPushesUseOnePush971767441/001/store/0v2bkr68l9zhslb8zqhwsi4f91biy7zs-a1825 URL: nar/1pk9bcfvy21j5c9gn8x6y9ngzikypbwjsrx39agvdfnfsq7s6msa.nar.zst1826 Compression: zstd1827 NarHash: sha256:1pk9bcfvy21j5c9gn8x6y9ngzikypbwjsrx39agvdfnfsq7s6msa1828 NarSize: 2081829 References: /build/TestClientPushesUseOnePush971767441/001/store/2ppzhs8kd5sa2hcbpc7kl40xjs61x6vn-shared-dep18302026/10/11 05:55:16 INFO Received push request method=POST path=/api/pushes1831 CA: text:sha256:0znyckmk6fn65mcvwsgj1fa8sq5d5knpgizzqlw90k21n8xf004m18322026/10/11 05:55:16 INFO Received complete push request method=POST path=/api/pushes/1/complete1833 client_pushes_test.go:97: Retrieved narinfo from S3:18342026/10/11 05:55:16 WARN Failed to register uploaded object key=lj0pd8vav8nn38lha221j9jbk6n4z7wd.narinfo error="server returned 404: 404 page not found\n"1835 StorePath: /build/TestClientPushesUseOnePush971767441/001/store/bpynryzwyl2n5gg3yl4p1gx8k2706ifi-b1836 URL: nar/1pk9bcfvy21j5c9gn8x6y9ngzikypbwjsrx39agvdfnfsq7s6msa.nar.zst1837 Compression: zstd1838 NarHash: sha256:1pk9bcfvy21j5c9gn8x6y9ngzikypbwjsrx39agvdfnfsq7s6msa1839 NarSize: 2081840 References: /build/TestClientPushesUseOnePush971767441/001/store/2ppzhs8kd5sa2hcbpc7kl40xjs61x6vn-shared-dep1841 CA: text:sha256:0znyckmk6fn65mcvwsgj1fa8sq5d5knpgizzqlw90k21n8xf004m18422026/10/11 05:55:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18432026/10/11 05:55:16 INFO Uploading 2wkbdir5il55z9vhfyp4hk6fn570k3kv-test-script (136B)1844--- PASS: TestClientPushesUseOnePush (0.67s)1845=== CONT TestClientErrorHandling/InvalidStorePath18462026/10/11 05:55:16 WARN Failed to register uploaded object key=2wkbdir5il55z9vhfyp4hk6fn570k3kv.ls error="server returned 404: 404 page not found\n"18472026/10/11 05:55:16 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"18482026/10/11 05:55:16 WARN Failed to register uploaded object key=log/vrpr0864kz7bqfbv0c8z7ncpilbyjq4v-test-script.drv error="server returned 404: 404 page not found\n"18492026/10/11 05:55:16 INFO Completed push id=1 objects=3 duration=9.766851ms18502026/10/11 05:55:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18512026/10/11 05:55:16 INFO Upload complete. (65ms)18522026/10/11 05:55:16 INFO Signed narinfos id=1 count=118532026/10/11 05:55:16 INFO Uploading 1 narinfos18542026/10/11 05:55:16 INFO Received push request method=POST path=/api/pushes18552026/10/11 05:55:16 INFO Received complete push request method=POST path=/api/pushes/1/complete18562026/10/11 05:55:16 WARN Failed to register uploaded object key=2wkbdir5il55z9vhfyp4hk6fn570k3kv.narinfo error="server returned 404: 404 page not found\n"18572026/10/11 05:55:16 INFO Received push request method=POST path=/api/pushes18582026/10/11 05:55:16 INFO Received uploads request method=POST path=/api/pending_closures18592026/10/11 05:55:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18602026/10/11 05:55:16 INFO Uploading 1mnvkddckkkbsizj2s1smkscds8lm84j-pinned-file.txt (128B)18612026/10/11 05:55:16 INFO Completed push id=1 objects=4 duration=14.022672ms18622026/10/11 05:55:16 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)18632026/10/11 05:55:16 INFO Uploading 9hprw1nnkvjsm4yyqfb8nxdlpcnqn7sp-test-file-1.txt (160B)18642026/10/11 05:55:16 INFO Uploading sjyhnx028vx0617ghks50vkalbym1vkb-test-file-2.txt (160B)18652026/10/11 05:55:16 INFO Uploading czrskam9brw35a17maykkd88hb790fv8-test-file-0.txt (160B)18662026/10/11 05:55:16 INFO Upload complete. (73ms)1867=== NAME TestClientWithDependencies1868 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3275652665/001/store) requires matching store prefix18692026/10/11 05:55:16 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"18702026/10/11 05:55:16 WARN Failed to register uploaded object key=9hprw1nnkvjsm4yyqfb8nxdlpcnqn7sp.ls error="server returned 404: 404 page not found\n"18712026/10/11 05:55:16 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"18722026/10/11 05:55:16 WARN Failed to register uploaded object key=1mnvkddckkkbsizj2s1smkscds8lm84j.ls error="server returned 404: 404 page not found\n"18732026/10/11 05:55:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18742026/10/11 05:55:16 WARN Failed to register uploaded object key=czrskam9brw35a17maykkd88hb790fv8.ls error="server returned 404: 404 page not found\n"18752026/10/11 05:55:16 INFO Signed narinfos id=1 count=118762026/10/11 05:55:16 INFO Uploading 1 narinfos18772026/10/11 05:55:16 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"18782026/10/11 05:55:16 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"18792026/10/11 05:55:16 WARN Failed to register uploaded object key=sjyhnx028vx0617ghks50vkalbym1vkb.ls error="server returned 404: 404 page not found\n"18802026/10/11 05:55:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18812026/10/11 05:55:16 INFO Signed narinfos id=1 count=318822026/10/11 05:55:16 INFO Uploading 3 narinfos1883--- PASS: TestClientWithDependencies (0.70s)18842026/10/11 05:55:16 INFO Received complete push request method=POST path=/api/pushes/1/complete1885=== CONT TestClientErrorHandling/ServerNotAvailable18862026/10/11 05:55:16 WARN Failed to register uploaded object key=1mnvkddckkkbsizj2s1smkscds8lm84j.narinfo error="server returned 404: 404 page not found\n"18872026/10/11 05:55:16 WARN Failed to register uploaded object key=9hprw1nnkvjsm4yyqfb8nxdlpcnqn7sp.narinfo error="server returned 404: 404 page not found\n"18882026/10/11 05:55:16 WARN Failed to register uploaded object key=czrskam9brw35a17maykkd88hb790fv8.narinfo error="server returned 404: 404 page not found\n"18892026/10/11 05:55:16 INFO Received complete push request method=POST path=/api/pushes/1/complete18902026/10/11 05:55:16 WARN Failed to register uploaded object key=sjyhnx028vx0617ghks50vkalbym1vkb.narinfo error="server returned 404: 404 page not found\n"18912026/10/11 05:55:16 INFO Received push request method=POST path=/api/pushes18922026/10/11 05:55:16 INFO All 1 paths already cached1893=== NAME TestClientIntegration1894 client_integration_test.go:312: Retrieved narinfo from S3:1895 StorePath: /build/TestClientIntegration3121620348/002/store/lj0pd8vav8nn38lha221j9jbk6n4z7wd-test-file.txt1896 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst18972026/10/11 05:55:16 INFO Completed push id=1 objects=3 duration=15.09671ms1898 Compression: zstd1899 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11900 NarSize: 15219012026/10/11 05:55:16 INFO Upload complete. (79ms)1902 References: 1903 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11904=== NAME TestClientCADerivations1905 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1906 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1907 error: binary cache 's3://bucket77?endpoint=http://localhost:37743®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations4275305078/001/store'19082026/10/11 05:55:16 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)1909 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 119102026/10/11 05:55:16 INFO Uploading x7mwzsx2wmi2m3h13wzjwbkj7k38i50d-shared-dep (136B)19112026/10/11 05:55:16 INFO Uploading vl9402gaf6g0pxdzp1cmnc8b9kdkan13-top (224B)1912=== NAME TestClientIntegration1913 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1914 client_integration_test.go:313: Decompressed .ls content (64 bytes):1915 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1916 client_integration_test.go:316: Testing garbage collection...19172026/10/11 05:55:16 INFO Completed push id=1 objects=9 duration=17.232747ms19182026/10/11 05:55:16 INFO Upload complete. (91ms)1919=== NAME TestClientMultipleUploads1920 client_integration_test.go:369: Uploaded 3 paths in 126.303135ms19212026/10/11 05:55:16 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1922--- PASS: TestClientCADerivations (0.90s)1923=== CONT TestClientErrorHandling/InvalidAuthToken19242026/10/11 05:55:16 WARN Failed to register uploaded object key=vl9402gaf6g0pxdzp1cmnc8b9kdkan13.ls error="server returned 404: 404 page not found\n"19252026/10/11 05:55:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19262026/10/11 05:55:16 INFO Starting cleanup of old closures method=DELETE path=/api/closures19272026/10/11 05:55:16 WARN Failed to register uploaded object key=x7mwzsx2wmi2m3h13wzjwbkj7k38i50d.ls error="server returned 404: 404 page not found\n"19282026/10/11 05:55:16 INFO Garbage collection started19292026/10/11 05:55:16 WARN Failed to register uploaded object key=nar/16sk8yvj3zbb3i9nmqfcybnfs332ai03r25kbrqymh313wix9kbk.nar.zst error="server returned 404: 404 page not found\n"19302026/10/11 05:55:16 INFO Signed narinfos id=1 count=219312026/10/11 05:55:16 INFO Uploading 2 narinfos19322026/10/11 05:55:16 WARN Failed to register uploaded object key=x7mwzsx2wmi2m3h13wzjwbkj7k38i50d.narinfo error="server returned 404: 404 page not found\n"19332026/10/11 05:55:16 INFO Received complete push request method=POST path=/api/pushes/1/complete19342026/10/11 05:55:16 WARN Failed to register uploaded object key=vl9402gaf6g0pxdzp1cmnc8b9kdkan13.narinfo error="server returned 404: 404 page not found\n"19352026/10/11 05:55:16 INFO Aborted multipart uploads count=0 kept=01936--- PASS: TestClientMultipleUploads (0.74s)1937=== CONT TestCacheConfigHandler/full_config,_no_issuer1938=== CONT TestCacheConfigHandler/no_signing_keys1939=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1940=== CONT TestCacheConfigHandler/no_cache_url_configured1941--- PASS: TestCacheConfigHandler (0.00s)1942 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1943 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1944 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1945 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1946=== CONT TestService_RequireScope_OIDC/builder_may_write1947=== CONT TestService_RequireScope_OIDC/reader_may_read1948=== CONT TestService_RequireScope_OIDC/static_token_may_write1949=== CONT TestService_RequireScope_OIDC/static_token_may_admin1950=== CONT TestService_RequireScope_OIDC/reader_may_not_write1951=== CONT TestService_RequireScope_OIDC/ops_may_not_write1952=== CONT TestService_RequireScope_OIDC/ops_may_admin1953=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1954=== CONT TestService_RequireScope_OIDC/writer_implies_read1955=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19562026/10/11 05:55:16 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]1957=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1958=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1959=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1960=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1961=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1962--- PASS: TestService_RequireScope_OIDC (0.50s)1963 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1964 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1965 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1966 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1967 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1968 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1969 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1970 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1971 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1972 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1973 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1974 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1975 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1976 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)19772026/10/11 05:55:16 WARN Force mode enabled - objects will be deleted immediately without grace period19782026/10/11 05:55:16 INFO Completed push id=1 objects=6 duration=10.850749ms19792026/10/11 05:55:16 INFO Upload complete. (176ms)1980=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1981=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19822026/10/11 05:55:16 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]1983=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1984=== NAME TestClientSharedPathCommittedMidPush1985 client_integration_test.go:680: Retrieved narinfo from S3:1986 StorePath: /build/TestClientSharedPathCommittedMidPush2611507409/001/store/x7mwzsx2wmi2m3h13wzjwbkj7k38i50d-shared-dep1987 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1988 Compression: zstd1989 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821990 NarSize: 1361991 References: 1992 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n19932026/10/11 05:55:16 WARN Authentication failed token_preview=eyJhbGciOi...EXDDCGv91A token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1994 client_integration_test.go:680: Retrieved narinfo from S3:1995 StorePath: /build/TestClientSharedPathCommittedMidPush2611507409/001/store/vl9402gaf6g0pxdzp1cmnc8b9kdkan13-top1996 URL: nar/16sk8yvj3zbb3i9nmqfcybnfs332ai03r25kbrqymh313wix9kbk.nar.zst1997 Compression: zstd1998 NarHash: sha256:16sk8yvj3zbb3i9nmqfcybnfs332ai03r25kbrqymh313wix9kbk1999 NarSize: 2242000 References: /build/TestClientSharedPathCommittedMidPush2611507409/001/store/x7mwzsx2wmi2m3h13wzjwbkj7k38i50d-shared-dep2001 CA: text:sha256:1xgx50z7ncv6k1azv0p84c6ax1llc75ngf80zrllcqzjqnb3ccls2002--- PASS: TestService_AuthMiddleware_OIDC (0.41s)2003 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2004 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2005 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2006 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2007--- PASS: TestClientSharedPathCommittedMidPush (0.72s)20082026/10/11 05:55:16 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20092026/10/11 05:55:16 INFO Received push request method=POST path=/api/pushes20102026/10/11 05:55:16 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=020112026/10/11 05:55:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20122026/10/11 05:55:16 INFO Uploading fywx217wsvyj9q6bxzahngnl4f0d4lah-unpinned-file.txt (128B)20132026/10/11 05:55:16 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"20142026/10/11 05:55:16 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign20152026/10/11 05:55:16 WARN Failed to register uploaded object key=fywx217wsvyj9q6bxzahngnl4f0d4lah.ls error="server returned 404: 404 page not found\n"20162026/10/11 05:55:16 INFO Vacuumed table table=pending_closures20172026/10/11 05:55:16 INFO Signed narinfos id=2 count=120182026/10/11 05:55:16 INFO Uploading 1 narinfos20192026/10/11 05:55:16 INFO Vacuumed table table=pending_objects20202026/10/11 05:55:16 INFO Vacuumed table table=multipart_uploads20212026/10/11 05:55:16 INFO Received complete push request method=POST path=/api/pushes/2/complete20222026/10/11 05:55:16 WARN Failed to register uploaded object key=fywx217wsvyj9q6bxzahngnl4f0d4lah.narinfo error="server returned 404: 404 page not found\n"20232026/10/11 05:55:16 INFO Vacuumed table table=closures20242026/10/11 05:55:16 INFO Completed push id=2 objects=3 duration=3.385483ms20252026/10/11 05:55:16 INFO Upload complete. (59ms)20262026/10/11 05:55:16 INFO Vacuumed table table=objects20272026/10/11 05:55:16 INFO Starting cleanup of old closures method=DELETE path=/api/closures20282026/10/11 05:55:16 INFO Garbage collection started20292026/10/11 05:55:16 INFO Aborted multipart uploads count=0 kept=020302026/10/11 05:55:16 WARN Force mode enabled - objects will be deleted immediately without grace period20312026/10/11 05:55:16 INFO Aborted multipart uploads count=0 kept=020322026/10/11 05:55:16 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:37743/bucket95/?delete=\": context canceled"20332026/10/11 05:55:16 WARN Force mode enabled - objects will be deleted immediately without grace period20342026/10/11 05:55:16 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=020352026/10/11 05:55:16 WARN Request failed, retrying attempt=2 backoff=216.680184ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20362026/10/11 05:55:16 INFO Vacuumed table table=pending_closures20372026/10/11 05:55:16 INFO Vacuumed table table=pending_objects20382026/10/11 05:55:16 INFO Vacuumed table table=multipart_uploads20392026/10/11 05:55:16 INFO Vacuumed table table=closures20402026/10/11 05:55:16 INFO Aborted multipart uploads count=0 kept=020412026/10/11 05:55:16 INFO Vacuumed table table=objects20422026/10/11 05:55:16 WARN Force mode enabled - objects will be deleted immediately without grace period2043--- PASS: TestGCEndsOnShutdown (0.00s)2044 --- PASS: TestGCEndsOnShutdown/before_the_run (0.29s)2045 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.33s)2046 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.37s)20472026/10/11 05:55:16 INFO Received uploads request method=POST path=/api/pending_closures20482026/10/11 05:55:16 INFO Aborted multipart uploads count=0 kept=020492026/10/11 05:55:16 WARN Force mode enabled - objects will be deleted immediately without grace period20502026/10/11 05:55:16 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=020512026/10/11 05:55:16 INFO Vacuumed table table=pending_closures20522026/10/11 05:55:16 INFO Vacuumed table table=pending_objects20532026/10/11 05:55:16 INFO Vacuumed table table=multipart_uploads20542026/10/11 05:55:16 INFO Vacuumed table table=closures20552026/10/11 05:55:16 INFO Vacuumed table table=objects20562026/10/11 05:55:16 INFO Received uploads request method=POST path=/api/pending_closures20572026/10/11 05:55:16 INFO Aborted multipart uploads count=0 kept=020582026/10/11 05:55:16 WARN Force mode enabled - objects will be deleted immediately without grace period20592026/10/11 05:55:16 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=020602026/10/11 05:55:16 INFO Vacuumed table table=pending_closures20612026/10/11 05:55:16 INFO Vacuumed table table=pending_objects20622026/10/11 05:55:16 INFO Vacuumed table table=multipart_uploads20632026/10/11 05:55:16 INFO Vacuumed table table=closures20642026/10/11 05:55:16 INFO Vacuumed table table=objects2065--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2066 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.39s)2067 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.42s)2068=== NAME TestOrphanedObjectsGCStressTest2069 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains20702026/10/11 05:55:17 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2071 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion2072--- PASS: TestUploadHandlersRejectOversizedBody (0.21s)2073 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)2074 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)2075 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.77s)20762026/10/11 05:55:17 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20772026/10/11 05:55:17 WARN Request failed, retrying attempt=3 backoff=386.190758ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20782026/10/11 05:55:17 INFO lead: released remote=192.0.2.1:12342079--- PASS: TestLeadEndsOnShutdown (1.50s)2080--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2081 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.73s)2082 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.81s)2083--- PASS: TestDeleteClosuresRacingPins (1.51s)20842026/10/11 05:55:17 INFO lead: released remote=192.0.2.1:123420852026/10/11 05:55:17 WARN Rate limiter enabled after throttle name=s3-test rate=520862026/10/11 05:55:17 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2087=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2088 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102089 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002090--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (3.57s)20912026/10/11 05:55:17 INFO lead: acquired remote=192.0.2.1:12342092--- PASS: TestPendingClosureWriteTimeout (0.11s)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.16s)2097=== NAME TestOrphanedObjectsGCStressTest2098 orphaned_objects_gc_test.go:503: Stress test completed successfully:2099 orphaned_objects_gc_test.go:504: - Active objects preserved: 202100 orphaned_objects_gc_test.go:505: - Objects deleted: 2102101 orphaned_objects_gc_test.go:506: - Total GC'd: 2102102--- PASS: TestOrphanedObjectsGCStressTest (2.76s)21032026/10/11 05:55:17 WARN Request failed, retrying attempt=4 backoff=769.243631ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21042026/10/11 05:55:18 WARN Request failed, retrying attempt=5 backoff=1.541925696s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21052026/10/11 05:55:18 INFO lead: released remote=192.0.2.1:12342106--- PASS: TestLeadElectsOneAndHandsOver (2.76s)21072026/10/11 05:55:18 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02108=== NAME TestClientIntegration2109 client_integration_test.go:323: Objects in database after GC:2110 client_integration_test.go:323: Successfully deleted all objects with GC --force2111--- PASS: TestClientIntegration (2.72s)21122026/10/11 05:55:18 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=021132026/10/11 05:55:18 INFO Received create pin request method=POST path=/api/pins/myapp21142026/10/11 05:55:18 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3236372972/001/store/1mnvkddckkkbsizj2s1smkscds8lm84j-pinned-file.txt narinfo_key=1mnvkddckkkbsizj2s1smkscds8lm84j.narinfo21152026/10/11 05:55:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures21162026/10/11 05:55:18 INFO Garbage collection started21172026/10/11 05:55:18 INFO Aborted multipart uploads count=0 kept=021182026/10/11 05:55:18 WARN Force mode enabled - objects will be deleted immediately without grace period21192026/10/11 05:55:18 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=021202026/10/11 05:55:18 INFO Vacuumed table table=pending_closures21212026/10/11 05:55:18 INFO Vacuumed table table=pending_objects21222026/10/11 05:55:18 INFO Vacuumed table table=multipart_uploads21232026/10/11 05:55:18 INFO Vacuumed table table=closures21242026/10/11 05:55:18 INFO Vacuumed table table=objects2125--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.83s)21262026/10/11 05:55:19 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-config21272026/10/11 05:55:19 WARN Request failed, retrying attempt=2 backoff=183.471668ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21282026/10/11 05:55:20 WARN Request failed, retrying attempt=3 backoff=402.351664ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21292026/10/11 05:55:20 WARN Request failed, retrying attempt=4 backoff=807.992397ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2130=== NAME TestPinProtectsFromGC2131 client_integration_test.go:840: Pin successfully protected closure from garbage collection2132--- PASS: TestPinProtectsFromGC (4.85s)2133--- PASS: TestConnectWaitsForAPeerMigration (5.17s)21342026/10/11 05:55:21 WARN Request failed, retrying attempt=5 backoff=1.473218818s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21352026/10/11 05:55:21 INFO Aborted multipart uploads count=1 kept=021362026/10/11 05:55:21 INFO Received cleanup request method=DELETE path=/api/pending_closures21372026/10/11 05:55:21 INFO Aborted multipart uploads count=1 kept=02138--- PASS: TestPendingCleanupUsesOneCutoff (6.64s)21392026/10/11 05:55:22 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"21402026/10/11 05:55:22 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-config21412026/10/11 05:55:22 WARN Request failed, retrying attempt=2 backoff=211.762356ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21422026/10/11 05:55:23 WARN Request failed, retrying attempt=3 backoff=437.818757ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21432026/10/11 05:55:23 WARN Request failed, retrying attempt=4 backoff=878.820642ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21442026/10/11 05:55:24 WARN Request failed, retrying attempt=5 backoff=1.449878179s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21452026/10/11 05:55:25 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_closures21462026/10/11 05:55:26 WARN Request failed, retrying attempt=2 backoff=191.601416ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21472026/10/11 05:55:26 WARN Request failed, retrying attempt=3 backoff=418.786701ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21482026/10/11 05:55:26 WARN Request failed, retrying attempt=4 backoff=739.885705ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21492026/10/11 05:55:27 WARN Request failed, retrying attempt=5 backoff=1.671599167s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2150--- PASS: TestClientErrorHandling (0.00s)2151 --- PASS: TestClientErrorHandling/InvalidStorePath (0.36s)2152 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.35s)2153 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.42s)2154PASS2155{"timestamp":"2026-10-11T05:55:29.041579158Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:39942","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(387)"}21562026-10-11 05:55:29.417 UTC [128] LOG: received smart shutdown request21572026-10-11 05:55:29.422 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 121582026-10-11 05:55:29.437 UTC [133] LOG: shutting down21592026-10-11 05:55:29.438 UTC [133] LOG: checkpoint starting: shutdown immediate21602026-10-11 05:55:31.250 UTC [133] LOG: checkpoint complete: wrote 10688 buffers (65.2%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.260 s, sync=1.486 s, total=1.814 s; sync files=34045, longest=0.024 s, average=0.001 s; distance=531567 kB, estimate=531567 kB; lsn=0/21E81A00, redo lsn=0/21E81A0021612026-10-11 05:55:31.339 UTC [128] LOG: database system is shut down2162Running OIDC tests...2163=== RUN TestAudienceForIssuer2164=== PAUSE TestAudienceForIssuer2165=== RUN TestGlobMatch2166=== PAUSE TestGlobMatch2167=== RUN TestValidateToken_ValidToken2168=== PAUSE TestValidateToken_ValidToken2169=== RUN TestValidateToken_WrongAudience2170=== PAUSE TestValidateToken_WrongAudience2171=== RUN TestValidateToken_Expired2172=== PAUSE TestValidateToken_Expired2173=== RUN TestValidateToken_BoundClaimsMismatch2174=== PAUSE TestValidateToken_BoundClaimsMismatch2175=== RUN TestValidateToken_BoundSubjectMismatch2176=== PAUSE TestValidateToken_BoundSubjectMismatch2177=== RUN TestValidateToken_MultipleProviders2178=== PAUSE TestValidateToken_MultipleProviders2179=== RUN TestValidateToken_NoMatchingProvider2180=== PAUSE TestValidateToken_NoMatchingProvider2181=== RUN TestValidateToken_KubernetesServiceAccount2182=== PAUSE TestValidateToken_KubernetesServiceAccount2183=== RUN TestNewValidator_KubernetesRequiresCA2184=== PAUSE TestNewValidator_KubernetesRequiresCA2185=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2186=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2187=== RUN TestPins_ReservedForMatchingRule2188=== PAUSE TestPins_ReservedForMatchingRule2189=== RUN TestPins_TopLevelShorthand2190=== PAUSE TestPins_TopLevelShorthand2191=== RUN TestPins_ConfigValidation2192=== PAUSE TestPins_ConfigValidation2193=== RUN TestScopes_LegacyProviderDefaultsToWrite2194=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2195=== RUN TestScopes_Rules2196=== PAUSE TestScopes_Rules2197=== RUN TestScopes_ConfigValidation2198=== PAUSE TestScopes_ConfigValidation2199=== CONT TestAudienceForIssuer2200=== CONT TestValidateToken_KubernetesServiceAccount2201=== CONT TestPins_TopLevelShorthand2202=== CONT TestPins_ReservedForMatchingRule2203--- PASS: TestAudienceForIssuer (0.00s)2204=== CONT TestValidateToken_NoMatchingProvider2205=== CONT TestScopes_Rules2206=== CONT TestValidateToken_MultipleProviders2207=== CONT TestValidateToken_BoundSubjectMismatch2208=== CONT TestValidateToken_BoundClaimsMismatch2209=== CONT TestPins_ConfigValidation2210=== CONT TestValidateToken_Expired2211=== CONT TestValidateToken_WrongAudience2212=== CONT TestValidateToken_ValidToken2213=== CONT TestScopes_ConfigValidation2214--- PASS: TestPins_ConfigValidation (0.00s)2215=== CONT TestScopes_LegacyProviderDefaultsToWrite2216=== CONT TestGlobMatch2217=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2218=== RUN TestGlobMatch/foo_foo2219=== PAUSE TestGlobMatch/foo_foo2220=== RUN TestGlobMatch/foo_bar2221=== PAUSE TestGlobMatch/foo_bar2222=== RUN TestGlobMatch/*_2223=== PAUSE TestGlobMatch/*_2224=== CONT TestNewValidator_KubernetesRequiresCA2225--- PASS: TestScopes_ConfigValidation (0.00s)2226=== RUN TestGlobMatch/*_anything2227=== PAUSE TestGlobMatch/*_anything2228=== RUN TestGlobMatch/foo*_foo2229=== PAUSE TestGlobMatch/foo*_foo2230=== RUN TestGlobMatch/foo*_foobar2231=== PAUSE TestGlobMatch/foo*_foobar2232=== RUN TestGlobMatch/foo*_bar2233=== PAUSE TestGlobMatch/foo*_bar2234=== RUN TestGlobMatch/*bar_bar2235=== PAUSE TestGlobMatch/*bar_bar2236=== RUN TestGlobMatch/*bar_foobar2237=== PAUSE TestGlobMatch/*bar_foobar2238=== RUN TestGlobMatch/*bar_foo2239=== PAUSE TestGlobMatch/*bar_foo2240=== RUN TestGlobMatch/foo*bar_foobar2241=== PAUSE TestGlobMatch/foo*bar_foobar2242=== RUN TestGlobMatch/foo*bar_foo123bar2243=== PAUSE TestGlobMatch/foo*bar_foo123bar2244=== RUN TestGlobMatch/foo*bar_foobarbaz2245=== PAUSE TestGlobMatch/foo*bar_foobarbaz2246=== RUN TestGlobMatch/*/*_foo/bar2247=== PAUSE TestGlobMatch/*/*_foo/bar2248=== RUN TestGlobMatch/*/*_foo2249=== PAUSE TestGlobMatch/*/*_foo2250=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2251=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2252=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02253=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02254=== RUN TestGlobMatch/refs/*/main_refs/heads/main2255=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2256=== RUN TestGlobMatch/fo?_foo2257=== PAUSE TestGlobMatch/fo?_foo2258=== RUN TestGlobMatch/fo?_fo2259=== PAUSE TestGlobMatch/fo?_fo2260=== RUN TestGlobMatch/fo?_fooo2261=== PAUSE TestGlobMatch/fo?_fooo2262=== RUN TestGlobMatch/?oo_foo2263=== PAUSE TestGlobMatch/?oo_foo2264=== RUN TestGlobMatch/?oo_boo2265=== PAUSE TestGlobMatch/?oo_boo2266=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2267=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2268=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2269=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2270=== CONT TestGlobMatch/foo_foo2271=== CONT TestGlobMatch/refs/*/main_refs/heads/main2272=== CONT TestGlobMatch/foo*_bar2273=== CONT TestGlobMatch/foo*_foobar2274=== CONT TestGlobMatch/foo*_foo2275=== CONT TestGlobMatch/*_anything2276=== CONT TestGlobMatch/*_2277=== CONT TestGlobMatch/foo_bar2278=== CONT TestGlobMatch/foo*bar_foobarbaz2279=== CONT TestGlobMatch/?oo_boo2280=== CONT TestGlobMatch/fo?_fooo2281=== CONT TestGlobMatch/fo?_fo2282=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2283=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02284=== CONT TestGlobMatch/*/*_foo2285=== CONT TestGlobMatch/fo?_foo2286=== CONT TestGlobMatch/?oo_foo2287=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2288=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2289=== CONT TestGlobMatch/foo*bar_foo123bar2290=== CONT TestGlobMatch/foo*bar_foobar2291=== CONT TestGlobMatch/*bar_foo2292=== CONT TestGlobMatch/*bar_foobar2293=== CONT TestGlobMatch/*bar_bar2294=== CONT TestGlobMatch/*/*_foo/bar2295--- PASS: TestGlobMatch (0.00s)2296 --- PASS: TestGlobMatch/foo_foo (0.00s)2297 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2298 --- PASS: TestGlobMatch/foo*_bar (0.00s)2299 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2300 --- PASS: TestGlobMatch/foo*_foo (0.00s)2301 --- PASS: TestGlobMatch/*_anything (0.00s)2302 --- PASS: TestGlobMatch/*_ (0.00s)2303 --- PASS: TestGlobMatch/foo_bar (0.00s)2304 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2305 --- PASS: TestGlobMatch/?oo_boo (0.00s)2306 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2307 --- PASS: TestGlobMatch/fo?_fo (0.00s)2308 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2309 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2310 --- PASS: TestGlobMatch/*/*_foo (0.00s)2311 --- PASS: TestGlobMatch/fo?_foo (0.00s)2312 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2313 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2314 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2315 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2316 --- PASS: TestGlobMatch/*bar_foo (0.00s)2317 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2318 --- PASS: TestGlobMatch/*bar_bar (0.00s)2319 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2320 --- PASS: TestGlobMatch/?oo_foo (0.00s)23212026/10/11 05:55:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41731/oidc23222026/10/11 05:55:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37477/oidc2323--- PASS: TestValidateToken_BoundClaimsMismatch (0.03s)2324--- PASS: TestValidateToken_BoundSubjectMismatch (0.03s)23252026/10/11 05:55:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43117/oidc23262026/10/11 05:55:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34055/oidc2327--- PASS: TestValidateToken_WrongAudience (0.06s)23282026/10/11 05:55:34 http: TLS handshake error from 127.0.0.1:42040: remote error: tls: bad certificate2329--- PASS: TestNewValidator_KubernetesRequiresCA (0.06s)23302026/10/11 05:55:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38641/oidc2331--- PASS: TestPins_TopLevelShorthand (0.07s)2332--- PASS: TestScopes_Rules (0.07s)23332026/10/11 05:55:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42435/oidc2334--- PASS: TestPins_ReservedForMatchingRule (0.08s)23352026/10/11 05:55:34 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:37665/oidc23362026/10/11 05:55:34 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:45627/oidc2337--- PASS: TestValidateToken_MultipleProviders (0.09s)23382026/10/11 05:55:34 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:4393923392026/10/11 05:55:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42627/oidc2340--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.09s)2341--- PASS: TestValidateToken_KubernetesServiceAccount (0.10s)23422026/10/11 05:55:34 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:46589/oidc2343--- PASS: TestValidateToken_NoMatchingProvider (0.11s)23442026/10/11 05:55:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42441/oidc2345--- PASS: TestValidateToken_ValidToken (0.13s)23462026/10/11 05:55:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37385/oidc2347--- PASS: TestValidateToken_Expired (0.15s)23482026/10/11 05:55:34 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232349--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.17s)2350PASS2351Running hook tests...2352=== RUN TestSendPathsEmpty2353=== PAUSE TestSendPathsEmpty2354=== RUN TestQueueEnqueueAndFetch2355=== PAUSE TestQueueEnqueueAndFetch2356=== RUN TestQueueDeduplication2357=== PAUSE TestQueueDeduplication2358=== RUN TestQueueRemove2359=== PAUSE TestQueueRemove2360=== RUN TestQueueFetchBatchLimit2361=== PAUSE TestQueueFetchBatchLimit2362=== RUN TestQueueRetryMovesToBack2363=== PAUSE TestQueueRetryMovesToBack2364=== RUN TestQueueFetchRemoveLifecycle2365=== PAUSE TestQueueFetchRemoveLifecycle2366=== RUN TestQueueConcurrentWriters2367=== PAUSE TestQueueConcurrentWriters2368=== RUN TestQueueRemoveLargeClosure2369=== PAUSE TestQueueRemoveLargeClosure2370=== RUN TestServerClientIntegration2371--- PASS: TestServerClientIntegration (0.00s)2372=== RUN TestServerQueueError23732026/10/11 05:55:34 ERROR Failed to queue paths error="permission denied" count=12374--- PASS: TestServerQueueError (0.00s)2375=== RUN TestGetListenerSocketActivation2376 server_test.go:219: === RUN TestGetListenerSocketActivation2377 --- PASS: TestGetListenerSocketActivation (0.00s)2378 PASS2379 2380--- PASS: TestGetListenerSocketActivation (0.01s)2381=== RUN TestDrainIsolatesPoisonPath2382=== PAUSE TestDrainIsolatesPoisonPath2383=== RUN TestRunNotBlockedByPoisonHead2384=== PAUSE TestRunNotBlockedByPoisonHead2385=== RUN TestDrainGivesUpWhenServerDown2386=== PAUSE TestDrainGivesUpWhenServerDown2387=== RUN TestFailedPathPrunedByLaterClosure2388=== PAUSE TestFailedPathPrunedByLaterClosure2389=== RUN TestWorkerUploadsAndRemoves2390=== PAUSE TestWorkerUploadsAndRemoves2391=== RUN TestWorkerSkipsGCdPaths2392=== PAUSE TestWorkerSkipsGCdPaths2393=== RUN TestWorkerPrunesClosureDeps2394=== PAUSE TestWorkerPrunesClosureDeps2395=== RUN TestDrainTimeout2396=== PAUSE TestDrainTimeout2397=== CONT TestSendPathsEmpty2398--- PASS: TestSendPathsEmpty (0.00s)2399=== CONT TestDrainGivesUpWhenServerDown2400=== CONT TestQueueRemoveLargeClosure2401=== CONT TestFailedPathPrunedByLaterClosure2402=== CONT TestQueueConcurrentWriters2403=== CONT TestQueueFetchRemoveLifecycle2404=== CONT TestQueueRetryMovesToBack2405=== CONT TestWorkerUploadsAndRemoves2406=== CONT TestQueueFetchBatchLimit2407=== CONT TestQueueRemove2408=== CONT TestQueueDeduplication2409=== CONT TestDrainTimeout2410=== CONT TestQueueEnqueueAndFetch2411=== CONT TestDrainIsolatesPoisonPath2412=== CONT TestWorkerPrunesClosureDeps2413=== CONT TestWorkerSkipsGCdPaths2414=== CONT TestRunNotBlockedByPoisonHead24152026/10/11 05:55:34 INFO Uploading batch count=424162026/10/11 05:55:34 ERROR Upload failed error="upload failed" count=424172026/10/11 05:55:34 INFO Upload queue status pending=224182026/10/11 05:55:34 INFO Upload queue status pending=324192026/10/11 05:55:34 INFO Upload queue status pending=224202026/10/11 05:55:34 INFO Uploading batch count=224212026/10/11 05:55:34 INFO Uploading batch count=124222026/10/11 05:55:34 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath1905516355/002/bbb24232026/10/11 05:55:34 ERROR Upload failed error="upload failed" count=124242026/10/11 05:55:34 INFO Uploading batch count=224252026/10/11 05:55:34 ERROR Upload failed error="upload failed" count=224262026/10/11 05:55:34 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3210614506/002/a24272026/10/11 05:55:34 INFO Uploading batch count=22428--- PASS: TestQueueFetchBatchLimit (0.02s)24292026/10/11 05:55:34 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1105951668/002/nonexistent24302026/10/11 05:55:34 INFO Uploading batch count=124312026/10/11 05:55:34 ERROR Upload failed error="upload failed" count=12432--- PASS: TestQueueEnqueueAndFetch (0.02s)24332026/10/11 05:55:34 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3210614506/002/b24342026/10/11 05:55:34 INFO Upload queue status pending=224352026/10/11 05:55:34 INFO Uploading batch count=12436--- PASS: TestQueueDeduplication (0.02s)24372026/10/11 05:55:34 INFO Uploading batch count=124382026/10/11 05:55:34 INFO Uploading batch count=124392026/10/11 05:55:34 INFO Uploading batch count=224402026/10/11 05:55:34 ERROR Upload failed error="upload failed" count=224412026/10/11 05:55:34 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3210614506/002/c2442--- PASS: TestQueueFetchRemoveLifecycle (0.02s)2443--- PASS: TestQueueRemove (0.02s)24442026/10/11 05:55:34 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3210614506/002/d2445--- PASS: TestQueueRetryMovesToBack (0.02s)24462026/10/11 05:55:34 INFO Uploading batch count=124472026/10/11 05:55:34 INFO Uploading batch count=124482026/10/11 05:55:34 ERROR Upload failed error="upload failed" count=124492026/10/11 05:55:34 INFO Uploading batch count=224502026/10/11 05:55:34 ERROR Upload failed error="upload failed" count=224512026/10/11 05:55:34 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3210614506/002/e24522026/10/11 05:55:34 INFO Uploading batch count=124532026/10/11 05:55:34 ERROR Upload failed error="upload failed" count=124542026/10/11 05:55:34 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3210614506/002/f24552026/10/11 05:55:34 INFO Uploading batch count=124562026/10/11 05:55:34 ERROR Upload failed error="upload failed" count=124572026/10/11 05:55:34 ERROR Drain finished with paths left in queue remaining=1024582026/10/11 05:55:34 ERROR Drain finished with paths left in queue remaining=12459--- PASS: TestFailedPathPrunedByLaterClosure (0.03s)2460--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2461--- PASS: TestDrainIsolatesPoisonPath (0.03s)2462--- PASS: TestWorkerUploadsAndRemoves (0.04s)2463--- PASS: TestWorkerSkipsGCdPaths (0.04s)2464--- PASS: TestWorkerPrunesClosureDeps (0.04s)2465--- PASS: TestQueueRemoveLargeClosure (0.07s)24662026/10/11 05:55:34 ERROR Upload failed error="context deadline exceeded" count=224672026/10/11 05:55:34 ERROR Drain finished with paths left in queue remaining=42468--- PASS: TestDrainTimeout (0.22s)2469--- PASS: TestQueueConcurrentWriters (0.38s)24702026/10/11 05:55:35 INFO Uploading batch count=124712026/10/11 05:55:35 INFO Uploading batch count=124722026/10/11 05:55:35 INFO Uploading batch count=124732026/10/11 05:55:35 ERROR Upload failed error="upload failed" count=124742026/10/11 05:55:35 INFO Uploading batch count=124752026/10/11 05:55:35 ERROR Upload failed error="upload failed" count=124762026/10/11 05:55:35 INFO Uploading batch count=124772026/10/11 05:55:35 ERROR Upload failed error="upload failed" count=124782026/10/11 05:55:35 INFO Uploading batch count=124792026/10/11 05:55:35 ERROR Upload failed error="upload failed" count=124802026/10/11 05:55:35 ERROR Drain finished with paths left in queue remaining=12481--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2482PASS2483Running signing tests...2484=== RUN TestExternalSigner2485=== PAUSE TestExternalSigner2486=== RUN TestExternalSignerWrongPublicKey2487=== PAUSE TestExternalSignerWrongPublicKey2488=== RUN TestExternalSignerErrors2489=== PAUSE TestExternalSignerErrors2490=== RUN TestExternalSignerRestartsAfterCrash2491=== PAUSE TestExternalSignerRestartsAfterCrash2492=== RUN TestExternalSignerProgramErrorKeepsProcess2493=== PAUSE TestExternalSignerProgramErrorKeepsProcess2494=== RUN TestExternalSignerClose2495=== PAUSE TestExternalSignerClose2496=== RUN TestExternalSignerRejectsInvalidPublicKey2497=== PAUSE TestExternalSignerRejectsInvalidPublicKey2498=== RUN TestExternalSignerCancellation2499=== PAUSE TestExternalSignerCancellation2500=== RUN TestGenerateFingerprint2501=== PAUSE TestGenerateFingerprint2502=== RUN TestParseSigningKey2503=== PAUSE TestParseSigningKey2504=== RUN TestSign2505=== PAUSE TestSign2506=== RUN TestSignBatch2507=== PAUSE TestSignBatch2508=== RUN TestNilKeyPublicKey2509=== PAUSE TestNilKeyPublicKey2510=== RUN TestSignErrors2511=== PAUSE TestSignErrors2512=== CONT TestExternalSigner2513=== CONT TestExternalSignerCancellation2514=== CONT TestSignBatch2515=== CONT TestParseSigningKey2516=== CONT TestGenerateFingerprint2517=== CONT TestSign2518=== CONT TestSignErrors2519=== RUN TestSignErrors/nil_key2520=== PAUSE TestSignErrors/nil_key2521=== RUN TestSignErrors/nil_narinfo2522=== PAUSE TestSignErrors/nil_narinfo2523=== RUN TestSignErrors/invalid_narinfo2524=== PAUSE TestSignErrors/invalid_narinfo2525=== RUN TestSignErrors/canceled2526=== PAUSE TestSignErrors/canceled2527=== CONT TestSignErrors/nil_key2528=== CONT TestSignErrors/invalid_narinfo2529=== CONT TestNilKeyPublicKey2530=== CONT TestExternalSignerProgramErrorKeepsProcess2531=== CONT TestExternalSignerRejectsInvalidPublicKey2532=== CONT TestExternalSignerClose2533=== CONT TestExternalSignerErrors2534=== CONT TestExternalSignerRestartsAfterCrash2535=== CONT TestExternalSignerWrongPublicKey2536=== RUN TestParseSigningKey/valid_32-byte_key2537=== RUN TestGenerateFingerprint/basic_with_references2538=== PAUSE TestGenerateFingerprint/basic_with_references2539=== RUN TestGenerateFingerprint/no_references2540=== PAUSE TestGenerateFingerprint/no_references2541=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2542=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2543=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2544=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2545=== PAUSE TestParseSigningKey/valid_32-byte_key2546=== RUN TestGenerateFingerprint/invalid_nar_hash_length2547=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2548=== RUN TestGenerateFingerprint/invalid_store_path_prefix2549=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2550=== RUN TestGenerateFingerprint/invalid_reference_prefix2551=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2552=== CONT TestGenerateFingerprint/basic_with_references2553=== CONT TestGenerateFingerprint/invalid_nar_hash_length2554=== CONT TestSignErrors/nil_narinfo2555=== RUN TestExternalSignerErrors/wrong_shape2556=== PAUSE TestExternalSignerErrors/wrong_shape2557=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2558=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2559=== CONT TestSignErrors/canceled2560--- PASS: TestSignBatch (0.00s)2561--- PASS: TestSign (0.00s)2562=== RUN TestExternalSignerRejectsInvalidPublicKey/#002563=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2564=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002565=== CONT TestGenerateFingerprint/no_references2566=== CONT TestGenerateFingerprint/invalid_reference_prefix2567=== CONT TestGenerateFingerprint/invalid_store_path_prefix2568=== RUN TestExternalSignerErrors/wrong_id2569=== PAUSE TestExternalSignerErrors/wrong_id2570=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2571--- PASS: TestNilKeyPublicKey (0.00s)2572=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2573--- PASS: TestSignErrors (0.00s)2574 --- PASS: TestSignErrors/nil_key (0.00s)2575 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2576 --- PASS: TestSignErrors/nil_narinfo (0.00s)2577 --- PASS: TestSignErrors/canceled (0.00s)2578=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2579=== RUN TestParseSigningKey/no_colon2580=== RUN TestExternalSignerErrors/wrong_signature_length2581=== PAUSE TestExternalSignerErrors/wrong_signature_length2582=== RUN TestExternalSignerErrors/program_error2583=== PAUSE TestExternalSignerErrors/program_error2584--- PASS: TestGenerateFingerprint (0.00s)2585 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2586 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2587 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2588 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2589 --- PASS: TestGenerateFingerprint/no_references (0.00s)2590 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2591 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2592=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2593=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2594=== PAUSE TestParseSigningKey/no_colon2595=== RUN TestExternalSignerErrors/missing_signature_name2596=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2597=== RUN TestParseSigningKey/empty_name2598=== PAUSE TestParseSigningKey/empty_name2599=== RUN TestParseSigningKey/invalid_base642600=== PAUSE TestParseSigningKey/invalid_base642601=== PAUSE TestExternalSignerErrors/missing_signature_name2602=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2603=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2604=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2605=== RUN TestParseSigningKey/wrong_length2606=== RUN TestExternalSignerErrors/invalid_JSON2607=== PAUSE TestExternalSignerErrors/invalid_JSON2608=== CONT TestExternalSignerRejectsInvalidPublicKey/#002609=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2610=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2611=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2612=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2613=== PAUSE TestParseSigningKey/wrong_length2614=== CONT TestParseSigningKey/valid_32-byte_key2615=== CONT TestParseSigningKey/invalid_base642616=== CONT TestParseSigningKey/empty_name2617=== RUN TestExternalSignerErrors/null2618=== PAUSE TestExternalSignerErrors/null2619--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2620 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2621 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2622 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2623 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2624 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2625=== CONT TestParseSigningKey/wrong_length2626=== CONT TestParseSigningKey/no_colon2627=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2628--- PASS: TestParseSigningKey (0.00s)2629 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2630 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2631 --- PASS: TestParseSigningKey/empty_name (0.00s)2632 --- PASS: TestParseSigningKey/wrong_length (0.00s)2633 --- PASS: TestParseSigningKey/no_colon (0.00s)2634 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2635=== RUN TestExternalSignerErrors/exit_at_startup2636=== PAUSE TestExternalSignerErrors/exit_at_startup2637=== RUN TestExternalSignerErrors/missing_signatures2638=== PAUSE TestExternalSignerErrors/missing_signatures2639=== RUN TestExternalSignerErrors/null_signatures2640=== PAUSE TestExternalSignerErrors/null_signatures2641=== RUN TestExternalSignerErrors/wrong_signatures_shape2642=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2643=== RUN TestExternalSignerErrors/too_few_signatures2644=== PAUSE TestExternalSignerErrors/too_few_signatures2645=== RUN TestExternalSignerErrors/unrequested_key2646=== PAUSE TestExternalSignerErrors/unrequested_key2647=== RUN TestExternalSignerErrors/wrong_signature_name2648=== PAUSE TestExternalSignerErrors/wrong_signature_name2649=== RUN TestExternalSignerErrors/invalid_signature_base642650=== PAUSE TestExternalSignerErrors/invalid_signature_base642651=== RUN TestExternalSignerErrors/exit_on_request2652=== PAUSE TestExternalSignerErrors/exit_on_request2653=== CONT TestExternalSignerErrors/wrong_shape2654=== CONT TestExternalSignerErrors/null2655=== CONT TestExternalSignerErrors/null_signatures2656=== CONT TestExternalSignerErrors/unrequested_key2657=== CONT TestExternalSignerErrors/invalid_JSON2658=== CONT TestExternalSignerErrors/exit_on_request2659=== CONT TestExternalSignerErrors/invalid_signature_base642660=== CONT TestExternalSignerErrors/wrong_signature_name2661=== CONT TestExternalSignerErrors/program_error2662=== CONT TestExternalSignerErrors/missing_signature_name2663=== CONT TestExternalSignerErrors/wrong_signature_length2664=== CONT TestExternalSignerErrors/wrong_id2665=== CONT TestExternalSignerErrors/too_few_signatures2666=== CONT TestExternalSignerErrors/wrong_signatures_shape2667=== CONT TestExternalSignerErrors/missing_signatures2668=== CONT TestExternalSignerErrors/exit_at_startup2669--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2670--- PASS: TestExternalSignerClose (0.01s)2671--- PASS: TestExternalSignerWrongPublicKey (0.01s)2672--- PASS: TestExternalSigner (0.01s)2673--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2674--- PASS: TestExternalSignerErrors (0.00s)2675 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)2676 --- PASS: TestExternalSignerErrors/null (0.00s)2677 --- PASS: TestExternalSignerErrors/invalid_JSON (0.00s)2678 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2679 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2680 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2681 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2682 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2683 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2684 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2685 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2686 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2687 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2688 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2689 --- PASS: TestExternalSignerErrors/program_error (0.01s)2690 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2691--- PASS: TestExternalSignerCancellation (0.02s)2692PASS2693Running OpenBao signer tests...2694=== RUN TestSign2695=== PAUSE TestSign2696=== RUN TestSignErrors2697=== PAUSE TestSignErrors2698=== RUN TestServe2699=== PAUSE TestServe2700=== RUN TestServeRejectsGarbage2701=== PAUSE TestServeRejectsGarbage2702=== CONT TestSign2703=== CONT TestServe2704=== CONT TestServeRejectsGarbage2705=== CONT TestSignErrors2706=== RUN TestSignErrors/no_prefix2707=== PAUSE TestSignErrors/no_prefix2708=== RUN TestSignErrors/invalid_base642709--- PASS: TestServeRejectsGarbage (0.00s)2710=== PAUSE TestSignErrors/invalid_base642711--- PASS: TestServe (0.00s)2712=== RUN TestSignErrors/http_error2713=== PAUSE TestSignErrors/http_error2714=== RUN TestSignErrors/invalid_json2715=== PAUSE TestSignErrors/invalid_json2716=== CONT TestSignErrors/no_prefix2717=== CONT TestSignErrors/http_error2718=== CONT TestSignErrors/invalid_json2719=== CONT TestSignErrors/invalid_base642720--- PASS: TestSign (0.00s)2721--- PASS: TestSignErrors (0.00s)2722 --- PASS: TestSignErrors/invalid_base64 (0.00s)2723 --- PASS: TestSignErrors/http_error (0.00s)2724 --- PASS: TestSignErrors/no_prefix (0.00s)2725 --- PASS: TestSignErrors/invalid_json (0.00s)2726PASS