niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #413
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestUploadMultipart_PartsInParallel18=== PAUSE TestUploadMultipart_PartsInParallel19=== RUN TestPartSizeForNAR20=== PAUSE TestPartSizeForNAR21=== RUN TestUploadMultipart_SupersededByPeer22=== PAUSE TestUploadMultipart_SupersededByPeer23=== RUN TestDumpPathCaseHackMatchesNix24--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)25=== RUN TestDumpPathCaseHackCollision26--- PASS: TestDumpPathCaseHackCollision (0.00s)27=== RUN TestSupersededNARStillUploadsListing28=== PAUSE TestSupersededNARStillUploadsListing29=== RUN TestDumpPathMatchesNix30=== PAUSE TestDumpPathMatchesNix31=== RUN TestDumpPathSingleFile32=== PAUSE TestDumpPathSingleFile33=== RUN TestDumpPathWriterError34=== PAUSE TestDumpPathWriterError35=== RUN TestEncodeNixBase3236=== PAUSE TestEncodeNixBase3237=== RUN TestEncodeNixBase32WithRealHash38=== PAUSE TestEncodeNixBase32WithRealHash39=== RUN TestConvertHashToNix3240=== PAUSE TestConvertHashToNix3241=== RUN TestGetStorePathHash42=== PAUSE TestGetStorePathHash43=== RUN TestPathInfoHashCompatibility44=== PAUSE TestPathInfoHashCompatibility45=== RUN TestParsePathInfoJSON46=== PAUSE TestParsePathInfoJSON47=== RUN TestParsePathInfoJSONMultiplePaths48=== PAUSE TestParsePathInfoJSONMultiplePaths49=== RUN TestPathInfoCACompatibility50=== PAUSE TestPathInfoCACompatibility51=== RUN TestRateLimiterFeedback52=== PAUSE TestRateLimiterFeedback53=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess54=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess55=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer56=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer57=== RUN TestResolveStorePath58=== PAUSE TestResolveStorePath59=== RUN TestDoWithRetry_BodyReplayedViaGetBody60=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody61=== RUN TestRetryTimeoutOutlastsMaxRetries62=== PAUSE TestRetryTimeoutOutlastsMaxRetries63=== RUN TestDoWithRetry_FinalResponseBodyReadable64=== PAUSE TestDoWithRetry_FinalResponseBodyReadable65=== RUN TestShellSplit66=== PAUSE TestShellSplit67=== RUN TestShellSplitErrors68=== PAUSE TestShellSplitErrors69=== RUN TestStreamPushReportsEveryPath70=== PAUSE TestStreamPushReportsEveryPath71=== RUN TestStreamPushBatchesUnderLoad72=== PAUSE TestStreamPushBatchesUnderLoad73=== RUN TestStreamPushIsolatesFailures74=== PAUSE TestStreamPushIsolatesFailures75=== RUN TestStreamPushGivesUpOnDeadServer76=== PAUSE TestStreamPushGivesUpOnDeadServer77=== RUN TestStreamPushRequestLine78=== PAUSE TestStreamPushRequestLine79=== RUN TestStreamPushReportsSignatures80=== PAUSE TestStreamPushReportsSignatures81=== RUN TestStreamPushReportsSkippedPaths82=== PAUSE TestStreamPushReportsSkippedPaths83=== RUN TestClientSignaturesByStorePath84=== PAUSE TestClientSignaturesByStorePath85=== RUN TestStreamPushStopsWhenCanceled86=== PAUSE TestStreamPushStopsWhenCanceled87=== RUN TestSetClientTLS88=== PAUSE TestSetClientTLS89=== RUN TestSetClientTLSDoesNotMutateDefaultTransport90=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport91=== RUN TestSetClientTLSErrors92=== PAUSE TestSetClientTLSErrors93=== RUN TestStaticToken94=== PAUSE TestStaticToken95=== RUN TestFileTokenReadsAndCaches96=== PAUSE TestFileTokenReadsAndCaches97=== RUN TestFileTokenMissing98=== PAUSE TestFileTokenMissing99=== RUN TestFileTokenEmpty100=== PAUSE TestFileTokenEmpty101=== RUN TestScriptTokenNoExpiryRerunsEveryCall102=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall103=== RUN TestScriptTokenCachesUntilRefresh104=== PAUSE TestScriptTokenCachesUntilRefresh105=== RUN TestScriptTokenEmptyToken106=== PAUSE TestScriptTokenEmptyToken107=== RUN TestScriptTokenBadJSON108=== PAUSE TestScriptTokenBadJSON109=== RUN TestScriptTokenScriptFails110=== PAUSE TestScriptTokenScriptFails111=== RUN TestScriptTokenEmptyCommand112=== PAUSE TestScriptTokenEmptyCommand113=== CONT TestDoServerRequestAttachesToken114=== CONT TestRetryTimeoutOutlastsMaxRetries115=== CONT TestSetClientTLS116=== CONT TestEncodeNixBase32117=== RUN TestEncodeNixBase32/test_string_hash118=== PAUSE TestEncodeNixBase32/test_string_hash119=== RUN TestEncodeNixBase32/empty_input120=== PAUSE TestEncodeNixBase32/empty_input121=== CONT TestDoWithRetry_BodyReplayedViaGetBody122=== CONT TestScriptTokenEmptyCommand123--- PASS: TestScriptTokenEmptyCommand (0.00s)124=== CONT TestSetClientTLSErrors125=== CONT TestResolveStorePath126=== CONT TestScriptTokenScriptFails127=== CONT TestScriptTokenBadJSON128--- PASS: TestResolveStorePath (0.00s)129=== CONT TestEncodeNixBase32WithRealHash130--- PASS: TestEncodeNixBase32WithRealHash (0.00s)131=== CONT TestSetClientTLSDoesNotMutateDefaultTransport132=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer133=== CONT TestScriptTokenEmptyToken134=== CONT TestRateLimiterFeedback135=== CONT TestScriptTokenCachesUntilRefresh136=== CONT TestPathInfoCACompatibility137=== CONT TestScriptTokenNoExpiryRerunsEveryCall138=== CONT TestParsePathInfoJSONMultiplePaths139=== CONT TestFileTokenEmpty140=== CONT TestParsePathInfoJSON141=== CONT TestFileTokenMissing142=== CONT TestPathInfoHashCompatibility143=== CONT TestFileTokenReadsAndCaches144=== CONT TestGetStorePathHash145=== CONT TestStaticToken146=== CONT TestConvertHashToNix32147=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess148--- PASS: TestScriptTokenScriptFails (0.00s)149=== CONT TestDumpPathMatchesNix150=== RUN TestSetClientTLSErrors/missing_cert_file1512026/10/14 16:41:45 WARN Rate limiter enabled after throttle name=server-test rate=5152=== RUN TestRateLimiterFeedback/429_enables_limiter153=== PAUSE TestRateLimiterFeedback/429_enables_limiter154=== RUN TestRateLimiterFeedback/503_enables_limiter155=== PAUSE TestRateLimiterFeedback/503_enables_limiter156=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter157=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter158=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter1592026/10/14 16:41:45 WARN Rate limiter enabled after throttle name=server-test rate=5160=== RUN TestPathInfoCACompatibility/null_ca_field1612026/10/14 16:41:45 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:35291162=== PAUSE TestPathInfoCACompatibility/null_ca_field163=== RUN TestPathInfoCACompatibility/old_string_format_-_text164=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text165=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths166=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter167=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive168=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive169=== RUN TestPathInfoCACompatibility/new_structured_format_-_text170=== CONT TestStreamPushGivesUpOnDeadServer171=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text1722026/10/14 16:41:45 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:46319173=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method174--- PASS: TestFileTokenEmpty (0.00s)175=== CONT TestDumpPathWriterError176=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths177=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths178=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)179=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)1802026/10/14 16:41:45 WARN Rate limiter backed off name=server-test rate=5181=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon1822026/10/14 16:41:45 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:35291183=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon184=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI185=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI186=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha5121872026/10/14 16:41:45 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:46319188=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512189--- PASS: TestStaticToken (0.00s)190=== CONT TestStreamPushStopsWhenCanceled191--- PASS: TestStreamPushStopsWhenCanceled (0.00s)192=== CONT TestClientSignaturesByStorePath193--- PASS: TestClientSignaturesByStorePath (0.00s)194=== CONT TestStreamPushRequestLine195=== CONT TestDumpPathSingleFile196--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)197=== CONT TestStreamPushReportsSignatures198=== RUN TestConvertHashToNix32/SRI_format_to_Nix32199=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32200=== RUN TestConvertHashToNix32/already_Nix32_format201=== PAUSE TestConvertHashToNix32/already_Nix32_format202=== RUN TestConvertHashToNix32/invalid_format203=== PAUSE TestConvertHashToNix32/invalid_format204=== RUN TestGetStorePathHash/valid_store_path205=== PAUSE TestGetStorePathHash/valid_store_path206=== RUN TestGetStorePathHash/basename_without_hyphen_should_error207--- PASS: TestFileTokenReadsAndCaches (0.00s)208=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error209=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error210=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error211=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error212=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error213=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun214=== PAUSE TestSetClientTLSErrors/missing_cert_file215=== CONT TestStreamPushReportsSkippedPaths216=== CONT TestStreamPushReportsEveryPath2172026/10/14 16:41:45 ERROR Upload failed error=boom count=1218--- PASS: TestStreamPushReportsSignatures (0.00s)219=== CONT TestFilterOversizedClosures2202026/10/14 16:41:45 ERROR Upload failed error=boom count=1221=== RUN TestFilterOversizedClosures/no_limit_keeps_everything222=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything223=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped224=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped225=== RUN TestFilterOversizedClosures/all_closures_skipped226=== PAUSE TestFilterOversizedClosures/all_closures_skipped227=== CONT TestStreamPushIsolatesFailures2282026/10/14 16:41:45 ERROR Upload failed error="bad path" count=3229--- PASS: TestStreamPushIsolatesFailures (0.00s)230=== CONT TestCaseHackSuffix231--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)232=== CONT TestStreamPushBatchesUnderLoad233=== RUN TestSetClientTLS/rejects_connection_without_client_cert234=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert235=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA236=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA237=== RUN TestSetClientTLS/preserves_debug_logging_transport238=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths239=== PAUSE TestSetClientTLS/preserves_debug_logging_transport240=== CONT TestUploadMultipart_SupersededByPeer241=== RUN TestUploadMultipart_SupersededByPeer/exists242=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method243=== PAUSE TestUploadMultipart_SupersededByPeer/exists244=== CONT TestShellSplit245=== RUN TestSetClientTLSErrors/missing_key_file2462026/10/14 16:41:45 ERROR Upload failed error="connection refused" count=20247=== CONT TestDoWithRetry_FinalResponseBodyReadable248--- PASS: TestScriptTokenEmptyToken (0.01s)249--- PASS: TestStreamPushReportsEveryPath (0.00s)250--- PASS: TestFileTokenMissing (0.00s)2512026/10/14 16:41:45 ERROR Server seems unavailable, giving up on batch untried=17252--- PASS: TestShellSplit (0.00s)253--- PASS: TestStreamPushReportsSkippedPaths (0.00s)254=== CONT TestSupersededNARStillUploadsListing255=== RUN TestSupersededNARStillUploadsListing/small_NAR256=== RUN TestParsePathInfoJSON/Nix_format257=== PAUSE TestParsePathInfoJSON/Nix_format258=== RUN TestParsePathInfoJSON/Lix_format259=== PAUSE TestSupersededNARStillUploadsListing/small_NAR260=== CONT TestRegisterUploadedObjectReusesConnections261=== PAUSE TestParsePathInfoJSON/Lix_format262=== RUN TestParsePathInfoJSON/empty_input263=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry264=== CONT TestPartSizeForNAR265--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)266=== CONT TestShellSplitErrors267=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica268=== RUN TestSupersededNARStillUploadsListing/dump_cut_short269=== PAUSE TestSetClientTLSErrors/missing_key_file270=== RUN TestSetClientTLSErrors/missing_ca_file271=== PAUSE TestParsePathInfoJSON/empty_input272=== RUN TestParsePathInfoJSON/whitespace_only273=== RUN TestUploadMultipart_SupersededByPeer/missing274=== PAUSE TestUploadMultipart_SupersededByPeer/missing275=== CONT TestUploadMultipart_PartsInParallel276--- PASS: TestDoServerRequestAttachesToken (0.01s)277=== CONT TestEncodeNixBase32/test_string_hash278=== CONT TestEncodeNixBase32/empty_input279--- PASS: TestEncodeNixBase32 (0.00s)280 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)281 --- PASS: TestEncodeNixBase32/empty_input (0.00s)282=== CONT TestRateLimiterFeedback/429_enables_limiter283=== PAUSE TestSetClientTLSErrors/missing_ca_file284=== RUN TestSetClientTLSErrors/invalid_ca_file285=== PAUSE TestSetClientTLSErrors/invalid_ca_file286=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter287=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short288=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails289--- PASS: TestShellSplitErrors (0.00s)290=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter291=== RUN TestPartSizeForNAR/zero_stays_at_minimum2922026/10/14 16:41:45 INFO Garbage collection started293=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum294=== RUN TestPartSizeForNAR/small_stays_at_minimum295=== PAUSE TestPartSizeForNAR/small_stays_at_minimum296=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum297=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum298=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts299=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts300=== RUN TestPartSizeForNAR/1_TiB301=== PAUSE TestPartSizeForNAR/1_TiB302=== RUN TestPartSizeForNAR/5_TiB_S3_max_object303=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object304=== RUN TestPartSizeForNAR/capped_at_5_GiB305=== PAUSE TestPartSizeForNAR/capped_at_5_GiB306=== CONT TestRateLimiterFeedback/503_enables_limiter3072026/10/14 16:41:45 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:463193082026/10/14 16:41:45 WARN Rate limiter enabled after throttle name=server-test rate=53092026/10/14 16:41:45 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:394453102026/10/14 16:41:45 WARN Rate limiter backed off name=server-test rate=5311--- PASS: TestScriptTokenBadJSON (0.04s)312=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)3132026/10/14 16:41:45 WARN Rate limiter enabled after throttle name=server-test rate=5314=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha5123152026/10/14 16:41:45 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:36061316=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI317=== CONT TestConvertHashToNix32/SRI_format_to_Nix32318=== CONT TestConvertHashToNix32/invalid_format319=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon3202026/10/14 16:41:45 WARN Rate limiter backed off name=server-test rate=5321=== CONT TestConvertHashToNix32/already_Nix32_format322=== PAUSE TestParsePathInfoJSON/whitespace_only323--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.03s)324=== RUN TestParsePathInfoJSON/invalid_JSON325=== PAUSE TestParsePathInfoJSON/invalid_JSON326=== CONT TestGetStorePathHash/basename_without_hyphen_should_error327=== CONT TestFilterOversizedClosures/all_closures_skipped3282026/10/14 16:41:45 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50329=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error330=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped331=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths3322026/10/14 16:41:45 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=2000333--- PASS: TestRateLimiterFeedback (0.00s)334 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.02s)335 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)336 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)337 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)338=== CONT TestSetClientTLS/preserves_debug_logging_transport339=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails340=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths341=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error342=== CONT TestPathInfoCACompatibility/null_ca_field343--- PASS: TestConvertHashToNix32 (0.00s)344 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)345 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)346 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)347--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)348 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)349 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)350=== CONT TestGetStorePathHash/valid_store_path351--- PASS: TestPathInfoHashCompatibility (0.00s)352 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)353 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)354 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)355 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)356=== CONT TestFilterOversizedClosures/no_limit_keeps_everything357=== CONT TestUploadMultipart_SupersededByPeer/exists358=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method3592026/10/14 16:41:45 WARN Rate limiter enabled after throttle name=server-test rate=5360=== CONT TestUploadMultipart_SupersededByPeer/missing361=== CONT TestSetClientTLS/rejects_connection_without_client_cert3622026/10/14 16:41:45 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:46319363=== CONT TestPartSizeForNAR/zero_stays_at_minimum364=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts365=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum366=== CONT TestPartSizeForNAR/small_stays_at_minimum367=== CONT TestPartSizeForNAR/1_TiB368=== CONT TestPartSizeForNAR/capped_at_5_GiB369=== CONT TestPartSizeForNAR/5_TiB_S3_max_object370=== CONT TestParsePathInfoJSON/Nix_format371=== CONT TestParsePathInfoJSON/whitespace_only372=== CONT TestParsePathInfoJSON/empty_input373=== CONT TestParsePathInfoJSON/Lix_format374=== CONT TestParsePathInfoJSON/invalid_JSON375=== CONT TestSetClientTLSErrors/missing_cert_file376=== CONT TestSetClientTLSErrors/missing_ca_file3772026/10/14 16:41:45 INFO Garbage collection started378=== CONT TestSetClientTLSErrors/invalid_ca_file3792026/10/14 16:41:45 WARN Rate limiter enabled after throttle name=s3-test rate=5380=== CONT TestSupersededNARStillUploadsListing/small_NAR3812026/10/14 16:41:45 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:347513822026/10/14 16:41:45 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:37257383=== CONT TestSetClientTLSErrors/missing_key_file384=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails3852026/10/14 16:41:45 INFO Uploading abc-hello (1.0GB)3862026/10/14 16:41:45 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:463193872026/10/14 16:41:45 INFO Uploading abc-hello (1.0GB)3882026/10/14 16:41:45 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=0389=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA390=== CONT TestSupersededNARStillUploadsListing/dump_cut_short3912026/10/14 16:41:45 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:463193922026/10/14 16:41:45 WARN Rate limiter backed off name=server-test rate=5393=== CONT TestPathInfoCACompatibility/new_structured_format_-_text394=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive395=== CONT TestPathInfoCACompatibility/old_string_format_-_text396--- PASS: TestGetStorePathHash (0.00s)397 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)398 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)399 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)400 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)401--- PASS: TestPartSizeForNAR (0.00s)402 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)403 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)404 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)405 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)406 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)407 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)408 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)409--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)410--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.03s)411--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.03s)412--- PASS: TestParsePathInfoJSON (0.03s)413 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)414 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)415 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)416 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)417 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)418--- PASS: TestPathInfoCACompatibility (0.01s)419 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)420 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)421 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)422 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)423 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)4242026/10/14 16:41:45 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:463194252026/10/14 16:41:45 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:46319426--- PASS: TestFilterOversizedClosures (0.00s)427 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)428 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)429 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)430--- PASS: TestDumpPathSingleFile (0.28s)431--- PASS: TestCaseHackSuffix (0.28s)432--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)433 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)434 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.25s)4352026/10/14 16:41:45 WARN Garbage collection finished on another replica. Its statistics are not available here436--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.25s)4372026/10/14 16:41:45 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:46319438--- PASS: TestSetClientTLSErrors (0.28s)439 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)440 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)441 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)442 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)443--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.29s)4442026/10/14 16:41:45 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:463194452026/10/14 16:41:45 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:463194462026/10/14 16:41:45 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:463194472026/10/14 16:41:45 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:463194482026/10/14 16:41:45 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:46319449--- PASS: TestStreamPushRequestLine (0.29s)4502026/10/14 16:41:45 http: TLS handshake error from 127.0.0.1:42570: remote error: tls: bad certificate4512026/10/14 16:41:45 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:46319452--- PASS: TestSetClientTLS (0.01s)453 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.25s)454 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.25s)455 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.26s)4562026/10/14 16:41:45 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:463194572026/10/14 16:41:45 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:46319458--- PASS: TestRegisterUploadedObjectReusesConnections (0.29s)4592026/10/14 16:41:45 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:463194602026/10/14 16:41:45 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:46319461--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.31s)462--- PASS: TestDumpPathWriterError (0.30s)4632026/10/14 16:41:45 INFO Uploading abc-hello (1.0GB)464--- PASS: TestStreamPushBatchesUnderLoad (0.33s)465--- PASS: TestDumpPathMatchesNix (0.35s)4662026/10/14 16:41:45 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:45467/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:45467/part/24672026/10/14 16:41:45 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:45467/part/3\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:45467/part/34682026/10/14 16:41:45 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:45467/part/4\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:45467/part/44692026/10/14 16:41:45 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:45467/part/5\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:45467/part/54702026/10/14 16:41:45 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:45467/part/6\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:45467/part/64712026/10/14 16:41:45 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:45467/part/7\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:45467/part/7472--- PASS: TestSupersededNARStillUploadsListing (0.03s)473 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.25s)474 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.25s)475 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.81s)476--- PASS: TestUploadMultipart_PartsInParallel (0.89s)4772026/10/14 16:41:46 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:35669/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:35669/api/uploads/complete4782026/10/14 16:41:46 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4792026/10/14 16:41:46 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:35669/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:35669/api/uploads/complete4802026/10/14 16:41:46 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4812026/10/14 16:41:46 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:35669/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:35669/api/uploads/complete4822026/10/14 16:41:46 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"483--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)484--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)485PASS486Running server tests...487The files belonging to this database system will be owned by user "nixbld".488This user must also own the server process.489490The database cluster will be initialized with locale "C".491The default database encoding has accordingly been set to "SQL_ASCII".492The default text search configuration will be set to "english".493494Data page checksums are enabled.495496creating directory /build/postgres2860985053/data ... ok497creating subdirectories ... ok498selecting dynamic shared memory implementation ... posix499selecting default "max_connections" ... 100500selecting default "shared_buffers" ... 128MB501selecting default time zone ... UTC502creating configuration files ... ok503running bootstrap script ... ok504performing post-bootstrap initialization ... ok505syncing data to disk ... ok506507initdb: warning: enabling "trust" authentication for local connections508initdb: 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.509510Success. You can now start the database server using:511512 pg_ctl -D /build/postgres2860985053/data -l logfile start513514/build/postgres2860985053:5432 - no response5152026-10-14 16:41:47.290 UTC [129] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit5162026-10-14 16:41:47.290 UTC [129] LOG: listening on Unix socket "/build/postgres2860985053/.s.PGSQL.5432"5172026-10-14 16:41:47.294 UTC [136] LOG: database system was shut down at 2026-10-14 16:41:47 UTC5182026-10-14 16:41:47.301 UTC [129] LOG: database system is ready to accept connections519/build/postgres2860985053:5432 - accepting connections520{"timestamp":"2026-10-14T16:41:47.491998106Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"83ac9092-5a0d-4e75-adb9-1eff29935670","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":1,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(207)"}521=== RUN TestService_AuthMiddleware522=== PAUSE TestService_AuthMiddleware523=== RUN TestService_AuthMiddleware_MTLSProxyHeader524=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader525=== RUN TestService_AuthMiddleware_MTLSBoundSubjects526=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects527=== RUN TestService_ReadAuthMiddleware528=== PAUSE TestService_ReadAuthMiddleware529=== RUN TestService_AuthMiddleware_OIDC530=== PAUSE TestService_AuthMiddleware_OIDC531=== RUN TestService_RequireScope_OIDC532=== PAUSE TestService_RequireScope_OIDC533=== RUN TestService_ReadScope_PublicByDefault534=== PAUSE TestService_ReadScope_PublicByDefault535=== RUN TestCacheConfigHandler536=== PAUSE TestCacheConfigHandler537=== RUN TestCacheStatsHandler538=== PAUSE TestCacheStatsHandler539=== RUN TestClientCADerivations540=== PAUSE TestClientCADerivations541=== RUN TestClientErrorHandling542=== PAUSE TestClientErrorHandling543=== RUN TestClientIntegration544=== PAUSE TestClientIntegration545=== RUN TestClientMultipleUploads546=== PAUSE TestClientMultipleUploads547=== RUN TestClientWithDependencies548=== PAUSE TestClientWithDependencies549=== RUN TestClientSharedPathCommittedMidPush550=== PAUSE TestClientSharedPathCommittedMidPush551=== RUN TestPinProtectsFromGC552=== PAUSE TestPinProtectsFromGC553=== RUN TestClientPushesUseOnePush554=== PAUSE TestClientPushesUseOnePush555=== RUN TestClientFallsBackToClosures556=== PAUSE TestClientFallsBackToClosures557=== RUN TestDeleteClosuresRacingPins558=== PAUSE TestDeleteClosuresRacingPins559=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock560=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock561=== RUN TestResolveDBConnectionString562=== PAUSE TestResolveDBConnectionString563=== RUN TestConnectWaitsForAPeerMigration564=== PAUSE TestConnectWaitsForAPeerMigration565=== RUN TestLeadElectsOneAndHandsOver566=== PAUSE TestLeadElectsOneAndHandsOver567=== RUN TestLeadIncumbentWinsAfterRestart5682026/10/14 16:41:47 INFO lead: acquired remote=192.0.2.1:12345692026/10/14 16:41:48 INFO lead: released remote=192.0.2.1:12345702026/10/14 16:41:48 INFO lead: acquired remote=192.0.2.1:12345712026/10/14 16:41:49 INFO lead: released remote=192.0.2.1:1234572--- PASS: TestLeadIncumbentWinsAfterRestart (1.89s)573=== RUN TestLeadIncumbentAnnouncesAtOnce574=== PAUSE TestLeadIncumbentAnnouncesAtOnce575=== RUN TestLeadEndsOnShutdown576=== PAUSE TestLeadEndsOnShutdown577=== RUN TestLeadEndsWhenItsConnectionHangs5782026/10/14 16:41:49 INFO lead: acquired remote=192.0.2.1:12345792026-10-14 16:41:51.001 UTC [385] FATAL: terminating connection due to administrator command5802026/10/14 16:41:51 INFO lead: acquired remote=192.0.2.1:12345812026/10/14 16:41:52 WARN lead: lock connection lost error="timeout: context deadline exceeded"5822026/10/14 16:41:52 INFO lead: released remote=192.0.2.1:12345832026/10/14 16:41:52 INFO lead: released remote=192.0.2.1:1234584--- PASS: TestLeadEndsWhenItsConnectionHangs (3.11s)585=== RUN TestGCAdvisoryLockBlocksConcurrentRun586=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun587=== RUN TestGCBugBareHashReferences588=== PAUSE TestGCBugBareHashReferences589=== RUN TestGCMetrics590=== PAUSE TestGCMetrics591=== RUN TestPushDedupSurvivesConcurrentGC592=== PAUSE TestPushDedupSurvivesConcurrentGC593=== RUN TestDeduplicatedObjectsRecordedAsPending594=== PAUSE TestDeduplicatedObjectsRecordedAsPending595=== RUN TestGCSweepSkipsPendingObjects596=== PAUSE TestGCSweepSkipsPendingObjects597=== RUN TestTombstonedObjectOfferedWithoutWaiting598=== PAUSE TestTombstonedObjectOfferedWithoutWaiting599=== RUN TestGCSweepDeliversEachKeyOnce600=== PAUSE TestGCSweepDeliversEachKeyOnce601=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection602=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection603=== RUN TestForceGCDuringPushOffersSweptObject604=== PAUSE TestForceGCDuringPushOffersSweptObject605=== RUN TestFailedS3DeleteKeepsTombstone606=== PAUSE TestFailedS3DeleteKeepsTombstone607=== RUN TestSweepSkipsRowsLockedByPush608=== PAUSE TestSweepSkipsRowsLockedByPush609=== RUN TestRegisterCompletedObjectNeedsPendingRow610=== PAUSE TestRegisterCompletedObjectNeedsPendingRow611=== RUN TestGetExistingObjectsLocksRows612=== PAUSE TestGetExistingObjectsLocksRows613=== RUN TestSweepRechecksPendingAfterLocking614=== PAUSE TestSweepRechecksPendingAfterLocking615=== RUN TestPushWaitsForSweepHoldingRow616=== PAUSE TestPushWaitsForSweepHoldingRow617=== RUN TestCommitRacingPendingCleanupKeepsObjects618=== PAUSE TestCommitRacingPendingCleanupKeepsObjects619=== RUN TestGCEndsOnShutdown620=== PAUSE TestGCEndsOnShutdown621=== RUN TestGCTaskStore_StartNew622=== PAUSE TestGCTaskStore_StartNew623=== RUN TestGCTaskStore_DeduplicateSameParams624=== PAUSE TestGCTaskStore_DeduplicateSameParams625=== RUN TestGCTaskStore_ConflictDifferentParams626=== PAUSE TestGCTaskStore_ConflictDifferentParams627=== RUN TestGCTaskStore_GetEmpty628=== PAUSE TestGCTaskStore_GetEmpty629=== RUN TestGCTaskStore_GetReturnsLatest630=== PAUSE TestGCTaskStore_GetReturnsLatest631=== RUN TestGCTaskStore_CompletedAllowsNewTask632=== PAUSE TestGCTaskStore_CompletedAllowsNewTask633=== RUN TestGCTaskStore_PhaseUpdates634=== PAUSE TestGCTaskStore_PhaseUpdates635=== RUN TestGCTaskStore_Fail636=== PAUSE TestGCTaskStore_Fail637=== RUN TestGracefulShutdownDrainsInflight638=== PAUSE TestGracefulShutdownDrainsInflight639=== RUN TestService_healthCheckHandler640=== PAUSE TestService_healthCheckHandler641=== RUN TestService_readinessHandler642=== PAUSE TestService_readinessHandler643=== RUN TestGenerateLandingPage644=== PAUSE TestGenerateLandingPage645=== RUN TestCacheConfigHandlerMaxNarSize646=== PAUSE TestCacheConfigHandlerMaxNarSize647=== RUN TestCreatePendingClosureRejectsOversizedNAR648=== PAUSE TestCreatePendingClosureRejectsOversizedNAR649=== RUN TestNARDeduplicationMetadataUploadBug650=== PAUSE TestNARDeduplicationMetadataUploadBug651=== RUN TestMetricsInventory652=== PAUSE TestMetricsInventory653=== RUN TestMetricsCommit654=== PAUSE TestMetricsCommit655=== RUN TestService_NativeMTLS656=== PAUSE TestService_NativeMTLS657=== RUN TestServerTLSConfig658=== PAUSE TestServerTLSConfig659=== RUN TestMultipartCleanup660=== PAUSE TestMultipartCleanup661=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded662=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded663=== RUN TestPendingCleanupUsesOneCutoff664=== PAUSE TestPendingCleanupUsesOneCutoff665=== RUN TestObjectStatsTrigger666=== PAUSE TestObjectStatsTrigger667=== RUN TestObjectStatsLargeCommit668=== PAUSE TestObjectStatsLargeCommit669=== RUN TestOrphanedObjectsGC670=== PAUSE TestOrphanedObjectsGC671=== RUN TestOrphanedObjectsGCStressTest672=== PAUSE TestOrphanedObjectsGCStressTest673=== RUN TestCreatePin_ReservedPins674=== PAUSE TestCreatePin_ReservedPins675=== RUN TestPresentReportsOnlyClosureRoots676=== PAUSE TestPresentReportsOnlyClosureRoots677=== RUN TestPresentRefreshesOnlyStaleClosures678=== PAUSE TestPresentRefreshesOnlyStaleClosures679=== RUN TestPresentNotReportedWhileGCDeletesClosure680=== PAUSE TestPresentNotReportedWhileGCDeletesClosure681=== RUN TestParseSingleRange682=== PAUSE TestParseSingleRange683=== RUN TestProxyHeadersOnlyTrustedOnSocket6842026/10/14 16:41:52 INFO Starting HTTP server address=proxy.sock6852026/10/14 16:41:52 INFO Starting HTTP server address=127.0.0.1:451136862026/10/14 16:41:52 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6872026/10/14 16:41:52 INFO Shutdown signal received, draining in-flight requests timeout=10s688--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.11s)689=== RUN TestIsValidCachePath690=== PAUSE TestIsValidCachePath691=== RUN TestReadProxyNarinfo692=== PAUSE TestReadProxyNarinfo693=== RUN TestReadProxyNarinfoAlreadyDecompressed694=== PAUSE TestReadProxyNarinfoAlreadyDecompressed695=== RUN TestReadProxyContentNegotiation696=== PAUSE TestReadProxyContentNegotiation697=== RUN TestReadProxyNarStreaming698=== PAUSE TestReadProxyNarStreaming699=== RUN TestReadProxy404700=== PAUSE TestReadProxy404701=== RUN TestReadProxyInvalidPath702=== PAUSE TestReadProxyInvalidPath703=== RUN TestReadProxyHead704=== PAUSE TestReadProxyHead705=== RUN TestReadProxyOutlastsServerWriteTimeout706=== PAUSE TestReadProxyOutlastsServerWriteTimeout707=== RUN TestReadProxyConditionalGet708=== PAUSE TestReadProxyConditionalGet709=== RUN TestReadProxyRootRedirectsToIndexHTML710=== PAUSE TestReadProxyRootRedirectsToIndexHTML711=== RUN TestReadProxyDisabled712=== PAUSE TestReadProxyDisabled713=== RUN TestReadRedirectNar714=== PAUSE TestReadRedirectNar715=== RUN TestReadRedirectKeepsNarinfoProxied716=== PAUSE TestReadRedirectKeepsNarinfoProxied717=== RUN TestReadProxyRangeRequest718=== PAUSE TestReadProxyRangeRequest719=== RUN TestReadRedirectUsesPublicS3URL720=== PAUSE TestReadRedirectUsesPublicS3URL721=== RUN TestPush_OverlappingRootsStoreOneRowPerKey722=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey723=== RUN TestPush_CompleteCommitsEveryRoot724=== PAUSE TestPush_CompleteCommitsEveryRoot725=== RUN TestPush_RepeatedRootCommitsOnce726=== PAUSE TestPush_RepeatedRootCommitsOnce727=== RUN TestPush_CompleteWaitsForCleanupOfThePush728=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush729=== RUN TestPush_RootsAreLockedInByteOrder730=== PAUSE TestPush_RootsAreLockedInByteOrder731=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit732=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit733=== RUN TestPush_RejectsBadRequests734=== PAUSE TestPush_RejectsBadRequests735=== RUN TestPush_SignsNarinfosOfItsPendingObjects736=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects737=== RUN TestRedundantMultipartUpload738=== PAUSE TestRedundantMultipartUpload739=== RUN TestCompleteMultipartUpload_ErrorButObjectExists740=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists741=== RUN TestCompletedNarNotReofferedAcrossClosures742=== PAUSE TestCompletedNarNotReofferedAcrossClosures743=== RUN TestPresignedUploadRegisteredBeforeCommit744=== PAUSE TestPresignedUploadRegisteredBeforeCommit745=== RUN TestService_Rustfstest746=== PAUSE TestService_Rustfstest747=== RUN TestParseSize748=== PAUSE TestParseSize749=== RUN TestSkippedUploadsHandler750=== PAUSE TestSkippedUploadsHandler751=== RUN TestSystemdListenerNotActivated752--- PASS: TestSystemdListenerNotActivated (0.00s)753=== RUN TestWatchdogBeatsWhenHealthy754--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)755=== RUN TestWatchdogSkipsWhenUnhealthy7562026/10/14 16:41:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7572026/10/14 16:41:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7582026/10/14 16:41:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7592026/10/14 16:41:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7602026/10/14 16:41:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7612026/10/14 16:41:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7622026/10/14 16:41:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7632026/10/14 16:41:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7642026/10/14 16:41:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7652026/10/14 16:41:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"766--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)767=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle768=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle769=== RUN TestProxyWriteTimeout770=== PAUSE TestProxyWriteTimeout771=== RUN TestPendingClosureWriteTimeout772=== PAUSE TestPendingClosureWriteTimeout773=== RUN TestIsValidUploadKey774=== PAUSE TestIsValidUploadKey775=== RUN TestUploadHandlersRejectInvalidKeys776=== PAUSE TestUploadHandlersRejectInvalidKeys777=== RUN TestUploadHandlersRejectOversizedBody778=== PAUSE TestUploadHandlersRejectOversizedBody779=== RUN TestService_cleanupPendingClosuresHandler780=== PAUSE TestService_cleanupPendingClosuresHandler781=== RUN TestService_createPendingClosureHandler782=== PAUSE TestService_createPendingClosureHandler783=== RUN TestService_verifyS3Integrity784=== PAUSE TestService_verifyS3Integrity785=== RUN TestCompleteMultipartUnregistered786=== PAUSE TestCompleteMultipartUnregistered787=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT788=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT789=== CONT TestSkippedUploadsHandler790=== CONT TestService_AuthMiddleware791=== CONT TestParseSize792--- PASS: TestParseSize (0.00s)793=== CONT TestService_createPendingClosureHandler794=== CONT TestService_Rustfstest795=== CONT TestPresignedUploadRegisteredBeforeCommit7962026/10/14 16:41:52 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000797=== CONT TestCompletedNarNotReofferedAcrossClosures798=== CONT TestCompleteMultipartUpload_ErrorButObjectExists799=== CONT TestRedundantMultipartUpload800=== CONT TestPush_SignsNarinfosOfItsPendingObjects801=== CONT TestPush_RejectsBadRequests802=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit803=== CONT TestPush_RootsAreLockedInByteOrder804=== CONT TestPush_CompleteWaitsForCleanupOfThePush805=== CONT TestPush_RepeatedRootCommitsOnce806=== CONT TestPush_CompleteCommitsEveryRoot807=== CONT TestPush_OverlappingRootsStoreOneRowPerKey808=== CONT TestReadRedirectUsesPublicS3URL809=== CONT TestUploadHandlersRejectOversizedBody810=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT811=== CONT TestReadProxyRangeRequest812=== CONT TestCompleteMultipartUnregistered813=== CONT TestReadRedirectKeepsNarinfoProxied814=== CONT TestService_verifyS3Integrity815=== CONT TestReadRedirectNar816--- PASS: TestSkippedUploadsHandler (0.01s)817=== CONT TestService_cleanupPendingClosuresHandler818=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure819=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure820=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart821=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart822=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts823=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts824=== CONT TestReadProxyDisabled825--- PASS: TestService_Rustfstest (0.35s)826=== CONT TestReadProxyRootRedirectsToIndexHTML8272026/10/14 16:41:53 INFO Received uploads request method=POST path=/api/pending_closures828=== RUN TestPush_RejectsBadRequests/no_objects829=== PAUSE TestPush_RejectsBadRequests/no_objects830=== RUN TestPush_RejectsBadRequests/bad_root831=== PAUSE TestPush_RejectsBadRequests/bad_root832=== RUN TestPush_RejectsBadRequests/root_not_in_objects833=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects834=== RUN TestPush_RejectsBadRequests/no_roots835=== PAUSE TestPush_RejectsBadRequests/no_roots836=== CONT TestGCEndsOnShutdown837=== RUN TestGCEndsOnShutdown/before_the_run838=== PAUSE TestGCEndsOnShutdown/before_the_run839=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete840=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete841=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark842=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark843=== CONT TestCommitRacingPendingCleanupKeepsObjects8442026/10/14 16:41:53 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"845--- PASS: TestService_AuthMiddleware (0.41s)846=== CONT TestReadProxyConditionalGet8472026/10/14 16:41:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8482026/10/14 16:41:53 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Y2FkMmM5N2UtMWZkMC00N2U0LWJhNjQtMmU2NTczZmEyOWYyLjYzMGYyMWY3LWQ0N2QtNDEyOC04OGM5LWE4MWFkMmNhZDliOHgxNzkxOTk2MTEzMzIxNTcwMjUy8492026/10/14 16:41:53 INFO Received uploads request method=POST path=/api/pending_closures8502026/10/14 16:41:53 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Y2FkMmM5N2UtMWZkMC00N2U0LWJhNjQtMmU2NTczZmEyOWYyLjYzMGYyMWY3LWQ0N2QtNDEyOC04OGM5LWE4MWFkMmNhZDliOHgxNzkxOTk2MTEzMzIxNTcwMjUy parts=1851--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.43s)852=== CONT TestPushWaitsForSweepHoldingRow8532026/10/14 16:41:53 INFO Received uploads request method=POST path=/api/pending_closures8542026/10/14 16:41:53 INFO Received uploads request method=POST path=/api/pending_closures8552026/10/14 16:41:53 INFO Received uploads request method=POST path=/api/pending_closures8562026/10/14 16:41:53 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst8572026/10/14 16:41:53 INFO Received push request method=POST path=/api/pushes8582026/10/14 16:41:53 INFO Received uploads request method=POST path=/api/pending_closures859--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.49s)860=== CONT TestReadProxyOutlastsServerWriteTimeout8612026/10/14 16:41:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8622026/10/14 16:41:53 INFO Signed narinfos id=1 count=18632026/10/14 16:41:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8642026/10/14 16:41:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8652026/10/14 16:41:53 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"8662026/10/14 16:41:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8672026/10/14 16:41:53 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"8682026/10/14 16:41:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8692026/10/14 16:41:53 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=18702026/10/14 16:41:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8712026/10/14 16:41:53 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo872--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.50s)873=== CONT TestSweepRechecksPendingAfterLocking8742026/10/14 16:41:53 INFO Received push request method=POST path=/api/pushes8752026/10/14 16:41:53 INFO Received complete push request method=POST path=/api/pushes/1/complete8762026/10/14 16:41:53 INFO Received push request method=POST path=/api/pushes8772026/10/14 16:41:53 INFO Completed push id=1 objects=4 duration=9.525824ms8782026/10/14 16:41:53 INFO Received push request method=POST path=/api/pushes8792026/10/14 16:41:53 INFO Received uploads request method=POST path=/api/pending_closures8802026/10/14 16:41:53 INFO Received uploads request method=POST path=/api/pending_closures8812026/10/14 16:41:53 INFO Received uploads request method=POST path=/api/pending_closures8822026/10/14 16:41:53 INFO Received push request method=POST path=/api/pushes8832026/10/14 16:41:53 INFO Received complete push request method=POST path=/api/pushes/1/complete8842026/10/14 16:41:53 INFO Aborted multipart uploads count=0 kept=08852026/10/14 16:41:53 INFO Received push request method=POST path=/api/pushes8862026/10/14 16:41:53 WARN Force mode enabled - objects will be deleted immediately without grace period8872026/10/14 16:41:53 INFO Completed push id=1 objects=6 duration=9.066801ms888--- PASS: TestPush_CompleteCommitsEveryRoot (0.61s)889=== CONT TestReadProxyHead8902026/10/14 16:41:53 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=08912026/10/14 16:41:53 INFO Vacuumed table table=pending_closures8922026/10/14 16:41:53 INFO Vacuumed table table=pending_objects8932026/10/14 16:41:53 INFO Vacuumed table table=multipart_uploads8942026/10/14 16:41:53 INFO Vacuumed table table=closures8952026/10/14 16:41:53 INFO Vacuumed table table=objects8962026/10/14 16:41:53 INFO Received complete push request method=POST path=/api/pushes/2/complete8972026/10/14 16:41:53 INFO Completed push id=2 objects=4 duration=4.079196ms898--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.64s)899=== CONT TestGetExistingObjectsLocksRows9002026-10-14 16:41:53.583 UTC [512] ERROR: could not obtain lock on row in relation "closures"9012026-10-14 16:41:53.583 UTC [512] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9022026-10-14 16:41:53.584 UTC [512] ERROR: could not obtain lock on row in relation "closures"9032026-10-14 16:41:53.584 UTC [512] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9042026-10-14 16:41:53.585 UTC [512] ERROR: could not obtain lock on row in relation "closures"9052026-10-14 16:41:53.585 UTC [512] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9062026-10-14 16:41:53.585 UTC [512] ERROR: could not obtain lock on row in relation "closures"9072026-10-14 16:41:53.585 UTC [512] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9082026-10-14 16:41:53.585 UTC [512] ERROR: could not obtain lock on row in relation "closures"9092026-10-14 16:41:53.585 UTC [512] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT910--- PASS: TestPush_RootsAreLockedInByteOrder (0.65s)911=== CONT TestReadProxyInvalidPath912--- PASS: TestReadRedirectUsesPublicS3URL (0.65s)913=== CONT TestRegisterCompletedObjectNeedsPendingRow9142026/10/14 16:41:53 INFO Received push request method=POST path=/api/pushes9152026/10/14 16:41:53 INFO Received uploads request method=POST path=/api/pending_closures9162026/10/14 16:41:53 INFO Received complete push request method=POST path=/api/pushes/1/complete9172026/10/14 16:41:53 INFO Completed push id=1 objects=4 duration=10.684215ms918--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.69s)919=== CONT TestReadProxy404920--- PASS: TestPush_RepeatedRootCommitsOnce (0.69s)921=== CONT TestReadProxyNarStreaming9222026/10/14 16:41:53 INFO Received cleanup request method=DELETE path=/api/pending_closures9232026/10/14 16:41:53 INFO Aborted multipart uploads count=0 kept=09242026/10/14 16:41:53 INFO Received uploads request method=POST path=/api/pending_closures9252026/10/14 16:41:53 INFO Received cleanup request method=DELETE path=/api/pending_closures9262026/10/14 16:41:53 INFO Aborted multipart uploads count=1 kept=09272026/10/14 16:41:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9282026-10-14 16:41:53.665 UTC [477] ERROR: Closure does not exist: id=19292026-10-14 16:41:53.665 UTC [477] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9302026-10-14 16:41:53.665 UTC [477] STATEMENT: -- name: CommitPendingClosure :one931 SELECT commit_pending_closure($1::bigint)::bigint932 933--- PASS: TestService_cleanupPendingClosuresHandler (0.72s)934=== CONT TestSweepSkipsRowsLockedByPush9352026/10/14 16:41:53 INFO Received push request method=POST path=/api/pushes9362026/10/14 16:41:53 INFO Received uploads request method=POST path=/api/pending_closures937--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.75s)938=== CONT TestReadProxyContentNegotiation939--- PASS: TestReadRedirectKeepsNarinfoProxied (0.79s)940=== CONT TestFailedS3DeleteKeepsTombstone9412026/10/14 16:41:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete942--- PASS: TestReadProxyRangeRequest (0.81s)943=== CONT TestReadProxyNarinfoAlreadyDecompressed9442026/10/14 16:41:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9452026/10/14 16:41:53 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=Y2FkMmM5N2UtMWZkMC00N2U0LWJhNjQtMmU2NTczZmEyOWYyLjQzZDljMDA1LTYzODktNGEwNi04ZWFkLTc5NTU2YTliMmYzZHgxNzkxOTk2MTEzMzcwNTMyOTI4 parts=129462026/10/14 16:41:53 INFO Received uploads request method=POST path=/api/pending_closures9472026/10/14 16:41:53 INFO Received uploads request method=POST path=/api/pending_closures9482026/10/14 16:41:53 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=Y2FkMmM5N2UtMWZkMC00N2U0LWJhNjQtMmU2NTczZmEyOWYyLjU2YjM0YjVjLWFjMTYtNDRkNy04OWU3LTgyZTc5ZjUyZWU5N3gxNzkxOTk2MTEzMzkxNzExNzU2 parts=129492026/10/14 16:41:53 INFO Received uploads request method=POST path=/api/pending_closures950--- PASS: TestReadRedirectNar (0.84s)951=== CONT TestForceGCDuringPushOffersSweptObject952=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows953=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows954=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check955=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check956=== CONT TestReadProxyNarinfo957--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.85s)958=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection9592026-10-14 16:41:53.794 UTC [502] ERROR: Push does not exist: id=19602026-10-14 16:41:53.794 UTC [502] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE9612026-10-14 16:41:53.794 UTC [502] STATEMENT: SELECT commit_push($1)962--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.85s)963=== CONT TestIsValidCachePath964=== RUN TestIsValidCachePath/narinfo965=== PAUSE TestIsValidCachePath/narinfo966=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars967=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars968=== RUN TestIsValidCachePath/nar_zst969=== PAUSE TestIsValidCachePath/nar_zst970=== RUN TestIsValidCachePath/nar_xz971=== PAUSE TestIsValidCachePath/nar_xz972=== RUN TestIsValidCachePath/nar_bz2973=== PAUSE TestIsValidCachePath/nar_bz2974=== RUN TestIsValidCachePath/nar_uncompressed975=== PAUSE TestIsValidCachePath/nar_uncompressed976=== RUN TestIsValidCachePath/ls977=== PAUSE TestIsValidCachePath/ls978=== RUN TestIsValidCachePath/log979=== PAUSE TestIsValidCachePath/log980=== RUN TestIsValidCachePath/realisation981=== PAUSE TestIsValidCachePath/realisation982=== RUN TestIsValidCachePath/nix-cache-info983=== PAUSE TestIsValidCachePath/nix-cache-info984=== RUN TestIsValidCachePath/index.html985=== PAUSE TestIsValidCachePath/index.html986=== RUN TestIsValidCachePath/traversal_parent987=== PAUSE TestIsValidCachePath/traversal_parent988=== RUN TestIsValidCachePath/traversal_in_middle989=== PAUSE TestIsValidCachePath/traversal_in_middle990=== RUN TestIsValidCachePath/invalid_char_e991=== PAUSE TestIsValidCachePath/invalid_char_e992=== RUN TestIsValidCachePath/invalid_char_u993=== PAUSE TestIsValidCachePath/invalid_char_u994=== RUN TestIsValidCachePath/random_path995=== PAUSE TestIsValidCachePath/random_path996=== RUN TestIsValidCachePath/empty997=== PAUSE TestIsValidCachePath/empty998=== RUN TestIsValidCachePath/leading_slash999=== PAUSE TestIsValidCachePath/leading_slash1000=== RUN TestIsValidCachePath/wrong_extension1001=== PAUSE TestIsValidCachePath/wrong_extension1002=== RUN TestIsValidCachePath/short_hash1003=== PAUSE TestIsValidCachePath/short_hash1004=== CONT TestClientPushesUseOnePush10052026/10/14 16:41:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10062026/10/14 16:41:53 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1007--- PASS: TestCompleteMultipartUnregistered (0.86s)1008=== CONT TestParseSingleRange1009=== RUN TestParseSingleRange/none1010=== PAUSE TestParseSingleRange/none1011=== RUN TestParseSingleRange/unknown_unit1012=== PAUSE TestParseSingleRange/unknown_unit1013=== RUN TestParseSingleRange/multi-range_ignored1014=== PAUSE TestParseSingleRange/multi-range_ignored1015=== RUN TestParseSingleRange/malformed_no_dash1016=== PAUSE TestParseSingleRange/malformed_no_dash1017=== RUN TestParseSingleRange/malformed_both_empty1018=== PAUSE TestParseSingleRange/malformed_both_empty1019=== RUN TestParseSingleRange/malformed_end_before_start1020=== PAUSE TestParseSingleRange/malformed_end_before_start1021=== RUN TestParseSingleRange/closed1022=== PAUSE TestParseSingleRange/closed1023=== RUN TestParseSingleRange/open-ended1024=== PAUSE TestParseSingleRange/open-ended1025=== RUN TestParseSingleRange/end_clamped_to_size1026=== PAUSE TestParseSingleRange/end_clamped_to_size1027=== RUN TestParseSingleRange/suffix1028=== PAUSE TestParseSingleRange/suffix1029=== RUN TestParseSingleRange/suffix_exceeds_size1030=== PAUSE TestParseSingleRange/suffix_exceeds_size1031=== RUN TestParseSingleRange/single_byte1032=== PAUSE TestParseSingleRange/single_byte1033=== RUN TestParseSingleRange/start_past_EOF1034=== PAUSE TestParseSingleRange/start_past_EOF1035=== RUN TestParseSingleRange/start_far_past_EOF1036=== PAUSE TestParseSingleRange/start_far_past_EOF1037=== CONT TestPinProtectsFromGC10382026/10/14 16:41:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1039--- PASS: TestReadProxyDisabled (0.71s)1040=== CONT TestPresentNotReportedWhileGCDeletesClosure1041=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1042=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1043=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1044=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1045=== CONT TestClientSharedPathCommittedMidPush10462026/10/14 16:41:53 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=Y2FkMmM5N2UtMWZkMC00N2U0LWJhNjQtMmU2NTczZmEyOWYyLmIwMjg5ZmY0LTMxODMtNDE4Zi04ODQwLTZkY2Q3MDZkNWQ4YXgxNzkxOTk2MTEzNTA5OTU2NjI5 parts=1010472026/10/14 16:41:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10482026/10/14 16:41:53 INFO Completed upload id=1 objects=2 duration=3.37687ms10492026/10/14 16:41:53 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010502026/10/14 16:41:53 INFO Received uploads request method=POST path=/api/pending_closures1051--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.57s)1052=== CONT TestPresentRefreshesOnlyStaleClosures10532026/10/14 16:41:53 INFO Starting cleanup of old closures method=DELETE path=/api/closures10542026/10/14 16:41:53 INFO Aborted multipart uploads count=0 kept=010552026/10/14 16:41:53 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=010562026/10/14 16:41:53 INFO Vacuumed table table=pending_closures10572026/10/14 16:41:53 INFO Vacuumed table table=pending_objects10582026/10/14 16:41:53 INFO Vacuumed table table=multipart_uploads10592026/10/14 16:41:53 INFO Vacuumed table table=closures10602026/10/14 16:41:53 INFO Vacuumed table table=objects10612026/10/14 16:41:53 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001062--- PASS: TestService_createPendingClosureHandler (0.96s)1063=== CONT TestClientWithDependencies1064--- PASS: TestReadProxyConditionalGet (0.57s)1065=== CONT TestPresentReportsOnlyClosureRoots10662026/10/14 16:41:53 INFO Aborted multipart uploads count=0 kept=010672026/10/14 16:41:53 WARN Force mode enabled - objects will be deleted immediately without grace period10682026/10/14 16:41:53 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=010692026/10/14 16:41:53 INFO Vacuumed table table=pending_closures10702026/10/14 16:41:53 INFO Vacuumed table table=pending_objects10712026/10/14 16:41:53 INFO Vacuumed table table=multipart_uploads10722026/10/14 16:41:53 INFO Vacuumed table table=closures10732026/10/14 16:41:53 INFO Vacuumed table table=objects10742026/10/14 16:41:53 INFO Received uploads request method=POST path=/api/pending_closures1075--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.62s)1076=== CONT TestClientMultipleUploads10772026/10/14 16:41:53 INFO Aborted multipart uploads count=0 kept=010782026/10/14 16:41:54 WARN Force mode enabled - objects will be deleted immediately without grace period10792026/10/14 16:41:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1080--- PASS: TestReadProxyHead (0.46s)1081=== CONT TestCreatePin_ReservedPins10822026/10/14 16:41:54 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=010832026/10/14 16:41:54 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=Y2FkMmM5N2UtMWZkMC00N2U0LWJhNjQtMmU2NTczZmEyOWYyLmE0OWEzMTRmLTRlNTEtNDMyMy04ODA2LTZkOGYyODQwZDRiYXgxNzkxOTk2MTEzNzAwMjExOTYy parts=1010842026/10/14 16:41:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10852026/10/14 16:41:54 INFO Vacuumed table table=pending_closures10862026/10/14 16:41:54 INFO Vacuumed table table=pending_objects10872026/10/14 16:41:54 INFO Completed upload id=1 objects=2 duration=2.23506ms10882026/10/14 16:41:54 INFO Vacuumed table table=multipart_uploads10892026/10/14 16:41:54 INFO Vacuumed table table=closures10902026/10/14 16:41:54 INFO Vacuumed table table=objects10912026/10/14 16:41:54 INFO Received uploads request method=POST path=/api/pending_closures1092--- PASS: TestSweepRechecksPendingAfterLocking (0.58s)1093=== CONT TestClientIntegration10942026/10/14 16:41:54 INFO Received uploads request method=POST path=/api/pending_closures1095--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.44s)1096=== CONT TestOrphanedObjectsGCStressTest10972026/10/14 16:41:54 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10982026/10/14 16:41:54 WARN Found objects in DB but missing from S3, will re-upload count=11099--- PASS: TestService_verifyS3Integrity (1.09s)1100=== CONT TestClientErrorHandling1101=== RUN TestClientErrorHandling/InvalidStorePath1102=== PAUSE TestClientErrorHandling/InvalidStorePath1103=== RUN TestClientErrorHandling/InvalidAuthToken1104=== PAUSE TestClientErrorHandling/InvalidAuthToken1105=== RUN TestClientErrorHandling/ServerNotAvailable1106=== PAUSE TestClientErrorHandling/ServerNotAvailable1107=== CONT TestOrphanedObjectsGC1108--- PASS: TestGetExistingObjectsLocksRows (0.48s)1109=== CONT TestClientFallsBackToClosures1110--- PASS: TestReadProxyInvalidPath (0.48s)1111=== CONT TestObjectStatsLargeCommit11122026/10/14 16:41:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35293/oidc1113--- PASS: TestReadProxy404 (0.48s)1114=== CONT TestClientCADerivations1115--- PASS: TestReadProxyNarStreaming (0.49s)1116=== CONT TestGCSweepDeliversEachKeyOnce11172026/10/14 16:41:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11182026/10/14 16:41:54 INFO Aborted multipart uploads count=0 kept=011192026/10/14 16:41:54 WARN Force mode enabled - objects will be deleted immediately without grace period11202026/10/14 16:41:54 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=011212026/10/14 16:41:54 INFO Vacuumed table table=pending_closures11222026/10/14 16:41:54 INFO Vacuumed table table=pending_objects11232026/10/14 16:41:54 INFO Vacuumed table table=multipart_uploads11242026/10/14 16:41:54 INFO Vacuumed table table=closures11252026/10/14 16:41:54 INFO Vacuumed table table=objects11262026/10/14 16:41:54 INFO Received uploads request method=POST path=/api/pending_closures11272026/10/14 16:41:54 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=Y2FkMmM5N2UtMWZkMC00N2U0LWJhNjQtMmU2NTczZmEyOWYyLjEyNGU5ZDYwLTEwMGMtNDA4ZS05MjJiLTY4MjI5ZGRmYWE3YngxNzkxOTk2MTEzNzg0MDM3MTY4 error="Get \"http://127.0.0.1:1/bucket8/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"11282026/10/14 16:41:54 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=Y2FkMmM5N2UtMWZkMC00N2U0LWJhNjQtMmU2NTczZmEyOWYyLjkyNTk0OGExLTY1YjItNDM1My04MTk2LWI2OTI5NWZjYmFhNngxNzkxOTk2MTEzNzcwODY4NTEx parts=1211292026/10/14 16:41:54 INFO Received cleanup request method=DELETE path=/api/pending_closures11302026/10/14 16:41:54 INFO Aborted multipart uploads count=0 kept=011312026/10/14 16:41:54 INFO Aborted multipart uploads count=1 kept=011322026/10/14 16:41:54 WARN Force mode enabled - objects will be deleted immediately without grace period1133--- PASS: TestRedundantMultipartUpload (1.25s)1134=== CONT TestObjectStatsTrigger11352026/10/14 16:41:54 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=011362026/10/14 16:41:54 INFO Vacuumed table table=pending_closures11372026/10/14 16:41:54 INFO Vacuumed table table=pending_objects11382026/10/14 16:41:54 INFO Vacuumed table table=multipart_uploads11392026/10/14 16:41:54 INFO Vacuumed table table=closures11402026/10/14 16:41:54 INFO Vacuumed table table=objects1141--- PASS: TestSweepSkipsRowsLockedByPush (0.54s)1142=== CONT TestCacheStatsHandler1143--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.45s)1144=== CONT TestTombstonedObjectOfferedWithoutWaiting1145--- PASS: TestReadProxyContentNegotiation (0.53s)1146=== CONT TestPendingCleanupUsesOneCutoff11472026/10/14 16:41:54 INFO Received uploads request method=POST path=/api/pending_closures11482026/10/14 16:41:54 INFO Aborted multipart uploads count=0 kept=011492026/10/14 16:41:54 WARN Force mode enabled - objects will be deleted immediately without grace period11502026/10/14 16:41:54 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."11512026/10/14 16:41:54 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1152--- PASS: TestFailedS3DeleteKeepsTombstone (0.56s)1153=== CONT TestCacheConfigHandler1154=== RUN TestCacheConfigHandler/full_config,_no_issuer1155=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1156=== RUN TestCacheConfigHandler/no_cache_url_configured1157=== PAUSE TestCacheConfigHandler/no_cache_url_configured1158=== RUN TestCacheConfigHandler/no_signing_keys1159=== PAUSE TestCacheConfigHandler/no_signing_keys1160=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1161=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1162=== CONT TestGCSweepSkipsPendingObjects11632026/10/14 16:41:54 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1164--- PASS: TestReadProxyNarinfo (0.53s)1165=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1166--- PASS: TestPresentRefreshesOnlyStaleClosures (0.50s)1167=== CONT TestService_ReadScope_PublicByDefault1168=== NAME TestPinProtectsFromGC1169 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC2379313037/001/store/c36paasx068dc4rqlr09bd73yll5kazv-pinned-file.txt1170 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC2379313037/001/store/rpc9w9jydaqylgbf2pyis09f1xayaw8g-unpinned-file.txt1171--- PASS: TestPresentReportsOnlyClosureRoots (0.48s)1172=== CONT TestDeduplicatedObjectsRecordedAsPending1173--- PASS: TestPushWaitsForSweepHoldingRow (1.07s)1174=== CONT TestMultipartCleanup1175=== NAME TestClientMultipleUploads1176 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads2938140325/001/store/w28bp9vscnjzim3am4h4q6q87xqmqx34-test-file-0.txt11772026/10/14 16:41:54 INFO Received push request method=POST path=/api/pushes1178=== NAME TestClientWithDependencies1179 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies588460805/001/store/39g66ldpcgqqir8mh3n91imvm8whd0na-test-script11802026/10/14 16:41:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11812026/10/14 16:41:54 INFO Uploading c36paasx068dc4rqlr09bd73yll5kazv-pinned-file.txt (128B)11822026/10/14 16:41:54 WARN Failed to register uploaded object key=c36paasx068dc4rqlr09bd73yll5kazv.ls error="server returned 404: 404 page not found\n"11832026/10/14 16:41:54 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"11842026/10/14 16:41:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11852026/10/14 16:41:54 INFO Signed narinfos id=1 count=111862026/10/14 16:41:54 INFO Uploading 1 narinfos1187--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.68s)1188=== CONT TestService_RequireScope_OIDC11892026/10/14 16:41:54 INFO Received push request method=POST path=/api/pushes11902026/10/14 16:41:54 INFO Received complete push request method=POST path=/api/pushes/1/complete11912026/10/14 16:41:54 WARN Failed to register uploaded object key=c36paasx068dc4rqlr09bd73yll5kazv.narinfo error="server returned 404: 404 page not found\n"1192=== NAME TestClientIntegration1193 client_integration_test.go:286: Created store path: /build/TestClientIntegration4118429909/002/store/gi3yj6sw7i5gc7ynylicmjriwrl42wxi-test-file.txt11942026/10/14 16:41:54 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11952026/10/14 16:41:54 INFO Uploading mw8qhma5vqvi5if567bm0ibw6q1xbc1h-a (216B)11962026/10/14 16:41:54 INFO Uploading 6n15jxiz00rqbv5wp0k06j5cyhpfsvak-shared-dep (136B)11972026/10/14 16:41:54 INFO Received push request method=POST path=/api/pushes11982026/10/14 16:41:54 INFO Completed push id=1 objects=3 duration=6.69892ms11992026/10/14 16:41:54 INFO Upload complete. (62ms)12002026/10/14 16:41:54 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)12012026/10/14 16:41:54 INFO Uploading cw620xmp5vh0bd1fbrfpd87c6pr0lb8q-top (224B)12022026/10/14 16:41:54 INFO Uploading rxqx8qdp06j6g79s258mfyia8v8zzqyg-shared-dep (136B)12032026/10/14 16:41:54 WARN Failed to register uploaded object key=l6m0ihgyxjxn2yh3ilazd67rgsjrsq36.ls error="server returned 404: 404 page not found\n"12042026/10/14 16:41:54 WARN Failed to register uploaded object key=6n15jxiz00rqbv5wp0k06j5cyhpfsvak.ls error="server returned 404: 404 page not found\n"12052026/10/14 16:41:54 WARN Failed to register uploaded object key=nar/0008rml5bvrm59z0k7kiixynp2pircq5209f6933v3pckymrg0xz.nar.zst error="server returned 404: 404 page not found\n"12062026/10/14 16:41:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12072026/10/14 16:41:54 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12082026/10/14 16:41:54 WARN Failed to register uploaded object key=mw8qhma5vqvi5if567bm0ibw6q1xbc1h.ls error="server returned 404: 404 page not found\n"12092026/10/14 16:41:54 INFO Signed narinfos id=1 count=312102026/10/14 16:41:54 INFO Uploading 3 narinfos12112026/10/14 16:41:54 WARN Failed to register uploaded object key=cw620xmp5vh0bd1fbrfpd87c6pr0lb8q.ls error="server returned 404: 404 page not found\n"12122026/10/14 16:41:54 WARN Failed to register uploaded object key=rxqx8qdp06j6g79s258mfyia8v8zzqyg.ls error="server returned 404: 404 page not found\n"1213=== NAME TestClientMultipleUploads1214 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads2938140325/001/store/ykfgysvl2azbw82ia5rfksy7z9wdbxwy-test-file-1.txt12152026/10/14 16:41:54 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12162026/10/14 16:41:54 WARN Failed to register uploaded object key=nar/1il1dz1w8vf6vxxmp8bha17zbndpn9k9vdhxl55pa7mk1c10lfdq.nar.zst error="server returned 404: 404 page not found\n"12172026/10/14 16:41:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12182026/10/14 16:41:54 WARN Failed to register uploaded object key=mw8qhma5vqvi5if567bm0ibw6q1xbc1h.narinfo error="server returned 404: 404 page not found\n"12192026/10/14 16:41:54 INFO Signed narinfos id=1 count=212202026/10/14 16:41:54 INFO Uploading 2 narinfos12212026/10/14 16:41:54 INFO Received complete push request method=POST path=/api/pushes/1/complete12222026/10/14 16:41:54 WARN Failed to register uploaded object key=6n15jxiz00rqbv5wp0k06j5cyhpfsvak.narinfo error="server returned 404: 404 page not found\n"12232026/10/14 16:41:54 WARN Failed to register uploaded object key=l6m0ihgyxjxn2yh3ilazd67rgsjrsq36.narinfo error="server returned 404: 404 page not found\n"12242026/10/14 16:41:54 INFO Received complete push request method=POST path=/api/pushes/1/complete12252026/10/14 16:41:54 WARN Failed to register uploaded object key=rxqx8qdp06j6g79s258mfyia8v8zzqyg.narinfo error="server returned 404: 404 page not found\n"1226=== NAME TestClientWithDependencies12272026/10/14 16:41:54 WARN Failed to register uploaded object key=cw620xmp5vh0bd1fbrfpd87c6pr0lb8q.narinfo error="server returned 404: 404 page not found\n"1228 client_integration_test.go:615: Found 1 dependencies (including self)12292026/10/14 16:41:54 INFO Completed push id=1 objects=8 duration=6.971863ms12302026/10/14 16:41:54 INFO Upload complete. (60ms)1231=== NAME TestClientPushesUseOnePush1232 client_pushes_test.go:97: Retrieved narinfo from S3:1233 StorePath: /build/TestClientPushesUseOnePush3447719259/001/store/6n15jxiz00rqbv5wp0k06j5cyhpfsvak-shared-dep1234 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1235 Compression: zstd1236 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821237 NarSize: 1361238 References: 1239 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n12402026/10/14 16:41:54 INFO Completed push id=1 objects=6 duration=7.071762ms12412026/10/14 16:41:54 INFO Upload complete. (60ms)1242 client_pushes_test.go:97: Retrieved narinfo from S3:1243 StorePath: /build/TestClientPushesUseOnePush3447719259/001/store/mw8qhma5vqvi5if567bm0ibw6q1xbc1h-a1244 URL: nar/0008rml5bvrm59z0k7kiixynp2pircq5209f6933v3pckymrg0xz.nar.zst1245 Compression: zstd1246 NarHash: sha256:0008rml5bvrm59z0k7kiixynp2pircq5209f6933v3pckymrg0xz1247 NarSize: 2161248 References: /build/TestClientPushesUseOnePush3447719259/001/store/6n15jxiz00rqbv5wp0k06j5cyhpfsvak-shared-dep1249 CA: text:sha256:1l4xk8qnyklm8gsd57kp28ianqm9j3n5c2q25hw0sh2riwgwx9rd1250=== NAME TestClientSharedPathCommittedMidPush1251 client_integration_test.go:680: Retrieved narinfo from S3:1252 StorePath: /build/TestClientSharedPathCommittedMidPush354232889/001/store/rxqx8qdp06j6g79s258mfyia8v8zzqyg-shared-dep1253 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1254 Compression: zstd1255 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821256 NarSize: 1361257 References: 1258 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1259=== NAME TestClientPushesUseOnePush1260 client_pushes_test.go:97: Retrieved narinfo from S3:1261 StorePath: /build/TestClientPushesUseOnePush3447719259/001/store/l6m0ihgyxjxn2yh3ilazd67rgsjrsq36-b1262 URL: nar/0008rml5bvrm59z0k7kiixynp2pircq5209f6933v3pckymrg0xz.nar.zst1263 Compression: zstd1264 NarHash: sha256:0008rml5bvrm59z0k7kiixynp2pircq5209f6933v3pckymrg0xz1265 NarSize: 2161266 References: /build/TestClientPushesUseOnePush3447719259/001/store/6n15jxiz00rqbv5wp0k06j5cyhpfsvak-shared-dep1267 CA: text:sha256:1l4xk8qnyklm8gsd57kp28ianqm9j3n5c2q25hw0sh2riwgwx9rd1268=== NAME TestClientSharedPathCommittedMidPush1269 client_integration_test.go:680: Retrieved narinfo from S3:1270 StorePath: /build/TestClientSharedPathCommittedMidPush354232889/001/store/cw620xmp5vh0bd1fbrfpd87c6pr0lb8q-top1271 URL: nar/1il1dz1w8vf6vxxmp8bha17zbndpn9k9vdhxl55pa7mk1c10lfdq.nar.zst1272 Compression: zstd1273 NarHash: sha256:1il1dz1w8vf6vxxmp8bha17zbndpn9k9vdhxl55pa7mk1c10lfdq1274 NarSize: 2241275 References: /build/TestClientSharedPathCommittedMidPush354232889/001/store/rxqx8qdp06j6g79s258mfyia8v8zzqyg-shared-dep1276 CA: text:sha256:1ws2dylfdb7krdi0wchrjl18wc1f7q6xxkr3i4r2yym8m7q9c0fl1277--- PASS: TestClientPushesUseOnePush (0.71s)1278=== CONT TestPushDedupSurvivesConcurrentGC1279--- PASS: TestClientSharedPathCommittedMidPush (0.68s)1280=== CONT TestServerTLSConfig1281=== RUN TestServerTLSConfig/no_client_CA1282=== PAUSE TestServerTLSConfig/no_client_CA1283=== RUN TestServerTLSConfig/missing_CA_file1284=== PAUSE TestServerTLSConfig/missing_CA_file1285=== RUN TestServerTLSConfig/not_a_PEM_file1286=== PAUSE TestServerTLSConfig/not_a_PEM_file1287=== CONT TestService_AuthMiddleware_OIDC1288=== NAME TestClientMultipleUploads1289 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads2938140325/001/store/2jw6442ply67akp4291i94s6i829z1m7-test-file-2.txt12902026/10/14 16:41:54 INFO Received push request method=POST path=/api/pushes12912026/10/14 16:41:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12922026/10/14 16:41:54 INFO Uploading gi3yj6sw7i5gc7ynylicmjriwrl42wxi-test-file.txt (152B)12932026/10/14 16:41:54 INFO Received push request method=POST path=/api/pushes12942026/10/14 16:41:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12952026/10/14 16:41:54 INFO Uploading rpc9w9jydaqylgbf2pyis09f1xayaw8g-unpinned-file.txt (128B)12962026/10/14 16:41:54 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12972026/10/14 16:41:54 WARN Refused reserved pin name=worker-x86_64-linux12982026/10/14 16:41:54 WARN Failed to register uploaded object key=gi3yj6sw7i5gc7ynylicmjriwrl42wxi.ls error="server returned 404: 404 page not found\n"12992026/10/14 16:41:54 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13002026/10/14 16:41:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13012026/10/14 16:41:54 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"13022026/10/14 16:41:54 INFO Received create pin request method=POST path=/api/pins/my-app13032026/10/14 16:41:54 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13042026/10/14 16:41:54 INFO Signed narinfos id=1 count=113052026/10/14 16:41:54 INFO Uploading 1 narinfos1306--- PASS: TestCreatePin_ReservedPins (0.54s)1307=== CONT TestService_NativeMTLS13082026/10/14 16:41:54 WARN Failed to register uploaded object key=rpc9w9jydaqylgbf2pyis09f1xayaw8g.ls error="server returned 404: 404 page not found\n"13092026/10/14 16:41:54 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13102026/10/14 16:41:54 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"13112026/10/14 16:41:54 INFO Signed narinfos id=2 count=113122026/10/14 16:41:54 INFO Uploading 1 narinfos13132026/10/14 16:41:54 INFO Received complete push request method=POST path=/api/pushes/1/complete13142026/10/14 16:41:54 WARN Failed to register uploaded object key=gi3yj6sw7i5gc7ynylicmjriwrl42wxi.narinfo error="server returned 404: 404 page not found\n"13152026/10/14 16:41:54 INFO Received complete push request method=POST path=/api/pushes/2/complete13162026/10/14 16:41:54 WARN Failed to register uploaded object key=rpc9w9jydaqylgbf2pyis09f1xayaw8g.narinfo error="server returned 404: 404 page not found\n"13172026/10/14 16:41:54 INFO Received push request method=POST path=/api/pushes13182026/10/14 16:41:54 INFO Completed push id=2 objects=3 duration=8.552036ms13192026/10/14 16:41:54 INFO Completed push id=1 objects=3 duration=9.525845ms13202026/10/14 16:41:54 INFO Upload complete. (54ms)13212026/10/14 16:41:54 INFO Upload complete. (65ms)13222026/10/14 16:41:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13232026/10/14 16:41:54 INFO Uploading 39g66ldpcgqqir8mh3n91imvm8whd0na-test-script (136B)13242026/10/14 16:41:54 WARN Failed to register uploaded object key=39g66ldpcgqqir8mh3n91imvm8whd0na.ls error="server returned 404: 404 page not found\n"13252026/10/14 16:41:54 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"13262026/10/14 16:41:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13272026/10/14 16:41:54 WARN Failed to register uploaded object key=log/74zn008q99ycfrlhpy0m4f1ls60mj1qq-test-script.drv error="server returned 404: 404 page not found\n"13282026/10/14 16:41:54 INFO Signed narinfos id=1 count=113292026/10/14 16:41:54 INFO Uploading 1 narinfos13302026/10/14 16:41:54 INFO Received push request method=POST path=/api/pushes13312026/10/14 16:41:54 INFO Received complete push request method=POST path=/api/pushes/1/complete13322026/10/14 16:41:54 WARN Failed to register uploaded object key=39g66ldpcgqqir8mh3n91imvm8whd0na.narinfo error="server returned 404: 404 page not found\n"13332026/10/14 16:41:54 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)13342026/10/14 16:41:54 INFO Uploading 2jw6442ply67akp4291i94s6i829z1m7-test-file-2.txt (160B)13352026/10/14 16:41:54 INFO Uploading ykfgysvl2azbw82ia5rfksy7z9wdbxwy-test-file-1.txt (160B)13362026/10/14 16:41:54 INFO Uploading w28bp9vscnjzim3am4h4q6q87xqmqx34-test-file-0.txt (160B)13372026/10/14 16:41:54 INFO Completed push id=1 objects=4 duration=8.219713ms13382026/10/14 16:41:54 INFO Upload complete. (68ms)13392026/10/14 16:41:54 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"13402026/10/14 16:41:54 WARN Failed to register uploaded object key=w28bp9vscnjzim3am4h4q6q87xqmqx34.ls error="server returned 404: 404 page not found\n"1341=== NAME TestClientWithDependencies1342 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies588460805/001/store) requires matching store prefix13432026/10/14 16:41:54 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"13442026/10/14 16:41:54 WARN Failed to register uploaded object key=ykfgysvl2azbw82ia5rfksy7z9wdbxwy.ls error="server returned 404: 404 page not found\n"13452026/10/14 16:41:54 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"13462026/10/14 16:41:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13472026/10/14 16:41:54 WARN Failed to register uploaded object key=2jw6442ply67akp4291i94s6i829z1m7.ls error="server returned 404: 404 page not found\n"13482026/10/14 16:41:54 INFO Signed narinfos id=1 count=313492026/10/14 16:41:54 INFO Uploading 3 narinfos1350--- PASS: TestClientWithDependencies (0.70s)1351=== CONT TestGCMetrics13522026/10/14 16:41:54 WARN Failed to register uploaded object key=2jw6442ply67akp4291i94s6i829z1m7.narinfo error="server returned 404: 404 page not found\n"13532026/10/14 16:41:54 INFO Received complete push request method=POST path=/api/pushes/1/complete13542026/10/14 16:41:54 WARN Failed to register uploaded object key=w28bp9vscnjzim3am4h4q6q87xqmqx34.narinfo error="server returned 404: 404 page not found\n"13552026/10/14 16:41:54 WARN Failed to register uploaded object key=ykfgysvl2azbw82ia5rfksy7z9wdbxwy.narinfo error="server returned 404: 404 page not found\n"13562026/10/14 16:41:54 INFO Starting cleanup of old closures method=DELETE path=/api/closures13572026/10/14 16:41:54 INFO All 1 paths already cached13582026/10/14 16:41:54 INFO Garbage collection started1359=== NAME TestClientIntegration1360 client_integration_test.go:312: Retrieved narinfo from S3:1361 StorePath: /build/TestClientIntegration4118429909/002/store/gi3yj6sw7i5gc7ynylicmjriwrl42wxi-test-file.txt1362 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1363 Compression: zstd1364 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11365 NarSize: 1521366 References: 1367 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk113682026/10/14 16:41:54 INFO Completed push id=1 objects=9 duration=5.942293ms13692026/10/14 16:41:54 INFO Upload complete. (62ms)1370=== NAME TestClientMultipleUploads1371 client_integration_test.go:369: Uploaded 3 paths in 89.82048ms1372=== NAME TestClientIntegration1373 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1374 client_integration_test.go:313: Decompressed .ls content (64 bytes):1375 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1376 client_integration_test.go:316: Testing garbage collection...1377--- PASS: TestClientMultipleUploads (0.68s)1378=== CONT TestService_ReadAuthMiddleware13792026/10/14 16:41:54 INFO Aborted multipart uploads count=0 kept=013802026/10/14 16:41:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41589/oidc13812026/10/14 16:41:54 WARN Force mode enabled - objects will be deleted immediately without grace period1382--- PASS: TestObjectStatsTrigger (0.44s)1383=== CONT TestMetricsCommit13842026/10/14 16:41:54 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=013852026/10/14 16:41:54 INFO Vacuumed table table=pending_closures1386--- PASS: TestCacheStatsHandler (0.44s)1387=== CONT TestGCBugBareHashReferences13882026/10/14 16:41:54 INFO Starting cleanup of old closures method=DELETE path=/api/closures13892026/10/14 16:41:54 INFO Garbage collection started13902026/10/14 16:41:54 INFO Aborted multipart uploads count=0 kept=013912026/10/14 16:41:54 WARN Force mode enabled - objects will be deleted immediately without grace period13922026/10/14 16:41:54 INFO Aborted multipart uploads count=0 kept=013932026/10/14 16:41:54 INFO Vacuumed table table=pending_objects13942026/10/14 16:41:54 INFO Vacuumed table table=multipart_uploads1395=== NAME TestClientCADerivations1396 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1619145990/001/store/m4pwwfsyn5f8d5ldj7y9a1ky4a7b8ay8-ca-test13972026/10/14 16:41:54 INFO Vacuumed table table=closures13982026/10/14 16:41:54 INFO Vacuumed table table=objects13992026/10/14 16:41:54 INFO Received uploads request method=POST path=/api/pending_closures14002026/10/14 16:41:54 WARN Force mode enabled - objects will be deleted immediately without grace period1401--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.46s)1402=== CONT TestService_AuthMiddleware_MTLSBoundSubjects14032026/10/14 16:41:54 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=014042026/10/14 16:41:54 INFO Vacuumed table table=pending_closures14052026/10/14 16:41:54 INFO Vacuumed table table=pending_objects14062026/10/14 16:41:54 INFO Vacuumed table table=multipart_uploads14072026/10/14 16:41:54 INFO Vacuumed table table=closures14082026/10/14 16:41:54 INFO Vacuumed table table=objects1409--- PASS: TestGCSweepDeliversEachKeyOnce (0.56s)1410=== CONT TestMetricsInventory14112026/10/14 16:41:54 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=014122026/10/14 16:41:54 INFO Received uploads request method=POST path=/api/pending_closures14132026/10/14 16:41:54 INFO Vacuumed table table=pending_closures1414=== NAME TestClientCADerivations1415 client_ca_test.go:139: Found 1 dependencies (including self)14162026/10/14 16:41:54 INFO Received uploads request method=POST path=/api/pending_closures14172026/10/14 16:41:54 INFO Vacuumed table table=pending_objects14182026/10/14 16:41:54 INFO Vacuumed table table=multipart_uploads14192026/10/14 16:41:54 INFO Received uploads request method=POST path=/api/pending_closures14202026/10/14 16:41:54 INFO Vacuumed table table=closures14212026/10/14 16:41:54 INFO Received uploads request method=POST path=/api/pending_closures14222026/10/14 16:41:54 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14232026/10/14 16:41:54 INFO Vacuumed table table=objects14242026/10/14 16:41:54 INFO Uploading vybxgpgj1kyc6vazq60691vvybck9z7k-b (216B)14252026/10/14 16:41:54 INFO Uploading 7l3ls493rkya1kdh678x0ppyd59blla8-shared-dep (136B)14262026/10/14 16:41:54 INFO Received cleanup request method=DELETE path=/api/pending_closures14272026/10/14 16:41:54 WARN Failed to register uploaded object key=7s3hw9cg0l12h8dpg4i59yk6a5k47yxr.ls error="server returned 404: 404 page not found\n"14282026/10/14 16:41:54 WARN Failed to register uploaded object key=7l3ls493rkya1kdh678x0ppyd59blla8.ls error="server returned 404: 404 page not found\n"14292026/10/14 16:41:54 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14302026/10/14 16:41:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14312026/10/14 16:41:54 WARN Failed to register uploaded object key=vybxgpgj1kyc6vazq60691vvybck9z7k.ls error="server returned 404: 404 page not found\n"14322026/10/14 16:41:54 WARN Failed to register uploaded object key=nar/09azh9g74y9lnss1d63w1is08vyg98pgd1p7zfffr2sqrbw71lxa.nar.zst error="server returned 404: 404 page not found\n"14332026/10/14 16:41:54 INFO Signed narinfos id=1 count=214342026/10/14 16:41:54 INFO Received uploads request method=POST path=/api/pending_closures14352026/10/14 16:41:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14362026/10/14 16:41:54 INFO Signed narinfos id=2 count=214372026/10/14 16:41:54 INFO Uploading 4 narinfos14382026/10/14 16:41:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43579/oidc14392026/10/14 16:41:54 WARN Failed to register uploaded object key=vybxgpgj1kyc6vazq60691vvybck9z7k.narinfo error="server returned 404: 404 page not found\n"14402026/10/14 16:41:54 WARN Failed to register uploaded object key=7l3ls493rkya1kdh678x0ppyd59blla8.narinfo error="server returned 404: 404 page not found\n"14412026/10/14 16:41:54 WARN Failed to register uploaded object key=7s3hw9cg0l12h8dpg4i59yk6a5k47yxr.narinfo error="server returned 404: 404 page not found\n"14422026/10/14 16:41:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14432026/10/14 16:41:54 WARN Failed to register uploaded object key=7l3ls493rkya1kdh678x0ppyd59blla8.narinfo error="server returned 404: 404 page not found\n"14442026/10/14 16:41:54 INFO Completed upload id=1 objects=6 duration=7.141663ms14452026/10/14 16:41:54 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14462026/10/14 16:41:54 INFO Completed upload id=2 objects=6 duration=1.988577ms14472026/10/14 16:41:54 INFO Upload complete. (82ms)14482026/10/14 16:41:54 INFO Aborted multipart uploads count=0 kept=014492026/10/14 16:41:54 INFO Received uploads request method=POST path=/api/pending_closures1450=== NAME TestClientFallsBackToClosures1451 client_pushes_test.go:112: Retrieved narinfo from S3:1452 StorePath: /build/TestClientFallsBackToClosures1962246599/001/store/7l3ls493rkya1kdh678x0ppyd59blla8-shared-dep1453 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1454 Compression: zstd1455 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821456 NarSize: 1361457 References: 1458 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1459 client_pushes_test.go:112: Retrieved narinfo from S3:1460 StorePath: /build/TestClientFallsBackToClosures1962246599/001/store/7s3hw9cg0l12h8dpg4i59yk6a5k47yxr-a1461 URL: nar/09azh9g74y9lnss1d63w1is08vyg98pgd1p7zfffr2sqrbw71lxa.nar.zst1462 Compression: zstd1463 NarHash: sha256:09azh9g74y9lnss1d63w1is08vyg98pgd1p7zfffr2sqrbw71lxa1464 NarSize: 2161465 References: /build/TestClientFallsBackToClosures1962246599/001/store/7l3ls493rkya1kdh678x0ppyd59blla8-shared-dep1466 CA: text:sha256:0nghhbbbz2r90psb7xqiwk08r6150a7amrh8llymrlbbn6c72d5314672026/10/14 16:41:54 WARN Force mode enabled - objects will be deleted immediately without grace period1468 client_pushes_test.go:112: Retrieved narinfo from S3:1469 StorePath: /build/TestClientFallsBackToClosures1962246599/001/store/vybxgpgj1kyc6vazq60691vvybck9z7k-b1470 URL: nar/09azh9g74y9lnss1d63w1is08vyg98pgd1p7zfffr2sqrbw71lxa.nar.zst1471 Compression: zstd1472 NarHash: sha256:09azh9g74y9lnss1d63w1is08vyg98pgd1p7zfffr2sqrbw71lxa1473 NarSize: 2161474 References: /build/TestClientFallsBackToClosures1962246599/001/store/7l3ls493rkya1kdh678x0ppyd59blla8-shared-dep1475 CA: text:sha256:0nghhbbbz2r90psb7xqiwk08r6150a7amrh8llymrlbbn6c72d5314762026/10/14 16:41:54 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=01477--- PASS: TestClientFallsBackToClosures (0.69s)1478=== CONT TestGCAdvisoryLockBlocksConcurrentRun14792026/10/14 16:41:54 INFO Vacuumed table table=pending_closures14802026/10/14 16:41:54 INFO Vacuumed table table=pending_objects14812026/10/14 16:41:54 INFO Vacuumed table table=multipart_uploads14822026/10/14 16:41:54 INFO Vacuumed table table=closures1483--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.45s)1484=== CONT TestService_AuthMiddleware_MTLSProxyHeader14852026/10/14 16:41:54 INFO Vacuumed table table=objects1486--- PASS: TestGCSweepSkipsPendingObjects (0.48s)1487=== CONT TestNARDeduplicationMetadataUploadBug1488--- PASS: TestService_ReadScope_PublicByDefault (0.43s)1489=== CONT TestResolveDBConnectionString1490=== RUN TestResolveDBConnectionString/flag_wins1491=== PAUSE TestResolveDBConnectionString/flag_wins1492=== RUN TestResolveDBConnectionString/file_when_flag_empty1493=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1494=== RUN TestResolveDBConnectionString/missing_file_is_an_error1495=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1496=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1497=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1498=== RUN TestResolveDBConnectionString/nothing_configured1499=== PAUSE TestResolveDBConnectionString/nothing_configured1500=== CONT TestCreatePendingClosureRejectsOversizedNAR15012026/10/14 16:41:54 INFO Received uploads request method=POST path=/api/pending_closures1502--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1503=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock15042026/10/14 16:41:54 INFO Received uploads request method=POST path=/api/pending_closures15052026/10/14 16:41:54 INFO Received push request method=POST path=/api/pushes1506--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.43s)1507=== CONT TestCacheConfigHandlerMaxNarSize1508--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1509=== CONT TestDeleteClosuresRacingPins15102026/10/14 16:41:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15112026/10/14 16:41:54 INFO Uploading m4pwwfsyn5f8d5ldj7y9a1ky4a7b8ay8-ca-test (144B)15122026/10/14 16:41:54 INFO Received uploads request method=POST path=/api/pending_closures15132026/10/14 16:41:54 WARN Failed to register uploaded object key=m4pwwfsyn5f8d5ldj7y9a1ky4a7b8ay8.ls error="server returned 404: 404 page not found\n"1514=== NAME TestOrphanedObjectsGC1515 orphaned_objects_gc_test.go:287: GC Test Summary:1516 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1517 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1518 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1519 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1520 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects15212026/10/14 16:41:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1522--- PASS: TestOrphanedObjectsGC (0.80s)15232026/10/14 16:41:54 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"1524=== CONT TestLeadIncumbentAnnouncesAtOnce15252026/10/14 16:41:54 WARN Failed to register uploaded object key=log/inxjz171s7ask7jzbba1wz3925qn2v55-ca-test.drv error="server returned 404: 404 page not found\n"15262026/10/14 16:41:54 INFO Signed narinfos id=1 count=115272026/10/14 16:41:54 INFO Uploading 1 narinfos15282026/10/14 16:41:54 INFO Received complete push request method=POST path=/api/pushes/1/complete15292026/10/14 16:41:54 WARN Failed to register uploaded object key=m4pwwfsyn5f8d5ldj7y9a1ky4a7b8ay8.narinfo error="server returned 404: 404 page not found\n"15302026/10/14 16:41:54 INFO Completed push id=1 objects=4 duration=6.623919ms15312026/10/14 16:41:54 INFO Upload complete. (110ms)1532=== NAME TestClientCADerivations1533 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1619145990/001/store/m4pwwfsyn5f8d5ldj7y9a1ky4a7b8ay8-ca-test1534 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1535 Compression: zstd1536 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1537 NarSize: 1441538 References: 1539 Deriver: /build/TestClientCADerivations1619145990/001/store/inxjz171s7ask7jzbba1wz3925qn2v55-ca-test.drv1540 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1541 client_ca_test.go:185: Checking for realisation files in S3...1542 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1543 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache15442026/10/14 16:41:54 WARN mTLS auth: subject not in bound subjects subject="CN=reader"15452026/10/14 16:41:54 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1546--- PASS: TestService_NativeMTLS (0.32s)1547=== CONT TestGenerateLandingPage1548--- PASS: TestGenerateLandingPage (0.00s)1549=== CONT TestLeadEndsOnShutdown15502026/10/14 16:41:54 INFO Received uploads request method=POST path=/api/pending_closures15512026/10/14 16:41:54 INFO Aborted multipart uploads count=0 kept=015522026/10/14 16:41:54 WARN Force mode enabled - objects will be deleted immediately without grace period15532026/10/14 16:41:54 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=015542026/10/14 16:41:54 INFO Vacuumed table table=pending_closures15552026/10/14 16:41:54 INFO Vacuumed table table=pending_objects15562026/10/14 16:41:54 INFO Vacuumed table table=multipart_uploads15572026/10/14 16:41:54 INFO Vacuumed table table=closures1558--- PASS: TestService_ReadAuthMiddleware (0.30s)15592026/10/14 16:41:54 INFO Vacuumed table table=objects1560=== CONT TestService_readinessHandler1561--- PASS: TestGCMetrics (0.33s)1562=== CONT TestPendingClosureWriteTimeout1563=== RUN TestPendingClosureWriteTimeout/empty1564=== PAUSE TestPendingClosureWriteTimeout/empty1565=== RUN TestPendingClosureWriteTimeout/400_objects1566=== PAUSE TestPendingClosureWriteTimeout/400_objects1567=== RUN TestPendingClosureWriteTimeout/670k_objects1568=== PAUSE TestPendingClosureWriteTimeout/670k_objects1569=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1570=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1571=== CONT TestUploadHandlersRejectInvalidKeys1572=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1573=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1574=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1575=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1576=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1577=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1578=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1579=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1580=== CONT TestService_healthCheckHandler15812026/10/14 16:41:54 INFO Received cleanup request method=DELETE path=/api/pending_closures15822026/10/14 16:41:54 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket69/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""15832026/10/14 16:41:54 INFO Aborted multipart uploads count=0 kept=115842026/10/14 16:41:54 INFO Received cleanup request method=DELETE path=/api/pending_closures15852026/10/14 16:41:54 INFO Aborted multipart uploads count=1 kept=015862026/10/14 16:41:54 INFO Aborted multipart uploads count=0 kept=01587--- PASS: TestMultipartCleanup (0.52s)1588=== CONT TestLeadElectsOneAndHandsOver1589=== RUN TestService_RequireScope_OIDC/builder_may_write1590=== PAUSE TestService_RequireScope_OIDC/builder_may_write1591=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1592=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1593=== RUN TestService_RequireScope_OIDC/ops_may_admin1594=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1595=== RUN TestService_RequireScope_OIDC/ops_may_not_write1596=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1597=== RUN TestService_RequireScope_OIDC/reader_may_not_write1598=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1599=== RUN TestService_RequireScope_OIDC/static_token_may_admin1600=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1601=== RUN TestService_RequireScope_OIDC/static_token_may_write1602=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1603=== RUN TestService_RequireScope_OIDC/reader_may_read1604=== PAUSE TestService_RequireScope_OIDC/reader_may_read1605=== RUN TestService_RequireScope_OIDC/writer_implies_read1606=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1607=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1608=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1609=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1610=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1611=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1612=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1613=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1614=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1615=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1616=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1617=== CONT TestGracefulShutdownDrainsInflight16182026/10/14 16:41:54 INFO Starting HTTP server address=127.0.0.1:4273516192026/10/14 16:41:54 INFO Shutdown signal received, draining in-flight requests timeout=10s16202026/10/14 16:41:54 INFO Received push request method=POST path=/api/pushes16212026/10/14 16:41:54 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=016222026/10/14 16:41:54 INFO Vacuumed table table=pending_closures16232026/10/14 16:41:54 INFO Vacuumed table table=pending_objects16242026/10/14 16:41:54 INFO Vacuumed table table=multipart_uploads16252026/10/14 16:41:54 INFO Vacuumed table table=closures16262026/10/14 16:41:54 INFO Vacuumed table table=objects1627=== NAME TestClientCADerivations1628 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1629 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1630 error: binary cache 's3://bucket59?endpoint=http://localhost:38213®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1619145990/001/store'1631 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 116322026/10/14 16:41:54 INFO Aborted multipart uploads count=0 kept=01633--- PASS: TestClientCADerivations (0.87s)1634=== CONT TestGCTaskStore_GetReturnsLatest1635--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1636=== CONT TestIsValidUploadKey1637=== RUN TestIsValidUploadKey/narinfo1638=== PAUSE TestIsValidUploadKey/narinfo1639=== RUN TestIsValidUploadKey/nar_zst1640=== PAUSE TestIsValidUploadKey/nar_zst1641=== RUN TestIsValidUploadKey/nar_xz1642=== PAUSE TestIsValidUploadKey/nar_xz1643=== RUN TestIsValidUploadKey/nar_plain1644=== PAUSE TestIsValidUploadKey/nar_plain1645=== RUN TestIsValidUploadKey/listing1646=== PAUSE TestIsValidUploadKey/listing1647=== RUN TestIsValidUploadKey/build_log1648=== PAUSE TestIsValidUploadKey/build_log1649=== RUN TestIsValidUploadKey/build_log_home-manager_file1650=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1651=== RUN TestIsValidUploadKey/build_log_plus_in_name16522026/10/14 16:41:54 INFO Received complete push request method=POST path=/api/pushes/1/complete1653=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1654=== RUN TestIsValidUploadKey/build_log_question_mark16552026/10/14 16:41:54 WARN Force mode enabled - objects will be deleted immediately without grace period1656=== PAUSE TestIsValidUploadKey/build_log_question_mark1657=== RUN TestIsValidUploadKey/build_log_equals1658=== PAUSE TestIsValidUploadKey/build_log_equals1659=== RUN TestIsValidUploadKey/realisation1660=== PAUSE TestIsValidUploadKey/realisation1661=== RUN TestIsValidUploadKey/realisation_plus_in_output1662=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1663=== RUN TestIsValidUploadKey/nix-cache-info1664=== PAUSE TestIsValidUploadKey/nix-cache-info1665=== RUN TestIsValidUploadKey/index.html1666=== PAUSE TestIsValidUploadKey/index.html1667=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1668=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1669=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1670=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1671=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1672=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1673=== RUN TestIsValidUploadKey/traversal1674=== PAUSE TestIsValidUploadKey/traversal1675=== RUN TestIsValidUploadKey/traversal_nar1676=== PAUSE TestIsValidUploadKey/traversal_nar1677=== RUN TestIsValidUploadKey/absolute1678=== PAUSE TestIsValidUploadKey/absolute1679=== RUN TestIsValidUploadKey/empty_key1680=== PAUSE TestIsValidUploadKey/empty_key1681=== RUN TestIsValidUploadKey/unknown_type1682=== PAUSE TestIsValidUploadKey/unknown_type1683=== CONT TestConnectWaitsForAPeerMigration16842026/10/14 16:41:54 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=016852026/10/14 16:41:54 INFO Vacuumed table table=pending_closures16862026/10/14 16:41:54 INFO Vacuumed table table=pending_objects16872026/10/14 16:41:55 INFO Vacuumed table table=multipart_uploads16882026/10/14 16:41:55 INFO Vacuumed table table=closures16892026/10/14 16:41:55 INFO Completed push id=1 objects=4 duration=10.215191ms16902026/10/14 16:41:55 INFO Vacuumed table table=objects16912026/10/14 16:41:55 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1692--- PASS: TestPushDedupSurvivesConcurrentGC (0.50s)1693=== CONT TestGCTaskStore_GetEmpty1694--- PASS: TestGCTaskStore_GetEmpty (0.00s)1695=== CONT TestGCTaskStore_DeduplicateSameParams1696--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1697=== CONT TestGCTaskStore_StartNew1698--- PASS: TestGCTaskStore_StartNew (0.00s)1699=== CONT TestGCTaskStore_ConflictDifferentParams1700--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1701=== CONT TestGCTaskStore_PhaseUpdates1702--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1703=== CONT TestGCTaskStore_CompletedAllowsNewTask1704--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1705=== CONT TestProxyWriteTimeout1706=== RUN TestProxyWriteTimeout/narinfo1707=== PAUSE TestProxyWriteTimeout/narinfo1708=== RUN TestProxyWriteTimeout/1_GiB_nar1709=== PAUSE TestProxyWriteTimeout/1_GiB_nar1710=== RUN TestProxyWriteTimeout/10_GiB_nar1711=== PAUSE TestProxyWriteTimeout/10_GiB_nar1712=== RUN TestProxyWriteTimeout/unknown_size1713=== PAUSE TestProxyWriteTimeout/unknown_size1714=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle17152026/10/14 16:41:55 INFO Completed upload id=2 objects=2 duration=1.529654ms1716--- PASS: TestMetricsCommit (0.38s)1717=== CONT TestGCTaskStore_Fail1718--- PASS: TestGCTaskStore_Fail (0.00s)1719=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17202026/10/14 16:41:55 INFO Received uploads request method=POST path=/17212026/10/14 16:41:55 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17222026/10/14 16:41:55 WARN mTLS auth: bound subjects configured but subject DN unavailable17232026/10/14 16:41:55 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1724--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.34s)1725=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17262026/10/14 16:41:55 INFO Received request for more parts method=POST path=/1727--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1728=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17292026/10/14 16:41:55 INFO Received complete multipart upload request method=POST path=/1730--- PASS: TestMetricsInventory (0.37s)1731=== CONT TestPush_RejectsBadRequests/no_objects17322026/10/14 16:41:55 INFO Received push request method=POST path=/api/pushes1733=== CONT TestPush_RejectsBadRequests/root_not_in_objects17342026/10/14 16:41:55 INFO Received push request method=POST path=/api/pushes1735=== CONT TestPush_RejectsBadRequests/no_roots17362026/10/14 16:41:55 INFO Received push request method=POST path=/api/pushes1737=== CONT TestPush_RejectsBadRequests/bad_root17382026/10/14 16:41:55 INFO Received push request method=POST path=/api/pushes1739--- PASS: TestPush_RejectsBadRequests (0.38s)1740 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1741 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1742 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1743 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1744=== CONT TestGCEndsOnShutdown/before_the_run1745=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1746=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1747=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1748=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1749=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1750=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1751=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1752=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1753=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1754=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1755=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1756--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.34s)1757=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1758=== NAME TestNARDeduplicationMetadataUploadBug1759 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3073649447/001/store/zri8f44hvrwcns6smy4kjrg1c1p3609r-file1.txt17602026/10/14 16:41:55 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"1761--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.38s)1762=== CONT TestIsValidCachePath/narinfo1763=== CONT TestIsValidCachePath/index.html1764=== CONT TestIsValidCachePath/short_hash1765=== CONT TestIsValidCachePath/wrong_extension1766=== CONT TestIsValidCachePath/leading_slash1767=== CONT TestIsValidCachePath/empty1768=== CONT TestIsValidCachePath/random_path1769=== CONT TestIsValidCachePath/invalid_char_u1770=== CONT TestIsValidCachePath/invalid_char_e1771=== CONT TestIsValidCachePath/traversal_in_middle1772=== CONT TestIsValidCachePath/traversal_parent1773=== CONT TestIsValidCachePath/realisation1774=== CONT TestIsValidCachePath/nix-cache-info1775=== CONT TestIsValidCachePath/nar_uncompressed1776=== CONT TestIsValidCachePath/log1777=== CONT TestIsValidCachePath/ls1778=== CONT TestIsValidCachePath/nar_xz1779=== CONT TestIsValidCachePath/nar_bz21780=== CONT TestIsValidCachePath/nar_zst1781=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1782=== CONT TestParseSingleRange/none1783=== CONT TestParseSingleRange/start_past_EOF1784=== CONT TestParseSingleRange/single_byte1785=== CONT TestParseSingleRange/suffix_exceeds_size1786=== CONT TestParseSingleRange/suffix1787=== CONT TestParseSingleRange/end_clamped_to_size1788=== CONT TestParseSingleRange/open-ended1789=== CONT TestParseSingleRange/closed1790=== CONT TestParseSingleRange/malformed_end_before_start1791=== CONT TestParseSingleRange/malformed_both_empty1792=== CONT TestParseSingleRange/malformed_no_dash1793=== CONT TestParseSingleRange/start_far_past_EOF1794=== CONT TestParseSingleRange/multi-range_ignored1795=== CONT TestParseSingleRange/unknown_unit1796=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1797--- PASS: TestIsValidCachePath (0.00s)1798 --- PASS: TestIsValidCachePath/narinfo (0.00s)1799 --- PASS: TestIsValidCachePath/index.html (0.00s)1800 --- PASS: TestIsValidCachePath/short_hash (0.00s)1801 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1802 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1803 --- PASS: TestIsValidCachePath/empty (0.00s)1804 --- PASS: TestIsValidCachePath/random_path (0.00s)1805 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1806 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1807 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1808 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1809 --- PASS: TestIsValidCachePath/realisation (0.00s)1810 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1811 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1812 --- PASS: TestIsValidCachePath/log (0.00s)1813 --- PASS: TestIsValidCachePath/ls (0.00s)1814 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1815 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1816 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1817 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1818--- PASS: TestParseSingleRange (0.00s)1819 --- PASS: TestParseSingleRange/none (0.00s)1820 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1821 --- PASS: TestParseSingleRange/single_byte (0.00s)1822 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1823 --- PASS: TestParseSingleRange/suffix (0.00s)1824 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1825 --- PASS: TestParseSingleRange/open-ended (0.00s)1826 --- PASS: TestParseSingleRange/closed (0.00s)1827 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1828 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1829 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1830 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1831 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1832 --- PASS: TestParseSingleRange/unknown_unit (0.00s)18332026/10/14 16:41:55 INFO lead: acquired remote=192.0.2.1:123418342026/10/14 16:41:55 INFO lead: released remote=192.0.2.1:12341835--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.34s)1836=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh18372026/10/14 16:41:55 INFO Received push request method=POST path=/api/pushes18382026/10/14 16:41:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18392026/10/14 16:41:55 INFO Uploading zri8f44hvrwcns6smy4kjrg1c1p3609r-file1.txt (160B)1840--- PASS: TestGCBugBareHashReferences (0.57s)1841=== CONT TestClientErrorHandling/InvalidStorePath18422026/10/14 16:41:55 INFO lead: acquired remote=192.0.2.1:123418432026/10/14 16:41:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18442026/10/14 16:41:55 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"18452026/10/14 16:41:55 WARN Failed to register uploaded object key=zri8f44hvrwcns6smy4kjrg1c1p3609r.ls error="server returned 404: 404 page not found\n"18462026/10/14 16:41:55 INFO Signed narinfos id=1 count=118472026/10/14 16:41:55 INFO Uploading 1 narinfos18482026/10/14 16:41:55 INFO Received complete push request method=POST path=/api/pushes/1/complete18492026/10/14 16:41:55 WARN Failed to register uploaded object key=zri8f44hvrwcns6smy4kjrg1c1p3609r.narinfo error="server returned 404: 404 page not found\n"18502026/10/14 16:41:55 INFO Completed push id=1 objects=3 duration=7.001682ms18512026/10/14 16:41:55 INFO Upload complete. (74ms)1852=== NAME TestNARDeduplicationMetadataUploadBug1853 metadata_upload_test.go:54: Retrieved narinfo from S3:1854 StorePath: /build/TestNARDeduplicationMetadataUploadBug3073649447/001/store/zri8f44hvrwcns6smy4kjrg1c1p3609r-file1.txt1855 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1856 Compression: zstd1857 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1858 NarSize: 1601859 References: 1860 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1861 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1862 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1863 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}18642026/10/14 16:41:55 WARN readiness check failed error="closed pool"1865--- PASS: TestService_readinessHandler (0.36s)1866=== CONT TestClientErrorHandling/ServerNotAvailable1867--- PASS: TestService_healthCheckHandler (0.38s)1868=== CONT TestClientErrorHandling/InvalidAuthToken1869=== NAME TestNARDeduplicationMetadataUploadBug1870 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3073649447/001/store/cch9pdz9khc06jng9ndflhj26anda0bb-file2.txt18712026/10/14 16:41:55 INFO lead: acquired remote=192.0.2.1:123418722026/10/14 16:41:55 INFO Received uploads request method=POST path=/api/pending_closures18732026/10/14 16:41:55 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/present1874=== CONT TestCacheConfigHandler/full_config,_no_issuer1875=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1876=== CONT TestCacheConfigHandler/no_signing_keys1877=== CONT TestCacheConfigHandler/no_cache_url_configured1878--- PASS: TestCacheConfigHandler (0.00s)1879 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1880 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1881 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1882 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1883=== CONT TestServerTLSConfig/no_client_CA1884=== CONT TestServerTLSConfig/missing_CA_file1885=== CONT TestServerTLSConfig/not_a_PEM_file1886=== CONT TestResolveDBConnectionString/flag_wins1887=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1888=== CONT TestResolveDBConnectionString/nothing_configured1889=== CONT TestResolveDBConnectionString/file_when_flag_empty1890--- PASS: TestServerTLSConfig (0.00s)1891 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1892 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1893 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1894=== CONT TestResolveDBConnectionString/missing_file_is_an_error1895=== CONT TestPendingClosureWriteTimeout/empty1896=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1897--- PASS: TestResolveDBConnectionString (0.00s)1898 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1899 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1900 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1901 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1902 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)19032026/10/14 16:41:55 INFO Received push request method=POST path=/api/pushes19042026/10/14 16:41:55 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19052026/10/14 16:41:55 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign19062026/10/14 16:41:55 INFO Signed narinfos id=2 count=119072026/10/14 16:41:55 WARN Failed to register uploaded object key=cch9pdz9khc06jng9ndflhj26anda0bb.ls error="server returned 404: 404 page not found\n"19082026/10/14 16:41:55 INFO Uploading 1 narinfos19092026/10/14 16:41:55 INFO Received complete push request method=POST path=/api/pushes/2/complete19102026/10/14 16:41:55 WARN Failed to register uploaded object key=cch9pdz9khc06jng9ndflhj26anda0bb.narinfo error="server returned 404: 404 page not found\n"19112026/10/14 16:41:55 INFO Completed push id=2 objects=3 duration=3.126628ms19122026/10/14 16:41:55 INFO Upload complete. (63ms)1913=== NAME TestNARDeduplicationMetadataUploadBug1914 metadata_upload_test.go:76: Retrieved narinfo from S3:1915 StorePath: /build/TestNARDeduplicationMetadataUploadBug3073649447/001/store/cch9pdz9khc06jng9ndflhj26anda0bb-file2.txt1916 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1917 Compression: zstd1918 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1919 NarSize: 1601920 References: 1921 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1922 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1923 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1924 {"version":1,"root":{"type":"regular","size":44}}1925--- PASS: TestNARDeduplicationMetadataUploadBug (0.65s)1926=== CONT TestPendingClosureWriteTimeout/670k_objects1927=== CONT TestPendingClosureWriteTimeout/400_objects1928=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info19292026/10/14 16:41:55 INFO Received uploads request method=POST path=/1930=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key19312026/10/14 16:41:55 INFO Received complete multipart upload request method=POST path=/1932=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key19332026/10/14 16:41:55 INFO Received request for more parts method=POST path=/1934=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal19352026/10/14 16:41:55 INFO Received uploads request method=POST path=/1936--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1937 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1938 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1939 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1940 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1941=== CONT TestService_RequireScope_OIDC/builder_may_write1942=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1943=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19442026/10/14 16:41:55 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]1945=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1946=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1947=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1948=== CONT TestService_RequireScope_OIDC/writer_implies_read1949=== CONT TestService_RequireScope_OIDC/reader_may_read1950=== CONT TestService_RequireScope_OIDC/static_token_may_write1951=== CONT TestService_RequireScope_OIDC/static_token_may_admin1952=== CONT TestService_RequireScope_OIDC/reader_may_not_write1953=== CONT TestService_RequireScope_OIDC/ops_may_not_write1954=== CONT TestService_RequireScope_OIDC/ops_may_admin19552026/10/14 16:41:55 INFO Aborted multipart uploads count=0 kept=01956=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1957=== CONT TestIsValidUploadKey/narinfo1958=== CONT TestIsValidUploadKey/realisation_plus_in_output1959=== CONT TestIsValidUploadKey/unknown_type1960=== CONT TestIsValidUploadKey/empty_key1961=== CONT TestIsValidUploadKey/absolute1962=== CONT TestIsValidUploadKey/traversal_nar1963=== CONT TestIsValidUploadKey/traversal1964=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1965=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1966=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1967=== CONT TestIsValidUploadKey/index.html1968=== CONT TestIsValidUploadKey/nix-cache-info1969=== CONT TestIsValidUploadKey/build_log_home-manager_file1970=== CONT TestIsValidUploadKey/realisation1971=== CONT TestIsValidUploadKey/build_log_question_mark1972=== CONT TestIsValidUploadKey/build_log_plus_in_name1973=== CONT TestIsValidUploadKey/build_log_equals1974=== CONT TestIsValidUploadKey/nar_plain1975=== CONT TestIsValidUploadKey/nar_xz1976=== CONT TestIsValidUploadKey/build_log1977=== CONT TestIsValidUploadKey/listing1978=== CONT TestIsValidUploadKey/nar_zst1979--- PASS: TestIsValidUploadKey (0.00s)1980 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1981 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1982 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1983 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1984 --- PASS: TestIsValidUploadKey/absolute (0.00s)1985 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1986 --- PASS: TestIsValidUploadKey/traversal (0.00s)1987 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1988 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1989 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1990 --- PASS: TestIsValidUploadKey/index.html (0.00s)1991 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1992 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1993 --- PASS: TestIsValidUploadKey/realisation (0.00s)1994 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1995 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1996 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1997 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1998 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1999 --- PASS: TestIsValidUploadKey/build_log (0.00s)2000 --- PASS: TestIsValidUploadKey/listing (0.00s)2001 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2002=== CONT TestProxyWriteTimeout/narinfo2003=== CONT TestProxyWriteTimeout/unknown_size2004=== CONT TestProxyWriteTimeout/10_GiB_nar2005=== CONT TestProxyWriteTimeout/1_GiB_nar2006--- PASS: TestService_RequireScope_OIDC (0.50s)2007 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2008 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2009 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2010 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2011 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2012 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2013 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2014 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2015 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2016 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2017 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2018 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2019 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2020 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2021--- PASS: TestProxyWriteTimeout (0.00s)2022 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2023 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2024 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2025 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2026=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token20272026/10/14 16:41:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2028=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20292026/10/14 16:41:55 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]2030=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2031=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20322026/10/14 16:41:55 WARN Authentication failed token_preview=eyJhbGciOi...kU0VTNmb2g token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]20332026/10/14 16:41:55 WARN Force mode enabled - objects will be deleted immediately without grace period2034--- PASS: TestService_AuthMiddleware_OIDC (0.55s)2035 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2036 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2037 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2038 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)20392026/10/14 16:41:55 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:38213/bucket92/?delete=\": context canceled"20402026/10/14 16:41:55 INFO Aborted multipart uploads count=0 kept=020412026/10/14 16:41:55 WARN Force mode enabled - objects will be deleted immediately without grace period20422026/10/14 16:41:55 INFO Received uploads request method=POST path=/api/pending_closures20432026/10/14 16:41:55 WARN Request failed, retrying attempt=2 backoff=216.357654ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20442026/10/14 16:41:55 INFO Aborted multipart uploads count=0 kept=02045--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.70s)2046--- PASS: TestGCEndsOnShutdown (0.00s)2047 --- PASS: TestGCEndsOnShutdown/before_the_run (0.34s)2048 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.38s)2049 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.42s)20502026/10/14 16:41:55 WARN Force mode enabled - objects will be deleted immediately without grace period20512026/10/14 16:41:55 INFO Received uploads request method=POST path=/api/pending_closures20522026/10/14 16:41:55 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=020532026/10/14 16:41:55 INFO Vacuumed table table=pending_closures20542026/10/14 16:41:55 INFO Vacuumed table table=pending_objects20552026/10/14 16:41:55 INFO Vacuumed table table=multipart_uploads20562026/10/14 16:41:55 INFO Vacuumed table table=closures20572026/10/14 16:41:55 INFO Aborted multipart uploads count=0 kept=020582026/10/14 16:41:55 INFO Vacuumed table table=objects20592026/10/14 16:41:55 WARN Force mode enabled - objects will be deleted immediately without grace period20602026/10/14 16:41:55 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=020612026/10/14 16:41:55 INFO Vacuumed table table=pending_closures20622026/10/14 16:41:55 INFO Vacuumed table table=pending_objects20632026/10/14 16:41:55 INFO Vacuumed table table=multipart_uploads20642026/10/14 16:41:55 INFO Vacuumed table table=closures20652026/10/14 16:41:55 INFO Vacuumed table table=objects2066--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2067 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.40s)2068 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.43s)2069--- PASS: TestObjectStatsLargeCommit (1.47s)20702026/10/14 16:41:55 INFO Received uploads request method=POST path=/api/pending_closures20712026/10/14 16:41:55 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20722026/10/14 16:41:55 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20732026/10/14 16:41:55 WARN Request failed, retrying attempt=3 backoff=369.581208ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2074--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2075 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.87s)2076 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.88s)20772026/10/14 16:41:56 WARN Request failed, retrying attempt=4 backoff=731.216251ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2078--- PASS: TestUploadHandlersRejectOversizedBody (0.17s)2079 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.05s)2080 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)2081 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.06s)2082=== NAME TestOrphanedObjectsGCStressTest2083 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2084 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion20852026/10/14 16:41:56 INFO lead: released remote=192.0.2.1:12342086--- PASS: TestLeadEndsOnShutdown (1.39s)2087--- PASS: TestDeleteClosuresRacingPins (1.54s)2088--- PASS: TestPendingClosureWriteTimeout (0.00s)2089 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2090 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2091 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2092 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (0.99s)2093=== NAME TestOrphanedObjectsGCStressTest2094 orphaned_objects_gc_test.go:503: Stress test completed successfully:2095 orphaned_objects_gc_test.go:504: - Active objects preserved: 202096 orphaned_objects_gc_test.go:505: - Objects deleted: 2102097 orphaned_objects_gc_test.go:506: - Total GC'd: 2102098--- PASS: TestOrphanedObjectsGCStressTest (2.37s)20992026/10/14 16:41:56 INFO lead: released remote=192.0.2.1:123421002026/10/14 16:41:56 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=021012026/10/14 16:41:56 INFO Received create pin request method=POST path=/api/pins/myapp21022026/10/14 16:41:56 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2379313037/001/store/c36paasx068dc4rqlr09bd73yll5kazv-pinned-file.txt narinfo_key=c36paasx068dc4rqlr09bd73yll5kazv.narinfo21032026/10/14 16:41:56 INFO Starting cleanup of old closures method=DELETE path=/api/closures21042026/10/14 16:41:56 INFO Garbage collection started21052026/10/14 16:41:56 INFO Aborted multipart uploads count=0 kept=021062026/10/14 16:41:56 WARN Force mode enabled - objects will be deleted immediately without grace period21072026/10/14 16:41:56 INFO lead: acquired remote=192.0.2.1:123421082026/10/14 16:41:56 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=021092026/10/14 16:41:56 INFO Vacuumed table table=pending_closures21102026/10/14 16:41:56 INFO Vacuumed table table=pending_objects21112026/10/14 16:41:56 INFO Vacuumed table table=multipart_uploads21122026/10/14 16:41:56 INFO Vacuumed table table=closures21132026/10/14 16:41:56 INFO Vacuumed table table=objects21142026/10/14 16:41:56 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02115=== NAME TestClientIntegration2116 client_integration_test.go:323: Objects in database after GC:2117 client_integration_test.go:323: Successfully deleted all objects with GC --force2118--- PASS: TestClientIntegration (2.63s)21192026/10/14 16:41:56 WARN Request failed, retrying attempt=5 backoff=1.593416801s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21202026/10/14 16:41:57 INFO lead: released remote=192.0.2.1:12342121--- PASS: TestLeadElectsOneAndHandsOver (2.73s)2122--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.74s)21232026/10/14 16:41:58 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-config21242026/10/14 16:41:58 WARN Request failed, retrying attempt=2 backoff=208.764374ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2125=== NAME TestPinProtectsFromGC2126 client_integration_test.go:840: Pin successfully protected closure from garbage collection2127--- PASS: TestPinProtectsFromGC (4.83s)21282026/10/14 16:41:58 WARN Request failed, retrying attempt=3 backoff=430.990435ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21292026/10/14 16:41:59 WARN Request failed, retrying attempt=4 backoff=730.073164ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21302026/10/14 16:41:59 WARN Request failed, retrying attempt=5 backoff=1.719335426s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2131--- PASS: TestConnectWaitsForAPeerMigration (5.14s)21322026/10/14 16:42:00 WARN Rate limiter enabled after throttle name=s3-test rate=521332026/10/14 16:42:00 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2134=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2135 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102136 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002137--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.51s)21382026/10/14 16:42:00 INFO Aborted multipart uploads count=1 kept=021392026/10/14 16:42:00 INFO Received cleanup request method=DELETE path=/api/pending_closures21402026/10/14 16:42:00 INFO Aborted multipart uploads count=1 kept=02141--- PASS: TestPendingCleanupUsesOneCutoff (6.51s)21422026/10/14 16:42:01 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"21432026/10/14 16:42:01 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-config21442026/10/14 16:42:01 WARN Request failed, retrying attempt=2 backoff=189.807912ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21452026/10/14 16:42:01 WARN Request failed, retrying attempt=3 backoff=375.507672ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21462026/10/14 16:42:02 WARN Request failed, retrying attempt=4 backoff=734.936296ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21472026/10/14 16:42:03 WARN Request failed, retrying attempt=5 backoff=1.468434567s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21482026/10/14 16:42:04 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_closures21492026/10/14 16:42:04 WARN Request failed, retrying attempt=2 backoff=218.084268ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21502026/10/14 16:42:04 WARN Request failed, retrying attempt=3 backoff=394.01437ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21512026/10/14 16:42:05 WARN Request failed, retrying attempt=4 backoff=782.225392ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21522026/10/14 16:42:05 WARN Request failed, retrying attempt=5 backoff=1.626938124s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2153--- PASS: TestClientErrorHandling (0.00s)2154 --- PASS: TestClientErrorHandling/InvalidStorePath (0.34s)2155 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.37s)2156 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.33s)2157PASS21582026-10-14 16:42:07.869 UTC [129] LOG: received smart shutdown request21592026-10-14 16:42:07.873 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 121602026-10-14 16:42:07.886 UTC [134] LOG: shutting down21612026-10-14 16:42:07.886 UTC [134] LOG: checkpoint starting: shutdown immediate21622026-10-14 16:42:08.814 UTC [134] LOG: checkpoint complete: wrote 10859 buffers (66.3%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.179 s, sync=0.714 s, total=0.928 s; sync files=34046, longest=0.007 s, average=0.001 s; distance=531629 kB, estimate=531629 kB; lsn=0/21E91478, redo lsn=0/21E9147821632026-10-14 16:42:08.889 UTC [129] LOG: database system is shut down2164Running OIDC tests...2165=== RUN TestAudienceForIssuer2166=== PAUSE TestAudienceForIssuer2167=== RUN TestGlobMatch2168=== PAUSE TestGlobMatch2169=== RUN TestValidateToken_ValidToken2170=== PAUSE TestValidateToken_ValidToken2171=== RUN TestValidateToken_WrongAudience2172=== PAUSE TestValidateToken_WrongAudience2173=== RUN TestValidateToken_Expired2174=== PAUSE TestValidateToken_Expired2175=== RUN TestValidateToken_BoundClaimsMismatch2176=== PAUSE TestValidateToken_BoundClaimsMismatch2177=== RUN TestValidateToken_BoundSubjectMismatch2178=== PAUSE TestValidateToken_BoundSubjectMismatch2179=== RUN TestValidateToken_MultipleProviders2180=== PAUSE TestValidateToken_MultipleProviders2181=== RUN TestValidateToken_NoMatchingProvider2182=== PAUSE TestValidateToken_NoMatchingProvider2183=== RUN TestValidateToken_KubernetesServiceAccount2184=== PAUSE TestValidateToken_KubernetesServiceAccount2185=== RUN TestNewValidator_KubernetesRequiresCA2186=== PAUSE TestNewValidator_KubernetesRequiresCA2187=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2188=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2189=== RUN TestPins_ReservedForMatchingRule2190=== PAUSE TestPins_ReservedForMatchingRule2191=== RUN TestPins_TopLevelShorthand2192=== PAUSE TestPins_TopLevelShorthand2193=== RUN TestPins_ConfigValidation2194=== PAUSE TestPins_ConfigValidation2195=== RUN TestScopes_LegacyProviderDefaultsToWrite2196=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2197=== RUN TestScopes_Rules2198=== PAUSE TestScopes_Rules2199=== RUN TestScopes_ConfigValidation2200=== PAUSE TestScopes_ConfigValidation2201=== CONT TestAudienceForIssuer2202=== CONT TestPins_ConfigValidation2203--- PASS: TestAudienceForIssuer (0.00s)2204=== CONT TestScopes_ConfigValidation2205=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2206=== CONT TestNewValidator_KubernetesRequiresCA2207=== CONT TestValidateToken_BoundClaimsMismatch2208=== CONT TestValidateToken_NoMatchingProvider2209--- PASS: TestPins_ConfigValidation (0.00s)2210=== CONT TestValidateToken_MultipleProviders2211=== CONT TestValidateToken_BoundSubjectMismatch2212=== CONT TestScopes_Rules2213--- PASS: TestScopes_ConfigValidation (0.00s)2214=== CONT TestValidateToken_Expired2215=== CONT TestValidateToken_WrongAudience2216=== CONT TestValidateToken_ValidToken2217=== CONT TestGlobMatch2218=== RUN TestGlobMatch/foo_foo2219=== PAUSE TestGlobMatch/foo_foo2220=== RUN TestGlobMatch/foo_bar2221=== PAUSE TestGlobMatch/foo_bar2222=== RUN TestGlobMatch/*_2223=== PAUSE TestGlobMatch/*_2224=== RUN TestGlobMatch/*_anything2225=== PAUSE TestGlobMatch/*_anything2226=== RUN TestGlobMatch/foo*_foo2227=== PAUSE TestGlobMatch/foo*_foo2228=== RUN TestGlobMatch/foo*_foobar2229=== PAUSE TestGlobMatch/foo*_foobar2230=== RUN TestGlobMatch/foo*_bar2231=== CONT TestPins_TopLevelShorthand2232=== CONT TestScopes_LegacyProviderDefaultsToWrite2233=== CONT TestPins_ReservedForMatchingRule2234=== CONT TestValidateToken_KubernetesServiceAccount2235=== PAUSE TestGlobMatch/foo*_bar2236=== RUN TestGlobMatch/*bar_bar2237=== PAUSE TestGlobMatch/*bar_bar2238=== RUN TestGlobMatch/*bar_foobar2239=== PAUSE TestGlobMatch/*bar_foobar2240=== RUN TestGlobMatch/*bar_foo2241=== PAUSE TestGlobMatch/*bar_foo2242=== RUN TestGlobMatch/foo*bar_foobar2243=== PAUSE TestGlobMatch/foo*bar_foobar2244=== RUN TestGlobMatch/foo*bar_foo123bar2245=== PAUSE TestGlobMatch/foo*bar_foo123bar2246=== RUN TestGlobMatch/foo*bar_foobarbaz2247=== PAUSE TestGlobMatch/foo*bar_foobarbaz2248=== RUN TestGlobMatch/*/*_foo/bar2249=== PAUSE TestGlobMatch/*/*_foo/bar2250=== RUN TestGlobMatch/*/*_foo2251=== PAUSE TestGlobMatch/*/*_foo2252=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2253=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2254=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02255=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02256=== RUN TestGlobMatch/refs/*/main_refs/heads/main2257=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2258=== RUN TestGlobMatch/fo?_foo2259=== PAUSE TestGlobMatch/fo?_foo2260=== RUN TestGlobMatch/fo?_fo2261=== PAUSE TestGlobMatch/fo?_fo2262=== RUN TestGlobMatch/fo?_fooo2263=== PAUSE TestGlobMatch/fo?_fooo2264=== RUN TestGlobMatch/?oo_foo2265=== PAUSE TestGlobMatch/?oo_foo2266=== RUN TestGlobMatch/?oo_boo2267=== PAUSE TestGlobMatch/?oo_boo2268=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2269=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2270=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2271=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2272=== CONT TestGlobMatch/foo_foo2273=== CONT TestGlobMatch/?oo_boo2274=== CONT TestGlobMatch/?oo_foo2275=== CONT TestGlobMatch/fo?_fooo2276=== CONT TestGlobMatch/fo?_fo2277=== CONT TestGlobMatch/fo?_foo2278=== CONT TestGlobMatch/refs/*/main_refs/heads/main2279=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02280=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2281=== CONT TestGlobMatch/*/*_foo2282=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2283=== CONT TestGlobMatch/foo*_foobar2284=== CONT TestGlobMatch/foo*_foo2285=== CONT TestGlobMatch/*_anything2286=== CONT TestGlobMatch/*_2287=== CONT TestGlobMatch/foo_bar2288=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2289=== CONT TestGlobMatch/*/*_foo/bar2290=== CONT TestGlobMatch/foo*bar_foobarbaz2291=== CONT TestGlobMatch/foo*bar_foo123bar2292=== CONT TestGlobMatch/foo*bar_foobar2293=== CONT TestGlobMatch/*bar_foo2294=== CONT TestGlobMatch/*bar_foobar2295=== CONT TestGlobMatch/*bar_bar2296=== CONT TestGlobMatch/foo*_bar2297--- PASS: TestGlobMatch (0.00s)2298 --- PASS: TestGlobMatch/foo_foo (0.00s)2299 --- PASS: TestGlobMatch/?oo_boo (0.00s)2300 --- PASS: TestGlobMatch/?oo_foo (0.00s)2301 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2302 --- PASS: TestGlobMatch/fo?_fo (0.00s)2303 --- PASS: TestGlobMatch/fo?_foo (0.00s)2304 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2305 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2306 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2307 --- PASS: TestGlobMatch/*/*_foo (0.00s)2308 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2309 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2310 --- PASS: TestGlobMatch/foo*_foo (0.00s)2311 --- PASS: TestGlobMatch/*_anything (0.00s)2312 --- PASS: TestGlobMatch/*_ (0.00s)2313 --- PASS: TestGlobMatch/foo_bar (0.00s)2314 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2315 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2316 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2317 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2318 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2319 --- PASS: TestGlobMatch/*bar_foo (0.00s)2320 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2321 --- PASS: TestGlobMatch/*bar_bar (0.00s)2322 --- PASS: TestGlobMatch/foo*_bar (0.00s)23232026/10/14 16:42:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46709/oidc2324--- PASS: TestValidateToken_Expired (0.03s)23252026/10/14 16:42:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38519/oidc2326--- PASS: TestPins_ReservedForMatchingRule (0.05s)23272026/10/14 16:42:10 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:367012328--- PASS: TestValidateToken_KubernetesServiceAccount (0.06s)23292026/10/14 16:42:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42539/oidc2330--- PASS: TestValidateToken_BoundSubjectMismatch (0.07s)23312026/10/14 16:42:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39695/oidc23322026/10/14 16:42:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34855/oidc23332026/10/14 16:42:10 http: TLS handshake error from 127.0.0.1:36058: remote error: tls: bad certificate2334--- PASS: TestNewValidator_KubernetesRequiresCA (0.11s)2335--- PASS: TestScopes_Rules (0.11s)2336--- PASS: TestValidateToken_WrongAudience (0.11s)23372026/10/14 16:42:10 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:41591/oidc23382026/10/14 16:42:10 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:40207/oidc2339--- PASS: TestValidateToken_MultipleProviders (0.16s)23402026/10/14 16:42:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42911/oidc2341--- PASS: TestPins_TopLevelShorthand (0.16s)23422026/10/14 16:42:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33301/oidc2343--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.17s)23442026/10/14 16:42:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43173/oidc2345--- PASS: TestValidateToken_BoundClaimsMismatch (0.23s)23462026/10/14 16:42:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44449/oidc2347--- PASS: TestValidateToken_ValidToken (0.23s)23482026/10/14 16:42:10 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232349--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.26s)23502026/10/14 16:42:11 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:35521/oidc2351--- PASS: TestValidateToken_NoMatchingProvider (0.38s)2352PASS2353Running hook tests...2354=== RUN TestSendPathsEmpty2355=== PAUSE TestSendPathsEmpty2356=== RUN TestQueueEnqueueAndFetch2357=== PAUSE TestQueueEnqueueAndFetch2358=== RUN TestQueueDeduplication2359=== PAUSE TestQueueDeduplication2360=== RUN TestQueueRemove2361=== PAUSE TestQueueRemove2362=== RUN TestQueueFetchBatchLimit2363=== PAUSE TestQueueFetchBatchLimit2364=== RUN TestQueueRetryMovesToBack2365=== PAUSE TestQueueRetryMovesToBack2366=== RUN TestQueueFetchRemoveLifecycle2367=== PAUSE TestQueueFetchRemoveLifecycle2368=== RUN TestQueueConcurrentWriters2369=== PAUSE TestQueueConcurrentWriters2370=== RUN TestQueueRemoveLargeClosure2371=== PAUSE TestQueueRemoveLargeClosure2372=== RUN TestServerClientIntegration2373--- PASS: TestServerClientIntegration (0.00s)2374=== RUN TestServerQueueError23752026/10/14 16:42:11 ERROR Failed to queue paths error="permission denied" count=12376--- PASS: TestServerQueueError (0.00s)2377=== RUN TestGetListenerSocketActivation2378 server_test.go:219: === RUN TestGetListenerSocketActivation2379 --- PASS: TestGetListenerSocketActivation (0.00s)2380 PASS2381 2382--- PASS: TestGetListenerSocketActivation (0.01s)2383=== RUN TestDrainIsolatesPoisonPath2384=== PAUSE TestDrainIsolatesPoisonPath2385=== RUN TestRunNotBlockedByPoisonHead2386=== PAUSE TestRunNotBlockedByPoisonHead2387=== RUN TestDrainGivesUpWhenServerDown2388=== PAUSE TestDrainGivesUpWhenServerDown2389=== RUN TestFailedPathPrunedByLaterClosure2390=== PAUSE TestFailedPathPrunedByLaterClosure2391=== RUN TestWorkerUploadsAndRemoves2392=== PAUSE TestWorkerUploadsAndRemoves2393=== RUN TestWorkerSkipsGCdPaths2394=== PAUSE TestWorkerSkipsGCdPaths2395=== RUN TestWorkerPrunesClosureDeps2396=== PAUSE TestWorkerPrunesClosureDeps2397=== RUN TestDrainTimeout2398=== PAUSE TestDrainTimeout2399=== CONT TestSendPathsEmpty2400=== CONT TestQueueConcurrentWriters2401--- PASS: TestSendPathsEmpty (0.00s)2402=== CONT TestDrainTimeout2403=== CONT TestWorkerPrunesClosureDeps2404=== CONT TestWorkerUploadsAndRemoves2405=== CONT TestWorkerSkipsGCdPaths2406=== CONT TestQueueFetchRemoveLifecycle2407=== CONT TestQueueDeduplication2408=== CONT TestQueueRemove2409=== CONT TestQueueRetryMovesToBack2410=== CONT TestRunNotBlockedByPoisonHead2411=== CONT TestDrainGivesUpWhenServerDown2412=== CONT TestQueueFetchBatchLimit2413=== CONT TestDrainIsolatesPoisonPath2414=== CONT TestFailedPathPrunedByLaterClosure2415=== CONT TestQueueRemoveLargeClosure2416=== CONT TestQueueEnqueueAndFetch24172026/10/14 16:42:11 INFO Upload queue status pending=224182026/10/14 16:42:11 INFO Upload queue status pending=224192026/10/14 16:42:11 INFO Uploading batch count=124202026/10/14 16:42:11 INFO Uploading batch count=224212026/10/14 16:42:11 INFO Uploading batch count=124222026/10/14 16:42:11 ERROR Upload failed error="upload failed" count=124232026/10/14 16:42:11 INFO Uploading batch count=424242026/10/14 16:42:11 ERROR Upload failed error="upload failed" count=42425--- PASS: TestQueueDeduplication (0.01s)24262026/10/14 16:42:11 INFO Uploading batch count=124272026/10/14 16:42:11 INFO Uploading batch count=224282026/10/14 16:42:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath4260107875/002/bbb24292026/10/14 16:42:11 INFO Uploading batch count=124302026/10/14 16:42:11 INFO Upload queue status pending=22431--- PASS: TestQueueRetryMovesToBack (0.01s)24322026/10/14 16:42:11 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2719461534/002/nonexistent24332026/10/14 16:42:11 INFO Upload queue status pending=324342026/10/14 16:42:11 INFO Uploading batch count=12435--- PASS: TestQueueFetchBatchLimit (0.01s)24362026/10/14 16:42:11 INFO Uploading batch count=12437--- PASS: TestQueueFetchRemoveLifecycle (0.02s)24382026/10/14 16:42:11 ERROR Upload failed error="upload failed" count=124392026/10/14 16:42:11 INFO Uploading batch count=224402026/10/14 16:42:11 ERROR Upload failed error="upload failed" count=224412026/10/14 16:42:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2526203319/002/a2442--- PASS: TestQueueEnqueueAndFetch (0.01s)2443--- PASS: TestQueueRemove (0.02s)24442026/10/14 16:42:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2526203319/002/b24452026/10/14 16:42:11 INFO Uploading batch count=224462026/10/14 16:42:11 ERROR Upload failed error="upload failed" count=224472026/10/14 16:42:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2526203319/002/c2448--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)24492026/10/14 16:42:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2526203319/002/d24502026/10/14 16:42:11 INFO Uploading batch count=124512026/10/14 16:42:11 ERROR Upload failed error="upload failed" count=124522026/10/14 16:42:11 INFO Uploading batch count=224532026/10/14 16:42:11 ERROR Upload failed error="upload failed" count=224542026/10/14 16:42:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2526203319/002/e24552026/10/14 16:42:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2526203319/002/f24562026/10/14 16:42:11 INFO Uploading batch count=124572026/10/14 16:42:11 ERROR Upload failed error="upload failed" count=124582026/10/14 16:42:11 ERROR Drain finished with paths left in queue remaining=1024592026/10/14 16:42:11 INFO Uploading batch count=124602026/10/14 16:42:11 ERROR Upload failed error="upload failed" count=124612026/10/14 16:42:11 ERROR Drain finished with paths left in queue remaining=12462--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2463--- PASS: TestDrainIsolatesPoisonPath (0.02s)2464--- PASS: TestWorkerPrunesClosureDeps (0.03s)2465--- PASS: TestWorkerUploadsAndRemoves (0.03s)2466--- PASS: TestWorkerSkipsGCdPaths (0.03s)2467--- PASS: TestQueueRemoveLargeClosure (0.07s)2468--- PASS: TestQueueConcurrentWriters (0.21s)24692026/10/14 16:42:11 ERROR Upload failed error="context deadline exceeded" count=224702026/10/14 16:42:11 ERROR Drain finished with paths left in queue remaining=42471--- PASS: TestDrainTimeout (0.22s)24722026/10/14 16:42:12 INFO Uploading batch count=124732026/10/14 16:42:12 INFO Uploading batch count=124742026/10/14 16:42:12 INFO Uploading batch count=124752026/10/14 16:42:12 ERROR Upload failed error="upload failed" count=124762026/10/14 16:42:12 INFO Uploading batch count=124772026/10/14 16:42:12 ERROR Upload failed error="upload failed" count=124782026/10/14 16:42:12 INFO Uploading batch count=124792026/10/14 16:42:12 ERROR Upload failed error="upload failed" count=124802026/10/14 16:42:12 INFO Uploading batch count=124812026/10/14 16:42:12 ERROR Upload failed error="upload failed" count=124822026/10/14 16:42:12 ERROR Drain finished with paths left in queue remaining=12483--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2484PASS2485Running signing tests...2486=== RUN TestExternalSigner2487=== PAUSE TestExternalSigner2488=== RUN TestExternalSignerWrongPublicKey2489=== PAUSE TestExternalSignerWrongPublicKey2490=== RUN TestExternalSignerErrors2491=== PAUSE TestExternalSignerErrors2492=== RUN TestExternalSignerRestartsAfterCrash2493=== PAUSE TestExternalSignerRestartsAfterCrash2494=== RUN TestExternalSignerProgramErrorKeepsProcess2495=== PAUSE TestExternalSignerProgramErrorKeepsProcess2496=== RUN TestExternalSignerClose2497=== PAUSE TestExternalSignerClose2498=== RUN TestExternalSignerRejectsInvalidPublicKey2499=== PAUSE TestExternalSignerRejectsInvalidPublicKey2500=== RUN TestExternalSignerCancellation2501=== PAUSE TestExternalSignerCancellation2502=== RUN TestGenerateFingerprint2503=== PAUSE TestGenerateFingerprint2504=== RUN TestParseSigningKey2505=== PAUSE TestParseSigningKey2506=== RUN TestSign2507=== PAUSE TestSign2508=== RUN TestSignBatch2509=== PAUSE TestSignBatch2510=== RUN TestNilKeyPublicKey2511=== PAUSE TestNilKeyPublicKey2512=== RUN TestSignErrors2513=== PAUSE TestSignErrors2514=== CONT TestExternalSigner2515=== CONT TestExternalSignerProgramErrorKeepsProcess2516=== CONT TestParseSigningKey2517=== CONT TestGenerateFingerprint2518=== CONT TestExternalSignerClose2519=== RUN TestGenerateFingerprint/basic_with_references2520=== CONT TestExternalSignerRestartsAfterCrash2521=== CONT TestExternalSignerErrors2522=== CONT TestNilKeyPublicKey2523--- PASS: TestNilKeyPublicKey (0.00s)2524=== CONT TestSignBatch2525=== RUN TestExternalSignerErrors/program_error2526=== PAUSE TestExternalSignerErrors/program_error2527=== RUN TestExternalSignerErrors/exit_at_startup2528=== PAUSE TestExternalSignerErrors/exit_at_startup2529=== RUN TestExternalSignerErrors/invalid_JSON2530=== CONT TestSign2531=== CONT TestExternalSignerRejectsInvalidPublicKey2532=== RUN TestExternalSignerRejectsInvalidPublicKey/#002533=== CONT TestExternalSignerWrongPublicKey2534=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002535=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2536=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2537=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2538=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2539=== CONT TestExternalSignerCancellation2540=== RUN TestParseSigningKey/valid_32-byte_key2541=== PAUSE TestGenerateFingerprint/basic_with_references2542=== RUN TestGenerateFingerprint/no_references2543=== PAUSE TestGenerateFingerprint/no_references2544=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2545=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2546=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2547=== CONT TestSignErrors2548=== PAUSE TestExternalSignerErrors/invalid_JSON2549=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2550=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2551=== RUN TestGenerateFingerprint/invalid_nar_hash_length2552=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2553=== RUN TestGenerateFingerprint/invalid_store_path_prefix2554=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2555=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2556=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2557=== RUN TestExternalSignerErrors/missing_signatures2558=== PAUSE TestParseSigningKey/valid_32-byte_key2559=== PAUSE TestExternalSignerErrors/missing_signatures2560=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2561=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2562=== RUN TestExternalSignerErrors/too_few_signatures2563=== RUN TestGenerateFingerprint/invalid_reference_prefix2564=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2565=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2566=== CONT TestGenerateFingerprint/basic_with_references2567=== CONT TestExternalSignerRejectsInvalidPublicKey/#002568=== CONT TestGenerateFingerprint/invalid_reference_prefix2569=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2570=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2571=== CONT TestGenerateFingerprint/invalid_store_path_prefix2572=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2573=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2574=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2575=== RUN TestParseSigningKey/no_colon2576=== PAUSE TestParseSigningKey/no_colon2577=== RUN TestParseSigningKey/empty_name2578=== PAUSE TestParseSigningKey/empty_name2579=== RUN TestParseSigningKey/invalid_base642580=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2581=== CONT TestGenerateFingerprint/no_references2582=== CONT TestGenerateFingerprint/invalid_nar_hash_length2583=== PAUSE TestExternalSignerErrors/too_few_signatures2584=== RUN TestExternalSignerErrors/missing_signature_name2585=== PAUSE TestExternalSignerErrors/missing_signature_name2586=== RUN TestExternalSignerErrors/invalid_signature_base642587=== PAUSE TestParseSigningKey/invalid_base642588--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2589 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2590 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2591 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2592 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2593 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2594=== PAUSE TestExternalSignerErrors/invalid_signature_base642595=== RUN TestExternalSignerErrors/null2596=== RUN TestParseSigningKey/wrong_length2597=== PAUSE TestExternalSignerErrors/null2598=== PAUSE TestParseSigningKey/wrong_length2599=== CONT TestParseSigningKey/valid_32-byte_key2600--- PASS: TestGenerateFingerprint (0.00s)2601 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2602 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2603 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2604 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2605 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2606 --- PASS: TestGenerateFingerprint/no_references (0.00s)2607 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2608=== RUN TestExternalSignerErrors/wrong_id2609=== PAUSE TestExternalSignerErrors/wrong_id2610=== RUN TestExternalSignerErrors/exit_on_request2611=== PAUSE TestExternalSignerErrors/exit_on_request2612=== RUN TestExternalSignerErrors/wrong_shape2613=== PAUSE TestExternalSignerErrors/wrong_shape2614=== RUN TestExternalSignerErrors/null_signatures2615=== CONT TestParseSigningKey/empty_name2616=== CONT TestParseSigningKey/wrong_length2617=== CONT TestParseSigningKey/invalid_base642618=== CONT TestParseSigningKey/no_colon2619=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2620=== PAUSE TestExternalSignerErrors/null_signatures2621=== RUN TestExternalSignerErrors/wrong_signature_name2622=== PAUSE TestExternalSignerErrors/wrong_signature_name2623=== RUN TestExternalSignerErrors/wrong_signatures_shape2624=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2625=== RUN TestExternalSignerErrors/unrequested_key2626=== PAUSE TestExternalSignerErrors/unrequested_key2627=== RUN TestExternalSignerErrors/wrong_signature_length2628=== PAUSE TestExternalSignerErrors/wrong_signature_length2629=== CONT TestExternalSignerErrors/program_error2630=== CONT TestExternalSignerErrors/wrong_id2631=== CONT TestExternalSignerErrors/missing_signature_name2632=== CONT TestExternalSignerErrors/wrong_shape2633=== CONT TestExternalSignerErrors/wrong_signature_length2634=== CONT TestExternalSignerErrors/unrequested_key2635=== CONT TestExternalSignerErrors/wrong_signatures_shape2636=== CONT TestExternalSignerErrors/too_few_signatures2637=== CONT TestExternalSignerErrors/null2638=== CONT TestExternalSignerErrors/invalid_signature_base642639=== CONT TestExternalSignerErrors/null_signatures2640=== CONT TestExternalSignerErrors/invalid_JSON2641=== CONT TestExternalSignerErrors/wrong_signature_name2642=== RUN TestSignErrors/nil_key2643=== CONT TestExternalSignerErrors/missing_signatures2644=== PAUSE TestSignErrors/nil_key2645--- PASS: TestSign (0.00s)2646=== RUN TestSignErrors/nil_narinfo2647--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2648--- PASS: TestExternalSignerClose (0.01s)2649--- PASS: TestSignBatch (0.00s)2650--- PASS: TestExternalSignerWrongPublicKey (0.00s)2651=== PAUSE TestSignErrors/nil_narinfo2652=== RUN TestSignErrors/invalid_narinfo2653=== PAUSE TestSignErrors/invalid_narinfo2654=== RUN TestSignErrors/canceled2655--- PASS: TestParseSigningKey (0.00s)2656 --- PASS: TestParseSigningKey/empty_name (0.00s)2657 --- PASS: TestParseSigningKey/wrong_length (0.00s)2658 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2659 --- PASS: TestParseSigningKey/no_colon (0.00s)2660 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2661 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2662=== CONT TestExternalSignerErrors/exit_on_request2663=== CONT TestExternalSignerErrors/exit_at_startup2664=== PAUSE TestSignErrors/canceled2665=== CONT TestSignErrors/nil_key2666=== CONT TestSignErrors/canceled2667=== CONT TestSignErrors/invalid_narinfo2668=== CONT TestSignErrors/nil_narinfo2669--- PASS: TestSignErrors (0.00s)2670 --- PASS: TestSignErrors/nil_key (0.00s)2671 --- PASS: TestSignErrors/canceled (0.00s)2672 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2673 --- PASS: TestSignErrors/nil_narinfo (0.00s)2674--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2675--- PASS: TestExternalSignerErrors (0.00s)2676 --- PASS: TestExternalSignerErrors/program_error (0.00s)2677 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2678 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2679 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2680 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2681 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2682 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.00s)2683 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2684 --- PASS: TestExternalSignerErrors/null (0.01s)2685 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2686 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2687 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2688 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2689 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2690 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2691 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2692--- PASS: TestExternalSigner (0.01s)2693--- PASS: TestExternalSignerCancellation (0.02s)2694PASS2695Running OpenBao signer tests...2696=== RUN TestSign2697=== PAUSE TestSign2698=== RUN TestSignErrors2699=== PAUSE TestSignErrors2700=== RUN TestServe2701=== PAUSE TestServe2702=== RUN TestServeRejectsGarbage2703=== PAUSE TestServeRejectsGarbage2704=== CONT TestSign2705=== CONT TestServeRejectsGarbage2706=== CONT TestServe2707--- PASS: TestServeRejectsGarbage (0.00s)2708--- PASS: TestServe (0.00s)2709=== CONT TestSignErrors2710=== RUN TestSignErrors/invalid_base642711=== PAUSE TestSignErrors/invalid_base642712=== RUN TestSignErrors/http_error2713=== PAUSE TestSignErrors/http_error2714=== RUN TestSignErrors/invalid_json2715=== PAUSE TestSignErrors/invalid_json2716=== RUN TestSignErrors/no_prefix2717=== PAUSE TestSignErrors/no_prefix2718=== CONT TestSignErrors/invalid_base642719=== CONT TestSignErrors/invalid_json2720=== CONT TestSignErrors/http_error2721=== CONT TestSignErrors/no_prefix2722--- PASS: TestSign (0.01s)2723--- PASS: TestSignErrors (0.00s)2724 --- PASS: TestSignErrors/no_prefix (0.00s)2725 --- PASS: TestSignErrors/invalid_base64 (0.00s)2726 --- PASS: TestSignErrors/http_error (0.00s)2727 --- PASS: TestSignErrors/invalid_json (0.00s)2728PASS