niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #488
· 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 TestUploadMultipart_ReturnsAfterDroppedBody20=== PAUSE TestUploadMultipart_ReturnsAfterDroppedBody21=== RUN TestPartSizeForNAR22=== PAUSE TestPartSizeForNAR23=== RUN TestDumpPathCaseHackMatchesNix24--- PASS: TestDumpPathCaseHackMatchesNix (0.34s)25=== RUN TestDumpPathCaseHackCollision26--- PASS: TestDumpPathCaseHackCollision (0.00s)27=== RUN TestDumpPathMatchesNix28=== PAUSE TestDumpPathMatchesNix29=== RUN TestDumpPathSingleFile30=== PAUSE TestDumpPathSingleFile31=== RUN TestDumpPathWriterError32=== PAUSE TestDumpPathWriterError33=== RUN TestEncodeNixBase3234=== PAUSE TestEncodeNixBase3235=== RUN TestEncodeNixBase32WithRealHash36=== PAUSE TestEncodeNixBase32WithRealHash37=== RUN TestConvertHashToNix3238=== PAUSE TestConvertHashToNix3239=== RUN TestGetStorePathHash40=== PAUSE TestGetStorePathHash41=== RUN TestPathInfoHashCompatibility42=== PAUSE TestPathInfoHashCompatibility43=== RUN TestParsePathInfoJSON44=== PAUSE TestParsePathInfoJSON45=== RUN TestParsePathInfoJSONMultiplePaths46=== PAUSE TestParsePathInfoJSONMultiplePaths47=== RUN TestPathInfoCACompatibility48=== PAUSE TestPathInfoCACompatibility49=== RUN TestRateLimiterFeedback50=== PAUSE TestRateLimiterFeedback51=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess52=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess53=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer54=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer55=== RUN TestRegisterUploadedObject_OutlivesPush56=== PAUSE TestRegisterUploadedObject_OutlivesPush57=== 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 TestScriptTokenEmptyCommand115--- PASS: TestScriptTokenEmptyCommand (0.00s)116=== CONT TestScriptTokenScriptFails117=== CONT TestResolveStorePath118=== CONT TestRegisterUploadedObject_OutlivesPush119--- PASS: TestResolveStorePath (0.00s)120=== CONT TestScriptTokenBadJSON121=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer122=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1232026/11/11 23:22:17 WARN Rate limiter enabled after throttle name=server-test rate=5124=== CONT TestRateLimiterFeedback125=== RUN TestRateLimiterFeedback/429_enables_limiter126=== PAUSE TestRateLimiterFeedback/429_enables_limiter127=== RUN TestRateLimiterFeedback/503_enables_limiter128=== PAUSE TestRateLimiterFeedback/503_enables_limiter129=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter130=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter131=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter132=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter133=== CONT TestRateLimiterFeedback/429_enables_limiter134=== CONT TestPathInfoCACompatibility135=== RUN TestPathInfoCACompatibility/null_ca_field136=== PAUSE TestPathInfoCACompatibility/null_ca_field137=== RUN TestPathInfoCACompatibility/old_string_format_-_text138=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text139=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive140=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive141=== RUN TestPathInfoCACompatibility/new_structured_format_-_text142=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text143=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method144=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method145=== CONT TestPathInfoCACompatibility/null_ca_field146=== CONT TestParsePathInfoJSONMultiplePaths147=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths148=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths149=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths150=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths151=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths152=== CONT TestParsePathInfoJSON153=== RUN TestParsePathInfoJSON/Nix_format154=== PAUSE TestParsePathInfoJSON/Nix_format155=== RUN TestParsePathInfoJSON/Lix_format156=== PAUSE TestParsePathInfoJSON/Lix_format157=== RUN TestParsePathInfoJSON/empty_input158=== PAUSE TestParsePathInfoJSON/empty_input159=== RUN TestParsePathInfoJSON/whitespace_only160=== PAUSE TestParsePathInfoJSON/whitespace_only161=== RUN TestParsePathInfoJSON/invalid_JSON162=== PAUSE TestParsePathInfoJSON/invalid_JSON163=== CONT TestParsePathInfoJSON/Nix_format164=== CONT TestScriptTokenEmptyToken165=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun166=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica167=== CONT TestRegisterUploadedObjectReusesConnections168--- PASS: TestScriptTokenScriptFails (0.01s)169=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry170=== CONT TestPathInfoHashCompatibility171=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)172=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)173=== CONT TestGetStorePathHash174=== RUN TestGetStorePathHash/valid_store_path175=== CONT TestConvertHashToNix32176=== CONT TestEncodeNixBase32WithRealHash177=== CONT TestEncodeNixBase32178=== CONT TestDumpPathWriterError179=== CONT TestDumpPathSingleFile180=== CONT TestDumpPathMatchesNix181=== CONT TestPartSizeForNAR182=== CONT TestUploadMultipart_ReturnsAfterDroppedBody183=== CONT TestUploadMultipart_PartsInParallel184=== CONT TestFilterOversizedClosures185=== CONT TestCaseHackSuffix186=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon187--- PASS: TestEncodeNixBase32WithRealHash (0.00s)188=== CONT TestScriptTokenCachesUntilRefresh189=== PAUSE TestGetStorePathHash/valid_store_path190=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon1912026/11/11 23:22:18 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:39123/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:39123/api/uploads/complete1922026/11/11 23:22:18 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"193--- PASS: TestScriptTokenEmptyToken (1.71s)194=== CONT TestScriptTokenNoExpiryRerunsEveryCall195=== RUN TestConvertHashToNix32/SRI_format_to_Nix32196=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32197=== RUN TestConvertHashToNix32/already_Nix32_format198=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI199=== RUN TestEncodeNixBase32/test_string_hash200=== RUN TestGetStorePathHash/basename_without_hyphen_should_error201--- PASS: TestDoServerRequestAttachesToken (3.40s)202=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error203=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI204=== PAUSE TestEncodeNixBase32/test_string_hash205=== CONT TestFileTokenEmpty206=== RUN TestPartSizeForNAR/zero_stays_at_minimum207=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum208=== RUN TestPartSizeForNAR/small_stays_at_minimum209=== PAUSE TestPartSizeForNAR/small_stays_at_minimum210=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum211=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum212=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts2132026/11/11 23:22:20 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:39123/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:39123/api/uploads/complete214=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts2152026/11/11 23:22:20 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"2162026/11/11 23:22:20 WARN Rate limiter enabled after throttle name=server-test rate=5217=== RUN TestPartSizeForNAR/1_TiB2182026/11/11 23:22:20 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:33223219=== PAUSE TestPartSizeForNAR/1_TiB220=== RUN TestPartSizeForNAR/5_TiB_S3_max_object221=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object222=== RUN TestPartSizeForNAR/capped_at_5_GiB223=== PAUSE TestPartSizeForNAR/capped_at_5_GiB224=== CONT TestFileTokenMissing225--- PASS: TestRegisterUploadedObject_OutlivesPush (3.44s)226=== CONT TestFileTokenReadsAndCaches227=== RUN TestFilterOversizedClosures/no_limit_keeps_everything228=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything229=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped230=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped231=== RUN TestFilterOversizedClosures/all_closures_skipped232=== PAUSE TestFilterOversizedClosures/all_closures_skipped233=== PAUSE TestConvertHashToNix32/already_Nix32_format234=== RUN TestConvertHashToNix32/invalid_format235=== PAUSE TestConvertHashToNix32/invalid_format236=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error2372026/11/11 23:22:20 WARN Rate limiter backed off name=server-test rate=5238=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error239=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error240=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error241=== CONT TestStaticToken242=== CONT TestClientSignaturesByStorePath243=== CONT TestStreamPushReportsSkippedPaths244=== CONT TestStreamPushReportsSignatures2452026/11/11 23:22:20 INFO Garbage collection started246=== CONT TestSetClientTLSDoesNotMutateDefaultTransport247=== CONT TestSetClientTLSErrors248=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512249=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512250=== RUN TestEncodeNixBase32/empty_input251=== PAUSE TestEncodeNixBase32/empty_input252=== CONT TestStreamPushRequestLine253=== CONT TestStreamPushIsolatesFailures254--- PASS: TestFileTokenEmpty (0.00s)255=== CONT TestStreamPushGivesUpOnDeadServer2562026/11/11 23:22:20 ERROR Upload failed error="bad path" count=3257=== CONT TestStreamPushBatchesUnderLoad2582026/11/11 23:22:20 INFO Garbage collection started259=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false260=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false261=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true2622026/11/11 23:22:20 WARN Rate limiter enabled after throttle name=s3-test rate=5263=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true264=== CONT TestShellSplitErrors2652026/11/11 23:22:20 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:43039266=== CONT TestShellSplit267=== CONT TestSetClientTLS2682026/11/11 23:22:20 ERROR Upload failed error=boom count=1269--- PASS: TestFileTokenMissing (0.00s)270--- PASS: TestStreamPushIsolatesFailures (0.00s)271--- PASS: TestClientSignaturesByStorePath (0.00s)272--- PASS: TestScriptTokenBadJSON (3.44s)2732026/11/11 23:22:20 ERROR Upload failed error="connection refused" count=20274--- PASS: TestStreamPushReportsSkippedPaths (0.00s)275--- PASS: TestFileTokenReadsAndCaches (0.00s)2762026/11/11 23:22:20 ERROR Server seems unavailable, giving up on batch untried=17277--- PASS: TestStaticToken (0.00s)278--- PASS: TestShellSplitErrors (0.00s)279=== CONT TestDoWithRetry_FinalResponseBodyReadable280=== CONT TestStreamPushStopsWhenCanceled281--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)282--- PASS: TestStreamPushStopsWhenCanceled (0.00s)283=== CONT TestRetryTimeoutOutlastsMaxRetries284=== CONT TestDoWithRetry_BodyReplayedViaGetBody285--- PASS: TestUploadMultipart_ReturnsAfterDroppedBody (0.05s)286=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter287--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (3.44s)288=== CONT TestStreamPushReportsEveryPath289--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (3.44s)290=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter291=== CONT TestRateLimiterFeedback/503_enables_limiter2922026/11/11 23:22:20 WARN Rate limiter enabled after throttle name=server-test rate=52932026/11/11 23:22:20 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:35527294--- PASS: TestShellSplit (0.00s)295=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method2962026/11/11 23:22:20 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:466872972026/11/11 23:22:20 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=02982026/11/11 23:22:20 WARN Rate limiter enabled after throttle name=server-test rate=52992026/11/11 23:22:20 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:41309300--- PASS: TestStreamPushReportsEveryPath (0.00s)301=== CONT TestPathInfoCACompatibility/new_structured_format_-_text302=== CONT TestPathInfoCACompatibility/old_string_format_-_text303=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive304=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths305--- PASS: TestPathInfoCACompatibility (0.00s)306 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)307 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)308 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)309 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)310 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)311=== CONT TestParsePathInfoJSON/invalid_JSON312=== CONT TestParsePathInfoJSON/empty_input313=== CONT TestParsePathInfoJSON/Lix_format3142026/11/11 23:22:20 ERROR Upload failed error=boom count=1315=== CONT TestParsePathInfoJSON/whitespace_only316=== CONT TestPartSizeForNAR/capped_at_5_GiB317=== CONT TestPartSizeForNAR/5_TiB_S3_max_object318=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum319=== CONT TestPartSizeForNAR/small_stays_at_minimum320=== CONT TestFilterOversizedClosures/no_limit_keeps_everything321=== CONT TestConvertHashToNix32/SRI_format_to_Nix32322=== CONT TestFilterOversizedClosures/all_closures_skipped323=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3242026/11/11 23:22:20 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=50325=== CONT TestPartSizeForNAR/1_TiB326=== CONT TestConvertHashToNix32/invalid_format3272026/11/11 23:22:20 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:46687328=== CONT TestGetStorePathHash/valid_store_path329=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error330=== CONT TestGetStorePathHash/basename_without_hyphen_should_error331=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)332=== CONT TestEncodeNixBase32/test_string_hash333=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512334=== CONT TestConvertHashToNix32/already_Nix32_format335=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI3362026/11/11 23:22:20 WARN Rate limiter backed off name=server-test rate=53372026/11/11 23:22:20 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:41309338=== CONT TestPartSizeForNAR/zero_stays_at_minimum339=== CONT TestEncodeNixBase32/empty_input340=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error3412026/11/11 23:22:20 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=2000342=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true3432026/11/11 23:22:20 WARN Rate limiter backed off name=server-test rate=53442026/11/11 23:22:20 WARN Rate limiter enabled after throttle name=server-test rate=5345=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts346=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon3472026/11/11 23:22:20 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:39477348--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)349 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)350 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)351--- PASS: TestStreamPushReportsSignatures (0.00s)352--- PASS: TestParsePathInfoJSON (0.00s)353 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)354 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)355 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)356 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)357 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)358=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false359--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.00s)360--- PASS: TestEncodeNixBase32 (0.05s)361 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)362 --- PASS: TestEncodeNixBase32/empty_input (0.00s)363--- PASS: TestGetStorePathHash (2.86s)364 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)365 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)366 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)367 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)368--- PASS: TestPartSizeForNAR (2.69s)369 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)370 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)371 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)372 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)373 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)374 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)375 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)376--- PASS: TestFilterOversizedClosures (0.05s)377 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)378 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)379 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)380--- PASS: TestPathInfoHashCompatibility (3.44s)381 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)382 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)383 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)384 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)3852026/11/11 23:22:20 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:39123/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:39123/api/uploads/complete386--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.21s)3872026/11/11 23:22:20 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"3882026/11/11 23:22:20 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:466873892026/11/11 23:22:20 WARN Rate limiter backed off name=server-test rate=5390--- PASS: TestConvertHashToNix32 (2.90s)391 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)392 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)393 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)3942026/11/11 23:22:20 WARN Garbage collection finished on another replica. Its statistics are not available here395--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (3.66s)396--- PASS: TestStreamPushBatchesUnderLoad (0.00s)397 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)398 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.21s)399--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (3.66s)400--- PASS: TestRateLimiterFeedback (0.00s)401 --- PASS: TestRateLimiterFeedback/429_enables_limiter (3.44s)402 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)403 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)404 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.21s)4052026/11/11 23:22:20 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:46687406--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.22s)4072026/11/11 23:22:20 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:46687408=== RUN TestSetClientTLSErrors/missing_cert_file409=== PAUSE TestSetClientTLSErrors/missing_cert_file410=== RUN TestSetClientTLSErrors/missing_key_file411=== PAUSE TestSetClientTLSErrors/missing_key_file412=== RUN TestSetClientTLSErrors/missing_ca_file413=== PAUSE TestSetClientTLSErrors/missing_ca_file414=== RUN TestSetClientTLSErrors/invalid_ca_file415=== PAUSE TestSetClientTLSErrors/invalid_ca_file416=== CONT TestSetClientTLSErrors/missing_cert_file417=== RUN TestSetClientTLS/rejects_connection_without_client_cert418=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert419=== CONT TestSetClientTLSErrors/missing_ca_file420=== CONT TestSetClientTLSErrors/missing_key_file421=== CONT TestSetClientTLSErrors/invalid_ca_file4222026/11/11 23:22:20 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:46687423=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA424=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA425=== RUN TestSetClientTLS/preserves_debug_logging_transport426=== PAUSE TestSetClientTLS/preserves_debug_logging_transport427=== CONT TestSetClientTLS/rejects_connection_without_client_cert428=== CONT TestSetClientTLS/preserves_debug_logging_transport429--- PASS: TestSetClientTLSErrors (0.22s)430 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)431 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)432 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)433 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)434=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA4352026/11/11 23:22:20 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:466874362026/11/11 23:22:20 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:466874372026/11/11 23:22:20 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:466874382026/11/11 23:22:20 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:466874392026/11/11 23:22:20 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:46687440--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.27s)4412026/11/11 23:22:20 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:46687442--- PASS: TestCaseHackSuffix (2.92s)443--- PASS: TestScriptTokenCachesUntilRefresh (2.92s)4442026/11/11 23:22:20 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:466874452026/11/11 23:22:20 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:466874462026/11/11 23:22:20 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:46687447--- PASS: TestRegisterUploadedObjectReusesConnections (3.67s)4482026/11/11 23:22:20 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:466874492026/11/11 23:22:20 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:466874502026/11/11 23:22:20 http: TLS handshake error from 127.0.0.1:60738: remote error: tls: bad certificate451--- PASS: TestSetClientTLS (0.22s)452 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)453 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)454 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)4552026/11/11 23:22:20 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:466874562026/11/11 23:22:20 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:46687457--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.88s)458--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (4.33s)459--- PASS: TestDumpPathSingleFile (3.75s)460--- PASS: TestStreamPushRequestLine (0.89s)461--- PASS: TestDumpPathWriterError (3.75s)462--- PASS: TestDumpPathMatchesNix (1.37s)463--- PASS: TestUploadMultipart_PartsInParallel (4.14s)464PASS465Running server tests...466The files belonging to this database system will be owned by user "nixbld".467This user must also own the server process.468469The database cluster will be initialized with locale "C".470The default database encoding has accordingly been set to "SQL_ASCII".471The default text search configuration will be set to "english".472473Data page checksums are enabled.474475creating directory /build/postgres3622544255/data ... ok476creating subdirectories ... ok477selecting dynamic shared memory implementation ... posix478selecting default "max_connections" ... 100479selecting default "shared_buffers" ... 128MB480selecting default time zone ... UTC481creating configuration files ... ok482running bootstrap script ... ok483performing post-bootstrap initialization ... ok484syncing data to disk ... ok485486initdb: warning: enabling "trust" authentication for local connections487initdb: 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.488489Success. You can now start the database server using:490491 pg_ctl -D /build/postgres3622544255/data -l logfile start492493/build/postgres3622544255:5432 - no response494/build/postgres3622544255:5432 - no response4952026-11-11 23:22:29.255 UTC [128] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4962026-11-11 23:22:29.255 UTC [128] LOG: listening on Unix socket "/build/postgres3622544255/.s.PGSQL.5432"4972026-11-11 23:22:29.261 UTC [136] LOG: database system was shut down at 2026-11-11 23:22:28 UTC4982026-11-11 23:22:29.270 UTC [128] LOG: database system is ready to accept connections499/build/postgres3622544255:5432 - accepting connections500{"timestamp":"2026-11-11T23:22:54.967909007Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"9f32e7e3-63f5-47cc-9edd-d5c30c2a201c","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":18,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(200)"}501{"timestamp":"2026-11-11T23:22:55.099027917Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"d64f1c55-4a58-44f9-8e53-8e6ddc987c50","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(207)"}502{"timestamp":"2026-11-11T23:22:55.202836006Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"d77f1513-3c38-4756-9d89-90803adf90fb","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(197)"}503=== RUN TestAbortSucceeded504=== PAUSE TestAbortSucceeded505=== RUN TestService_AuthMiddleware506=== PAUSE TestService_AuthMiddleware507=== RUN TestService_AuthMiddleware_MTLSProxyHeader508=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader509=== RUN TestService_AuthMiddleware_MTLSBoundSubjects510=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects511=== RUN TestService_ReadAuthMiddleware512=== PAUSE TestService_ReadAuthMiddleware513=== RUN TestService_AuthMiddleware_OIDC514=== PAUSE TestService_AuthMiddleware_OIDC515=== RUN TestService_RequireScope_OIDC516=== PAUSE TestService_RequireScope_OIDC517=== RUN TestService_ReadScope_PublicByDefault518=== PAUSE TestService_ReadScope_PublicByDefault519=== RUN TestCacheConfigHandler520=== PAUSE TestCacheConfigHandler521=== RUN TestCacheStatsHandler522=== PAUSE TestCacheStatsHandler523=== RUN TestClientCADerivations524=== PAUSE TestClientCADerivations525=== RUN TestClientErrorHandling526=== PAUSE TestClientErrorHandling527=== RUN TestClientIntegration528=== PAUSE TestClientIntegration529=== RUN TestClientMultipleUploads530=== PAUSE TestClientMultipleUploads531=== RUN TestClientWithDependencies532=== PAUSE TestClientWithDependencies533=== RUN TestClientSharedPathCommittedMidPush534=== PAUSE TestClientSharedPathCommittedMidPush535=== RUN TestPinProtectsFromGC536=== PAUSE TestPinProtectsFromGC537=== RUN TestClientPushesUseOnePush538=== PAUSE TestClientPushesUseOnePush539=== RUN TestClientFallsBackToClosures540=== PAUSE TestClientFallsBackToClosures541=== RUN TestDeleteClosuresRacingPins542=== PAUSE TestDeleteClosuresRacingPins543=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock544=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock545=== RUN TestResolveDBConnectionString546=== PAUSE TestResolveDBConnectionString547=== RUN TestConnectWaitsForAPeerMigration548=== PAUSE TestConnectWaitsForAPeerMigration549=== RUN TestLeadElectsOneAndHandsOver550=== PAUSE TestLeadElectsOneAndHandsOver551=== RUN TestLeadIncumbentWinsAfterRestart5522026/11/11 23:22:56 INFO lead: acquired remote=192.0.2.1:1234 generation=15532026/11/11 23:22:57 INFO lead: released remote=192.0.2.1:1234 generation=15542026/11/11 23:22:57 INFO lead: acquired remote=192.0.2.1:1234 generation=25552026/11/11 23:22:58 INFO lead: released remote=192.0.2.1:1234 generation=2556--- PASS: TestLeadIncumbentWinsAfterRestart (3.35s)557=== RUN TestLeadUnannouncedStandbyYieldsToIncumbent558=== PAUSE TestLeadUnannouncedStandbyYieldsToIncumbent559=== RUN TestLeadIncumbentAnnouncesAtOnce560=== PAUSE TestLeadIncumbentAnnouncesAtOnce561=== RUN TestLeadGenerationGrowsWithEveryGrant562=== PAUSE TestLeadGenerationGrowsWithEveryGrant563=== RUN TestLeadEndsOnShutdown564=== PAUSE TestLeadEndsOnShutdown565=== RUN TestLeadEndsWhenItsConnectionHangs5662026/11/11 23:23:00 INFO lead: acquired remote=192.0.2.1:1234 generation=15672026-11-11 23:23:01.660 UTC [388] FATAL: terminating connection due to administrator command5682026/11/11 23:23:01 INFO lead: acquired remote=192.0.2.1:1234 generation=25692026/11/11 23:23:02 WARN lead: lock connection lost error="timeout: context deadline exceeded"5702026/11/11 23:23:02 INFO lead: released remote=192.0.2.1:1234 generation=15712026/11/11 23:23:03 INFO lead: released remote=192.0.2.1:1234 generation=2572--- PASS: TestLeadEndsWhenItsConnectionHangs (4.58s)573=== RUN TestGCAdvisoryLockBlocksConcurrentRun574=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun575=== RUN TestGCBugBareHashReferences576=== PAUSE TestGCBugBareHashReferences577=== RUN TestGCMetrics578=== PAUSE TestGCMetrics579=== RUN TestPushDedupSurvivesConcurrentGC580=== PAUSE TestPushDedupSurvivesConcurrentGC581=== RUN TestDeduplicatedObjectsRecordedAsPending582=== PAUSE TestDeduplicatedObjectsRecordedAsPending583=== RUN TestGCSweepSkipsPendingObjects584=== PAUSE TestGCSweepSkipsPendingObjects585=== RUN TestTombstonedObjectOfferedWithoutWaiting586=== PAUSE TestTombstonedObjectOfferedWithoutWaiting587=== RUN TestGCSweepDeliversEachKeyOnce588=== PAUSE TestGCSweepDeliversEachKeyOnce589=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection590=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection591=== RUN TestForceGCDuringPushOffersSweptObject592=== PAUSE TestForceGCDuringPushOffersSweptObject593=== RUN TestFailedS3DeleteKeepsTombstone594=== PAUSE TestFailedS3DeleteKeepsTombstone595=== RUN TestSweepSkipsRowsLockedByPush596=== PAUSE TestSweepSkipsRowsLockedByPush597=== RUN TestRegisterCompletedObjectNeedsPendingRow598=== PAUSE TestRegisterCompletedObjectNeedsPendingRow599=== RUN TestGetExistingObjectsLocksRows600=== PAUSE TestGetExistingObjectsLocksRows601=== RUN TestSweepRechecksPendingAfterLocking602=== PAUSE TestSweepRechecksPendingAfterLocking603=== RUN TestPushWaitsForSweepHoldingRow604=== PAUSE TestPushWaitsForSweepHoldingRow605=== RUN TestCommitRacingPendingCleanupKeepsObjects606=== PAUSE TestCommitRacingPendingCleanupKeepsObjects607=== RUN TestGCEndsOnShutdown608=== PAUSE TestGCEndsOnShutdown609=== RUN TestGCTaskStore_StartNew610=== PAUSE TestGCTaskStore_StartNew611=== RUN TestGCTaskStore_DeduplicateSameParams612=== PAUSE TestGCTaskStore_DeduplicateSameParams613=== RUN TestGCTaskStore_ConflictDifferentParams614=== PAUSE TestGCTaskStore_ConflictDifferentParams615=== RUN TestGCTaskStore_GetEmpty616=== PAUSE TestGCTaskStore_GetEmpty617=== RUN TestGCTaskStore_GetReturnsLatest618=== PAUSE TestGCTaskStore_GetReturnsLatest619=== RUN TestGCTaskStore_CompletedAllowsNewTask620=== PAUSE TestGCTaskStore_CompletedAllowsNewTask621=== RUN TestGCTaskStore_PhaseUpdates622=== PAUSE TestGCTaskStore_PhaseUpdates623=== RUN TestGCTaskStore_Fail624=== PAUSE TestGCTaskStore_Fail625=== RUN TestGracefulShutdownDrainsInflight626=== PAUSE TestGracefulShutdownDrainsInflight627=== RUN TestService_healthCheckHandler628=== PAUSE TestService_healthCheckHandler629=== RUN TestService_readinessHandler630=== PAUSE TestService_readinessHandler631=== RUN TestGenerateLandingPage632=== PAUSE TestGenerateLandingPage633=== RUN TestEnsureAbortUploadsRule634=== PAUSE TestEnsureAbortUploadsRule635=== RUN TestCacheConfigHandlerMaxNarSize636=== PAUSE TestCacheConfigHandlerMaxNarSize637=== RUN TestCreatePendingClosureRejectsOversizedNAR638=== PAUSE TestCreatePendingClosureRejectsOversizedNAR639=== RUN TestNARDeduplicationMetadataUploadBug640=== PAUSE TestNARDeduplicationMetadataUploadBug641=== RUN TestMetricsInventory642=== PAUSE TestMetricsInventory643=== RUN TestMetricsCommit644=== PAUSE TestMetricsCommit645=== RUN TestService_NativeMTLS646=== PAUSE TestService_NativeMTLS647=== RUN TestServerTLSConfig648=== PAUSE TestServerTLSConfig649=== RUN TestMultipartCleanup650=== PAUSE TestMultipartCleanup651=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded652=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded653=== RUN TestPendingCleanupUsesOneCutoff654=== PAUSE TestPendingCleanupUsesOneCutoff655=== RUN TestObjectStatsTrigger656=== PAUSE TestObjectStatsTrigger657=== RUN TestObjectStatsUpdatedOncePerCommit658=== PAUSE TestObjectStatsUpdatedOncePerCommit659=== RUN TestOrphanedObjectsGC660=== PAUSE TestOrphanedObjectsGC661=== RUN TestOrphanedObjectsGCStressTest662=== PAUSE TestOrphanedObjectsGCStressTest663=== RUN TestCreatePin_ReservedPins664=== PAUSE TestCreatePin_ReservedPins665=== RUN TestPresentReportsOnlyClosureRoots666=== PAUSE TestPresentReportsOnlyClosureRoots667=== RUN TestPresentRefreshesOnlyStaleClosures668=== PAUSE TestPresentRefreshesOnlyStaleClosures669=== RUN TestPresentNotReportedWhileGCDeletesClosure670=== PAUSE TestPresentNotReportedWhileGCDeletesClosure671=== RUN TestParseSingleRange672=== PAUSE TestParseSingleRange673=== RUN TestProxyHeadersOnlyTrustedOnSocket6742026/11/11 23:23:04 INFO Starting HTTP server address=127.0.0.1:417816752026/11/11 23:23:04 INFO Starting HTTP server address=proxy.sock6762026/11/11 23:23:04 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6772026/11/11 23:23:04 INFO Shutdown signal received, draining in-flight requests timeout=10s678--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.90s)679=== RUN TestIsValidCachePath680=== PAUSE TestIsValidCachePath681=== RUN TestReadProxyNarinfo682=== PAUSE TestReadProxyNarinfo683=== RUN TestReadProxyNarinfoAlreadyDecompressed684=== PAUSE TestReadProxyNarinfoAlreadyDecompressed685=== RUN TestReadProxyContentNegotiation686=== PAUSE TestReadProxyContentNegotiation687=== RUN TestReadProxyNarStreaming688=== PAUSE TestReadProxyNarStreaming689=== RUN TestReadProxy404690=== PAUSE TestReadProxy404691=== RUN TestReadProxyInvalidPath692=== PAUSE TestReadProxyInvalidPath693=== RUN TestReadProxyHead694=== PAUSE TestReadProxyHead695=== RUN TestReadProxyOutlastsServerWriteTimeout696=== PAUSE TestReadProxyOutlastsServerWriteTimeout697=== RUN TestReadProxyConditionalGet698=== PAUSE TestReadProxyConditionalGet699=== RUN TestReadProxyRootRedirectsToIndexHTML700=== PAUSE TestReadProxyRootRedirectsToIndexHTML701=== RUN TestReadProxyDisabled702=== PAUSE TestReadProxyDisabled703=== RUN TestReadRedirectNar704=== PAUSE TestReadRedirectNar705=== RUN TestReadRedirectKeepsNarinfoProxied706=== PAUSE TestReadRedirectKeepsNarinfoProxied707=== RUN TestReadProxyRangeRequest708=== PAUSE TestReadProxyRangeRequest709=== RUN TestReadRedirectUsesPublicS3URL710=== PAUSE TestReadRedirectUsesPublicS3URL711=== RUN TestPush_OverlappingRootsStoreOneRowPerKey712=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey713=== RUN TestPush_CompleteCommitsEveryRoot714=== PAUSE TestPush_CompleteCommitsEveryRoot715=== RUN TestPush_RepeatedRootCommitsOnce716=== PAUSE TestPush_RepeatedRootCommitsOnce717=== RUN TestPush_CompleteWaitsForCleanupOfThePush718=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush719=== RUN TestPush_RootsAreLockedInByteOrder720=== PAUSE TestPush_RootsAreLockedInByteOrder721=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit722=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit723=== RUN TestPush_RejectsBadRequests724=== PAUSE TestPush_RejectsBadRequests725=== RUN TestPush_SignsNarinfosOfItsPendingObjects726=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects727=== RUN TestSharedNarBothUploadsComplete728=== PAUSE TestSharedNarBothUploadsComplete729=== RUN TestCompleteMultipartUpload_ErrorButObjectExists730=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists731=== RUN TestCompletedNarNotReofferedAcrossClosures732=== PAUSE TestCompletedNarNotReofferedAcrossClosures733=== RUN TestPresignedUploadRegisteredBeforeCommit734=== PAUSE TestPresignedUploadRegisteredBeforeCommit735=== RUN TestService_Rustfstest736=== PAUSE TestService_Rustfstest737=== RUN TestParseSize738=== PAUSE TestParseSize739=== RUN TestSkippedUploadsHandler740=== PAUSE TestSkippedUploadsHandler741=== RUN TestSystemdListenerNotActivated742--- PASS: TestSystemdListenerNotActivated (0.00s)743=== RUN TestWatchdogBeatsWhenHealthy744--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)745=== RUN TestWatchdogSkipsWhenUnhealthy7462026/11/11 23:23:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7472026/11/11 23:23:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7482026/11/11 23:23:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7492026/11/11 23:23:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7502026/11/11 23:23:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7512026/11/11 23:23:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7522026/11/11 23:23:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7532026/11/11 23:23:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7542026/11/11 23:23:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7552026/11/11 23:23:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"756--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)757=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle758=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle759=== RUN TestProxyWriteTimeout760=== PAUSE TestProxyWriteTimeout761=== RUN TestPendingClosureWriteTimeout762=== PAUSE TestPendingClosureWriteTimeout763=== RUN TestIsValidUploadKey764=== PAUSE TestIsValidUploadKey765=== RUN TestUploadHandlersRejectInvalidKeys766=== PAUSE TestUploadHandlersRejectInvalidKeys767=== RUN TestUploadHandlersRejectOversizedBody768=== PAUSE TestUploadHandlersRejectOversizedBody769=== RUN TestService_cleanupPendingClosuresHandler770=== PAUSE TestService_cleanupPendingClosuresHandler771=== RUN TestService_createPendingClosureHandler772=== PAUSE TestService_createPendingClosureHandler773=== RUN TestService_verifyS3Integrity774=== PAUSE TestService_verifyS3Integrity775=== RUN TestService_verifyS3ReuploadsStaleNarinfo776=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo777=== RUN TestCompleteMultipartUnregistered778=== PAUSE TestCompleteMultipartUnregistered779=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT780=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT781=== CONT TestParseSize782=== CONT TestSweepRechecksPendingAfterLocking783=== CONT TestReadRedirectKeepsNarinfoProxied784=== CONT TestGCTaskStore_DeduplicateSameParams785=== CONT TestService_Rustfstest786=== CONT TestPresignedUploadRegisteredBeforeCommit787=== CONT TestCompletedNarNotReofferedAcrossClosures788=== CONT TestCompleteMultipartUpload_ErrorButObjectExists789=== CONT TestSharedNarBothUploadsComplete790=== CONT TestPush_SignsNarinfosOfItsPendingObjects791=== CONT TestPush_RejectsBadRequests792=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit793=== CONT TestPush_RootsAreLockedInByteOrder794=== CONT TestPush_CompleteWaitsForCleanupOfThePush795=== CONT TestPush_RepeatedRootCommitsOnce796=== CONT TestPush_CompleteCommitsEveryRoot797=== CONT TestPush_OverlappingRootsStoreOneRowPerKey798=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT799=== CONT TestGCTaskStore_StartNew800=== CONT TestCompleteMultipartUnregistered801=== CONT TestGCEndsOnShutdown802=== RUN TestGCEndsOnShutdown/before_the_run803=== PAUSE TestGCEndsOnShutdown/before_the_run804=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete805=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete806=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark807=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark808=== CONT TestCommitRacingPendingCleanupKeepsObjects809=== CONT TestService_verifyS3ReuploadsStaleNarinfo810=== CONT TestPushWaitsForSweepHoldingRow811=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed812=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed813=== RUN TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed814=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed815=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost816=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost817=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed818=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed819=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed820=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed821=== CONT TestService_verifyS3Integrity822=== CONT TestReadRedirectUsesPublicS3URL823=== CONT TestReadProxyRangeRequest824=== CONT TestAbortSucceeded825=== CONT TestService_createPendingClosureHandler826--- PASS: TestParseSize (0.00s)827--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)828=== CONT TestUploadHandlersRejectOversizedBody829--- PASS: TestGCTaskStore_StartNew (0.00s)830--- PASS: TestAbortSucceeded (0.00s)831=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure832=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure833=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart834=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart835=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts836=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts837=== CONT TestService_cleanupPendingClosuresHandler8382026/11/11 23:23:08 INFO Received push request method=POST path=/api/pushes8392026/11/11 23:23:08 INFO Received push request method=POST path=/api/pushes8402026/11/11 23:23:08 INFO Received push request method=POST path=/api/pushes8412026/11/11 23:23:08 INFO Received complete push request method=POST path=/api/pushes/1/complete8422026/11/11 23:23:08 INFO Received push request method=POST path=/api/pushes8432026/11/11 23:23:08 INFO Received complete push request method=POST path=/api/pushes/1/complete844=== RUN TestPush_RejectsBadRequests/bad_root845=== PAUSE TestPush_RejectsBadRequests/bad_root846=== RUN TestPush_RejectsBadRequests/root_not_in_objects847=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects848=== RUN TestPush_RejectsBadRequests/no_roots849=== PAUSE TestPush_RejectsBadRequests/no_roots850=== RUN TestPush_RejectsBadRequests/no_objects851=== PAUSE TestPush_RejectsBadRequests/no_objects852=== CONT TestResolveDBConnectionString853=== RUN TestResolveDBConnectionString/flag_wins854=== PAUSE TestResolveDBConnectionString/flag_wins855=== RUN TestResolveDBConnectionString/file_when_flag_empty856=== PAUSE TestResolveDBConnectionString/file_when_flag_empty857=== RUN TestResolveDBConnectionString/missing_file_is_an_error858=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error859=== RUN TestResolveDBConnectionString/PGHOST_allows_empty860=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty861=== RUN TestResolveDBConnectionString/nothing_configured862=== PAUSE TestResolveDBConnectionString/nothing_configured863=== CONT TestGetExistingObjectsLocksRows8642026/11/11 23:23:08 INFO Received uploads request method=POST path=/api/pending_closures8652026/11/11 23:23:08 INFO Received uploads request method=POST path=/api/pending_closures8662026/11/11 23:23:08 INFO Received uploads request method=POST path=/api/pending_closures867--- PASS: TestReadProxyRangeRequest (2.70s)868=== CONT TestRegisterCompletedObjectNeedsPendingRow8692026/11/11 23:23:08 INFO Received push request method=POST path=/api/pushes8702026/11/11 23:23:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8712026/11/11 23:23:08 INFO Signed narinfos id=1 count=18722026/11/11 23:23:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8732026/11/11 23:23:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8742026/11/11 23:23:08 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"8752026/11/11 23:23:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8762026/11/11 23:23:08 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"8772026/11/11 23:23:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8782026/11/11 23:23:08 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=18792026/11/11 23:23:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8802026/11/11 23:23:08 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo881--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (2.73s)882=== CONT TestGCMetrics8832026/11/11 23:23:08 INFO Received uploads request method=POST path=/api/pending_closures8842026/11/11 23:23:08 INFO Received uploads request method=POST path=/api/pending_closures8852026/11/11 23:23:08 INFO Received uploads request method=POST path=/api/pending_closures8862026/11/11 23:23:08 INFO Received push request method=POST path=/api/pushes887--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (4.07s)888=== CONT TestGCBugBareHashReferences8892026/11/11 23:23:08 INFO Received cleanup request method=DELETE path=/api/pending_closures8902026/11/11 23:23:08 INFO Aborted multipart uploads count=0 kept=08912026/11/11 23:23:08 INFO Received uploads request method=POST path=/api/pending_closures8922026/11/11 23:23:08 INFO Received cleanup request method=DELETE path=/api/pending_closures8932026/11/11 23:23:08 INFO Aborted multipart uploads count=1 kept=08942026/11/11 23:23:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8952026-11-11 23:23:08.504 UTC [479] ERROR: Closure does not exist: id=18962026-11-11 23:23:08.504 UTC [479] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE8972026-11-11 23:23:08.504 UTC [479] STATEMENT: -- name: CommitPendingClosure :one898 SELECT commit_pending_closure($1::bigint)::bigint899 9002026/11/11 23:23:08 INFO Received uploads request method=POST path=/api/pending_closures901--- PASS: TestService_cleanupPendingClosuresHandler (2.63s)902=== CONT TestGCAdvisoryLockBlocksConcurrentRun9032026-11-11 23:23:08.583 UTC [485] ERROR: Push does not exist: id=19042026-11-11 23:23:08.583 UTC [485] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE9052026-11-11 23:23:08.583 UTC [485] STATEMENT: SELECT commit_push($1)906--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (2.93s)907=== CONT TestLeadEndsOnShutdown9082026/11/11 23:23:08 INFO Received uploads request method=POST path=/api/pending_closures9092026/11/11 23:23:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete910--- PASS: TestService_Rustfstest (4.26s)911=== CONT TestLeadGenerationGrowsWithEveryGrant9122026/11/11 23:23:08 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZGM4ZDNkMDMtODNjNy00MWQyLTlmN2QtMzZiNTVlMjM4ZDE2LjIzNmQ2NTcxLTQ1MjAtNDI0Zi1hNTJhLWY4MGE5MWU1MjU5NngxNzk0NDM5Mzg4NTIzODQ4NTQ29132026/11/11 23:23:08 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZGM4ZDNkMDMtODNjNy00MWQyLTlmN2QtMzZiNTVlMjM4ZDE2LjIzNmQ2NTcxLTQ1MjAtNDI0Zi1hNTJhLWY4MGE5MWU1MjU5NngxNzk0NDM5Mzg4NTIzODQ4NTQ2 parts=1914--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (4.28s)915=== CONT TestLeadIncumbentAnnouncesAtOnce916--- PASS: TestReadRedirectUsesPublicS3URL (3.06s)917=== CONT TestLeadUnannouncedStandbyYieldsToIncumbent918--- PASS: TestReadRedirectKeepsNarinfoProxied (4.33s)919=== CONT TestLeadElectsOneAndHandsOver9202026/11/11 23:23:08 INFO Received uploads request method=POST path=/api/pending_closures9212026/11/11 23:23:08 INFO Received uploads request method=POST path=/api/pending_closures9222026/11/11 23:23:08 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9232026/11/11 23:23:08 INFO Received uploads request method=POST path=/api/pending_closures924--- PASS: TestPresignedUploadRegisteredBeforeCommit (4.40s)925=== CONT TestConnectWaitsForAPeerMigration9262026/11/11 23:23:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9272026/11/11 23:23:08 INFO Received push request method=POST path=/api/pushes9282026/11/11 23:23:08 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZGM4ZDNkMDMtODNjNy00MWQyLTlmN2QtMzZiNTVlMjM4ZDE2LmUyMTkzMTE5LWJiMDQtNDRhMi04ZDdkLWM5NGQyYzMyOWRhMngxNzk0NDM5Mzg4MzM3NTk3Mjcx parts=109292026/11/11 23:23:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9302026/11/11 23:23:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9312026/11/11 23:23:08 INFO Received complete push request method=POST path=/api/pushes/1/complete9322026/11/11 23:23:08 INFO Completed upload id=1 objects=2 duration=5.790975ms9332026/11/11 23:23:08 INFO Received uploads request method=POST path=/api/pending_closures9342026/11/11 23:23:08 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZGM4ZDNkMDMtODNjNy00MWQyLTlmN2QtMzZiNTVlMjM4ZDE2LjFhNjM4NWJkLTAwYTktNGVhYS1hMjEwLWYwOTRjOWQyOGFmMngxNzk0NDM5Mzg4Mzg4NzA4MTU4 parts=109352026/11/11 23:23:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9362026/11/11 23:23:08 INFO Received uploads request method=POST path=/api/pending_closures9372026/11/11 23:23:08 INFO Completed upload id=1 objects=2 duration=5.786295ms9382026/11/11 23:23:08 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009392026/11/11 23:23:08 INFO Received uploads request method=POST path=/api/pending_closures9402026/11/11 23:23:08 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9412026/11/11 23:23:08 WARN Found objects in DB but missing from S3, will re-upload count=1942--- PASS: TestService_verifyS3Integrity (3.22s)943=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection9442026/11/11 23:23:08 INFO Starting cleanup of old closures method=DELETE path=/api/closures9452026/11/11 23:23:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9462026/11/11 23:23:08 INFO Aborted multipart uploads count=0 kept=09472026/11/11 23:23:08 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst948--- PASS: TestCompleteMultipartUnregistered (4.48s)949=== CONT TestSweepSkipsRowsLockedByPush9502026/11/11 23:23:08 INFO Aborted multipart uploads count=0 kept=09512026/11/11 23:23:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9522026/11/11 23:23:08 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZGM4ZDNkMDMtODNjNy00MWQyLTlmN2QtMzZiNTVlMjM4ZDE2LjI3NDM2MTE0LTg5ZWYtNDNjNS1iYTg5LTA5YzQ2YjQ4NDJmNngxNzk0NDM5Mzg4MzE2NzQwODcy parts=129532026/11/11 23:23:08 INFO Received uploads request method=POST path=/api/pending_closures954--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (4.57s)955=== CONT TestFailedS3DeleteKeepsTombstone9562026/11/11 23:23:08 INFO Aborted multipart uploads count=0 kept=09572026/11/11 23:23:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9582026/11/11 23:23:09 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZGM4ZDNkMDMtODNjNy00MWQyLTlmN2QtMzZiNTVlMjM4ZDE2LjM3Y2UyM2YyLTE1Y2YtNGIzOS1iMDA5LWUxNTZmOGQ5YjI5OXgxNzk0NDM5Mzg4NjI4MDY2OTQw parts=129592026/11/11 23:23:09 INFO Received uploads request method=POST path=/api/pending_closures960--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.74s)961=== CONT TestPushDedupSurvivesConcurrentGC962--- PASS: TestPushWaitsForSweepHoldingRow (3.65s)963=== CONT TestGCSweepDeliversEachKeyOnce9642026/11/11 23:23:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9652026/11/11 23:23:09 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZGM4ZDNkMDMtODNjNy00MWQyLTlmN2QtMzZiNTVlMjM4ZDE2LmFhZDA2ZmYxLWNlM2YtNGYyMC04ZWIzLWU4NDAxM2Y5NjA5OXgxNzk0NDM5Mzg4MzMyMTg5NDM5 parts=12966--- PASS: TestSharedNarBothUploadsComplete (3.79s)967=== CONT TestForceGCDuringPushOffersSweptObject968=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows969=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows970=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check971=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check972=== CONT TestTombstonedObjectOfferedWithoutWaiting9732026/11/11 23:23:09 WARN Force mode enabled - objects will be deleted immediately without grace period9742026/11/11 23:23:09 WARN Force mode enabled - objects will be deleted immediately without grace period9752026-11-11 23:23:09.944 UTC [486] ERROR: could not obtain lock on row in relation "closures"9762026-11-11 23:23:09.944 UTC [486] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9772026/11/11 23:23:09 INFO Completed push id=1 objects=4 duration=1.709035634s9782026/11/11 23:23:09 INFO Completed push id=1 objects=4 duration=1.689907432s9792026/11/11 23:23:09 INFO Received push request method=POST path=/api/pushes9802026-11-11 23:23:09.945 UTC [486] ERROR: could not obtain lock on row in relation "closures"9812026-11-11 23:23:09.945 UTC [486] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT982--- PASS: TestPush_RepeatedRootCommitsOnce (4.29s)983=== CONT TestGCSweepSkipsPendingObjects9842026-11-11 23:23:09.947 UTC [486] ERROR: could not obtain lock on row in relation "closures"9852026-11-11 23:23:09.947 UTC [486] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9862026/11/11 23:23:09 INFO Completed push id=1 objects=6 duration=1.114120582s9872026-11-11 23:23:09.947 UTC [486] ERROR: could not obtain lock on row in relation "closures"9882026-11-11 23:23:09.947 UTC [486] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9892026-11-11 23:23:09.948 UTC [486] ERROR: could not obtain lock on row in relation "closures"9902026-11-11 23:23:09.948 UTC [486] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT991--- PASS: TestPush_CompleteCommitsEveryRoot (5.56s)992=== CONT TestDeduplicatedObjectsRecordedAsPending9932026/11/11 23:23:09 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=09942026/11/11 23:23:09 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=0995--- PASS: TestPush_RootsAreLockedInByteOrder (4.30s)996=== CONT TestClientErrorHandling997=== RUN TestClientErrorHandling/InvalidStorePath9982026/11/11 23:23:09 INFO Vacuumed table table=pending_closures999=== PAUSE TestClientErrorHandling/InvalidStorePath1000=== RUN TestClientErrorHandling/InvalidAuthToken1001=== PAUSE TestClientErrorHandling/InvalidAuthToken10022026/11/11 23:23:09 INFO Vacuumed table table=pending_closures1003=== RUN TestClientErrorHandling/ServerNotAvailable1004=== PAUSE TestClientErrorHandling/ServerNotAvailable1005=== CONT TestService_AuthMiddleware_MTLSBoundSubjects10062026/11/11 23:23:09 INFO Vacuumed table table=pending_objects10072026/11/11 23:23:09 INFO Vacuumed table table=multipart_uploads10082026/11/11 23:23:09 INFO Vacuumed table table=pending_objects10092026/11/11 23:23:09 INFO Vacuumed table table=closures10102026/11/11 23:23:09 INFO Vacuumed table table=objects10112026/11/11 23:23:09 INFO Vacuumed table table=multipart_uploads10122026/11/11 23:23:09 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=010132026/11/11 23:23:09 INFO Vacuumed table table=pending_closures10142026/11/11 23:23:09 INFO Vacuumed table table=closures10152026/11/11 23:23:09 INFO Vacuumed table table=objects10162026/11/11 23:23:09 INFO Vacuumed table table=pending_objects10172026/11/11 23:23:09 INFO Vacuumed table table=multipart_uploads10182026/11/11 23:23:09 INFO Vacuumed table table=closures10192026/11/11 23:23:10 INFO Vacuumed table table=objects1020--- PASS: TestSweepRechecksPendingAfterLocking (5.62s)1021=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock10222026/11/11 23:23:10 INFO Aborted multipart uploads count=0 kept=010232026/11/11 23:23:10 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001024--- PASS: TestService_createPendingClosureHandler (4.38s)1025=== CONT TestService_AuthMiddleware_OIDC10262026/11/11 23:23:10 WARN Force mode enabled - objects will be deleted immediately without grace period10272026/11/11 23:23:10 INFO Aborted multipart uploads count=0 kept=010282026/11/11 23:23:10 INFO Received uploads request method=POST path=/api/pending_closures10292026/11/11 23:23:10 INFO Received uploads request method=POST path=/api/pending_closures1030--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.69s)1031=== CONT TestDeleteClosuresRacingPins10322026/11/11 23:23:10 INFO Received uploads request method=POST path=/api/pending_closures10332026/11/11 23:23:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41341/oidc10342026/11/11 23:23:10 INFO Aborted multipart uploads count=0 kept=010352026/11/11 23:23:10 INFO Aborted multipart uploads count=0 kept=010362026/11/11 23:23:10 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"1037--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (1.70s)1038=== CONT TestService_ReadAuthMiddleware10392026/11/11 23:23:10 INFO lead: acquired remote=192.0.2.1:1234 generation=110402026/11/11 23:23:10 INFO Aborted multipart uploads count=0 kept=010412026/11/11 23:23:10 INFO Received uploads request method=POST path=/api/pending_closures10422026/11/11 23:23:10 INFO lead: acquired remote=192.0.2.1:1234 generation=110432026/11/11 23:23:10 INFO Aborted multipart uploads count=0 kept=01044--- PASS: TestGetExistingObjectsLocksRows (2.08s)1045=== CONT TestClientFallsBackToClosures10462026/11/11 23:23:10 INFO lead: acquired remote=192.0.2.1:1234 generation=110472026/11/11 23:23:10 INFO lead: released remote=192.0.2.1:1234 generation=11048--- PASS: TestLeadIncumbentAnnouncesAtOnce (1.69s)1049=== CONT TestClientSharedPathCommittedMidPush1050--- PASS: TestRegisterCompletedObjectNeedsPendingRow (2.03s)1051=== CONT TestClientWithDependencies10522026/11/11 23:23:10 INFO lead: acquired remote=192.0.2.1:1234 generation=11053--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (1.60s)1054=== CONT TestService_RequireScope_OIDC10552026/11/11 23:23:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40623/oidc1056--- PASS: TestGCBugBareHashReferences (2.41s)1057=== CONT TestClientPushesUseOnePush10582026/11/11 23:23:10 WARN Force mode enabled - objects will be deleted immediately without grace period10592026/11/11 23:23:10 WARN Force mode enabled - objects will be deleted immediately without grace period10602026/11/11 23:23:10 WARN Force mode enabled - objects will be deleted immediately without grace period10612026/11/11 23:23:10 WARN Force mode enabled - objects will be deleted immediately without grace period10622026/11/11 23:23:10 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=010632026/11/11 23:23:10 INFO Vacuumed table table=pending_closures10642026/11/11 23:23:10 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=010652026/11/11 23:23:10 INFO Vacuumed table table=pending_objects10662026/11/11 23:23:10 INFO Vacuumed table table=multipart_uploads10672026/11/11 23:23:10 INFO Vacuumed table table=pending_closures10682026/11/11 23:23:10 INFO Vacuumed table table=closures10692026/11/11 23:23:10 INFO Vacuumed table table=pending_objects10702026/11/11 23:23:10 INFO Vacuumed table table=multipart_uploads10712026/11/11 23:23:10 INFO Vacuumed table table=closures10722026/11/11 23:23:10 INFO Vacuumed table table=objects1073--- PASS: TestCommitRacingPendingCleanupKeepsObjects (6.48s)1074=== CONT TestClientMultipleUploads10752026/11/11 23:23:10 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=010762026/11/11 23:23:10 INFO Vacuumed table table=objects1077--- PASS: TestGCMetrics (2.52s)1078=== CONT TestPinProtectsFromGC10792026/11/11 23:23:10 INFO Vacuumed table table=pending_closures10802026/11/11 23:23:10 INFO Vacuumed table table=pending_objects10812026/11/11 23:23:10 INFO Aborted multipart uploads count=0 kept=010822026/11/11 23:23:10 INFO Vacuumed table table=multipart_uploads10832026/11/11 23:23:10 WARN Force mode enabled - objects will be deleted immediately without grace period10842026/11/11 23:23:10 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=010852026/11/11 23:23:10 INFO Vacuumed table table=closures10862026/11/11 23:23:10 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."10872026/11/11 23:23:10 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."10882026/11/11 23:23:10 INFO Vacuumed table table=objects1089--- PASS: TestFailedS3DeleteKeepsTombstone (1.96s)1090=== CONT TestClientIntegration10912026/11/11 23:23:10 INFO Vacuumed table table=pending_closures10922026/11/11 23:23:10 INFO Vacuumed table table=pending_objects10932026/11/11 23:23:10 INFO Aborted multipart uploads count=0 kept=010942026/11/11 23:23:10 WARN Force mode enabled - objects will be deleted immediately without grace period10952026/11/11 23:23:10 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=010962026/11/11 23:23:10 INFO Vacuumed table table=multipart_uploads10972026/11/11 23:23:10 INFO Vacuumed table table=pending_closures10982026/11/11 23:23:10 INFO Vacuumed table table=closures10992026/11/11 23:23:10 INFO Vacuumed table table=objects11002026/11/11 23:23:10 INFO Vacuumed table table=pending_objects11012026/11/11 23:23:10 INFO Vacuumed table table=multipart_uploads11022026/11/11 23:23:10 INFO Received complete push request method=POST path=/api/pushes/2/complete11032026/11/11 23:23:10 INFO Vacuumed table table=closures11042026/11/11 23:23:10 INFO Completed push id=2 objects=4 duration=5.485993ms11052026/11/11 23:23:10 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=01106--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (5.30s)1107=== CONT TestClientCADerivations11082026/11/11 23:23:10 INFO Vacuumed table table=objects11092026/11/11 23:23:10 INFO Vacuumed table table=pending_closures11102026/11/11 23:23:10 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=011112026/11/11 23:23:10 INFO Vacuumed table table=pending_objects11122026/11/11 23:23:10 INFO Vacuumed table table=pending_closures11132026/11/11 23:23:10 INFO Vacuumed table table=pending_objects1114--- PASS: TestPushDedupSurvivesConcurrentGC (1.83s)1115=== CONT TestPendingClosureWriteTimeout11162026/11/11 23:23:10 INFO Vacuumed table table=multipart_uploads11172026/11/11 23:23:10 INFO Vacuumed table table=closures11182026/11/11 23:23:10 INFO Vacuumed table table=multipart_uploads11192026/11/11 23:23:10 INFO Vacuumed table table=closures1120=== RUN TestPendingClosureWriteTimeout/empty1121=== PAUSE TestPendingClosureWriteTimeout/empty1122=== RUN TestPendingClosureWriteTimeout/400_objects1123=== PAUSE TestPendingClosureWriteTimeout/400_objects1124=== RUN TestPendingClosureWriteTimeout/670k_objects1125=== PAUSE TestPendingClosureWriteTimeout/670k_objects1126=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1127=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1128=== CONT TestService_AuthMiddleware_MTLSProxyHeader11292026/11/11 23:23:10 INFO Vacuumed table table=objects11302026/11/11 23:23:10 INFO Vacuumed table table=objects1131--- PASS: TestGCSweepDeliversEachKeyOnce (1.68s)1132=== CONT TestUploadHandlersRejectInvalidKeys1133=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1134=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1135=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1136=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1137=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1138=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1139=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1140=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1141=== CONT TestCacheStatsHandler1142--- PASS: TestSweepSkipsRowsLockedByPush (2.10s)1143=== CONT TestIsValidUploadKey1144=== RUN TestIsValidUploadKey/narinfo1145=== PAUSE TestIsValidUploadKey/narinfo1146=== RUN TestIsValidUploadKey/nar_zst1147=== PAUSE TestIsValidUploadKey/nar_zst1148=== RUN TestIsValidUploadKey/nar_xz1149=== PAUSE TestIsValidUploadKey/nar_xz1150=== RUN TestIsValidUploadKey/nar_plain1151=== PAUSE TestIsValidUploadKey/nar_plain1152=== RUN TestIsValidUploadKey/listing1153=== PAUSE TestIsValidUploadKey/listing1154=== RUN TestIsValidUploadKey/build_log1155=== PAUSE TestIsValidUploadKey/build_log1156=== RUN TestIsValidUploadKey/build_log_home-manager_file1157=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1158=== RUN TestIsValidUploadKey/build_log_plus_in_name1159=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1160=== RUN TestIsValidUploadKey/build_log_question_mark1161=== PAUSE TestIsValidUploadKey/build_log_question_mark1162=== RUN TestIsValidUploadKey/build_log_equals1163=== PAUSE TestIsValidUploadKey/build_log_equals1164=== RUN TestIsValidUploadKey/realisation1165=== PAUSE TestIsValidUploadKey/realisation1166=== RUN TestIsValidUploadKey/realisation_plus_in_output1167=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1168=== RUN TestIsValidUploadKey/nix-cache-info1169=== PAUSE TestIsValidUploadKey/nix-cache-info1170=== RUN TestIsValidUploadKey/index.html1171=== PAUSE TestIsValidUploadKey/index.html1172=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1173=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1174=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1175=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1176=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1177=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1178=== RUN TestIsValidUploadKey/traversal1179=== PAUSE TestIsValidUploadKey/traversal1180=== RUN TestIsValidUploadKey/traversal_nar1181=== PAUSE TestIsValidUploadKey/traversal_nar1182=== RUN TestIsValidUploadKey/absolute1183=== PAUSE TestIsValidUploadKey/absolute1184=== RUN TestIsValidUploadKey/empty_key1185=== PAUSE TestIsValidUploadKey/empty_key1186=== RUN TestIsValidUploadKey/unknown_type1187=== PAUSE TestIsValidUploadKey/unknown_type1188=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1189--- PASS: TestService_ReadAuthMiddleware (0.79s)1190=== CONT TestService_ReadScope_PublicByDefault11912026/11/11 23:23:11 INFO Received uploads request method=POST path=/api/pending_closures1192--- PASS: TestDeduplicatedObjectsRecordedAsPending (1.14s)1193=== CONT TestCacheConfigHandler1194=== RUN TestCacheConfigHandler/full_config,_no_issuer1195=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1196=== RUN TestCacheConfigHandler/no_cache_url_configured1197=== PAUSE TestCacheConfigHandler/no_cache_url_configured1198=== RUN TestCacheConfigHandler/no_signing_keys1199=== PAUSE TestCacheConfigHandler/no_signing_keys1200=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1201=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1202=== CONT TestProxyWriteTimeout1203=== RUN TestProxyWriteTimeout/narinfo1204=== PAUSE TestProxyWriteTimeout/narinfo1205=== RUN TestProxyWriteTimeout/1_GiB_nar1206=== PAUSE TestProxyWriteTimeout/1_GiB_nar1207=== RUN TestProxyWriteTimeout/10_GiB_nar1208=== PAUSE TestProxyWriteTimeout/10_GiB_nar1209=== RUN TestProxyWriteTimeout/unknown_size1210=== PAUSE TestProxyWriteTimeout/unknown_size1211=== CONT TestService_AuthMiddleware12122026/11/11 23:23:11 INFO Received uploads request method=POST path=/api/pending_closures12132026/11/11 23:23:11 INFO Aborted multipart uploads count=0 kept=012142026/11/11 23:23:11 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"12152026/11/11 23:23:11 WARN mTLS auth: bound subjects configured but subject DN unavailable12162026/11/11 23:23:11 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1217--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.30s)1218=== CONT TestObjectStatsTrigger1219=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1220=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1221=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1222=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1223=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1224=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1225=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1226=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1227=== CONT TestSkippedUploadsHandler12282026/11/11 23:23:11 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001229--- PASS: TestSkippedUploadsHandler (0.01s)1230=== CONT TestReadProxyNarinfoAlreadyDecompressed12312026/11/11 23:23:11 INFO lead: released remote=192.0.2.1:1234 generation=112322026/11/11 23:23:11 INFO lead: acquired remote=192.0.2.1:1234 generation=112332026/11/11 23:23:11 INFO lead: acquired remote=192.0.2.1:1234 generation=212342026/11/11 23:23:11 INFO lead: released remote=192.0.2.1:1234 generation=11235--- PASS: TestLeadEndsOnShutdown (2.79s)1236=== CONT TestReadProxyNarinfo1237=== RUN TestService_RequireScope_OIDC/builder_may_write1238=== PAUSE TestService_RequireScope_OIDC/builder_may_write1239=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1240=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1241=== RUN TestService_RequireScope_OIDC/ops_may_admin1242=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1243=== RUN TestService_RequireScope_OIDC/ops_may_not_write1244=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1245=== RUN TestService_RequireScope_OIDC/reader_may_not_write1246=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1247=== RUN TestService_RequireScope_OIDC/static_token_may_admin1248=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1249=== RUN TestService_RequireScope_OIDC/static_token_may_write1250=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1251=== RUN TestService_RequireScope_OIDC/reader_may_read1252=== PAUSE TestService_RequireScope_OIDC/reader_may_read1253=== RUN TestService_RequireScope_OIDC/writer_implies_read1254=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1255=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1256=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1257=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1258=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1259=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1260=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1261=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1262=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1263=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1264=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1265=== CONT TestEnsureAbortUploadsRule12662026/11/11 23:23:11 INFO lead: given back to the incumbent remote=192.0.2.1:1234 generation=212672026/11/11 23:23:11 INFO lead: acquired remote=192.0.2.1:1234 generation=312682026/11/11 23:23:11 INFO lead: released remote=192.0.2.1:1234 generation=112692026/11/11 23:23:11 INFO lead: acquired remote=192.0.2.1:1234 generation=212702026/11/11 23:23:12 INFO lead: released remote=192.0.2.1:1234 generation=112712026/11/11 23:23:12 INFO lead: acquired remote=192.0.2.1:1234 generation=212722026/11/11 23:23:12 INFO lead: released remote=192.0.2.1:1234 generation=212732026/11/11 23:23:12 INFO lead: acquired remote=192.0.2.1:1234 generation=312742026/11/11 23:23:12 INFO lead: released remote=192.0.2.1:1234 generation=31275--- PASS: TestLeadGenerationGrowsWithEveryGrant (4.01s)1276=== CONT TestReadRedirectNar12772026/11/11 23:23:13 INFO lead: released remote=192.0.2.1:1234 generation=31278--- PASS: TestLeadUnannouncedStandbyYieldsToIncumbent (4.61s)1279=== CONT TestIsValidCachePath1280=== RUN TestIsValidCachePath/narinfo1281=== PAUSE TestIsValidCachePath/narinfo1282=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1283=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1284=== RUN TestIsValidCachePath/nar_zst1285=== PAUSE TestIsValidCachePath/nar_zst1286=== RUN TestIsValidCachePath/nar_xz1287=== PAUSE TestIsValidCachePath/nar_xz1288=== RUN TestIsValidCachePath/nar_bz21289=== PAUSE TestIsValidCachePath/nar_bz21290=== RUN TestIsValidCachePath/nar_uncompressed1291=== PAUSE TestIsValidCachePath/nar_uncompressed1292=== RUN TestIsValidCachePath/ls1293=== PAUSE TestIsValidCachePath/ls1294=== RUN TestIsValidCachePath/log1295=== PAUSE TestIsValidCachePath/log1296=== RUN TestIsValidCachePath/realisation1297=== PAUSE TestIsValidCachePath/realisation1298=== RUN TestIsValidCachePath/nix-cache-info1299=== PAUSE TestIsValidCachePath/nix-cache-info1300=== RUN TestIsValidCachePath/index.html1301=== PAUSE TestIsValidCachePath/index.html1302=== RUN TestIsValidCachePath/traversal_parent1303=== PAUSE TestIsValidCachePath/traversal_parent1304=== RUN TestIsValidCachePath/traversal_in_middle1305=== PAUSE TestIsValidCachePath/traversal_in_middle1306=== RUN TestIsValidCachePath/invalid_char_e1307=== PAUSE TestIsValidCachePath/invalid_char_e1308=== RUN TestIsValidCachePath/invalid_char_u1309=== PAUSE TestIsValidCachePath/invalid_char_u1310=== RUN TestIsValidCachePath/random_path1311=== PAUSE TestIsValidCachePath/random_path1312=== RUN TestIsValidCachePath/empty1313=== PAUSE TestIsValidCachePath/empty1314=== RUN TestIsValidCachePath/leading_slash1315=== PAUSE TestIsValidCachePath/leading_slash1316=== RUN TestIsValidCachePath/wrong_extension1317=== PAUSE TestIsValidCachePath/wrong_extension1318=== RUN TestIsValidCachePath/short_hash1319=== PAUSE TestIsValidCachePath/short_hash1320=== CONT TestPendingCleanupUsesOneCutoff13212026/11/11 23:23:13 WARN Force mode enabled - objects will be deleted immediately without grace period13222026/11/11 23:23:13 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=013232026/11/11 23:23:13 INFO Vacuumed table table=pending_closures13242026/11/11 23:23:13 INFO Vacuumed table table=pending_objects13252026/11/11 23:23:13 INFO Vacuumed table table=multipart_uploads13262026/11/11 23:23:13 INFO Vacuumed table table=closures13272026/11/11 23:23:13 INFO Vacuumed table table=objects1328--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (3.54s)1329=== CONT TestParseSingleRange1330=== RUN TestParseSingleRange/none1331=== PAUSE TestParseSingleRange/none1332=== RUN TestParseSingleRange/unknown_unit1333=== PAUSE TestParseSingleRange/unknown_unit1334=== RUN TestParseSingleRange/multi-range_ignored1335=== PAUSE TestParseSingleRange/multi-range_ignored1336=== RUN TestParseSingleRange/malformed_no_dash1337=== PAUSE TestParseSingleRange/malformed_no_dash1338=== RUN TestParseSingleRange/malformed_both_empty1339=== PAUSE TestParseSingleRange/malformed_both_empty1340=== RUN TestParseSingleRange/malformed_end_before_start1341=== PAUSE TestParseSingleRange/malformed_end_before_start1342=== RUN TestParseSingleRange/closed1343=== PAUSE TestParseSingleRange/closed1344=== RUN TestParseSingleRange/open-ended1345=== PAUSE TestParseSingleRange/open-ended1346=== RUN TestParseSingleRange/end_clamped_to_size1347=== PAUSE TestParseSingleRange/end_clamped_to_size1348=== RUN TestParseSingleRange/suffix1349=== PAUSE TestParseSingleRange/suffix1350=== RUN TestParseSingleRange/suffix_exceeds_size1351=== PAUSE TestParseSingleRange/suffix_exceeds_size1352=== RUN TestParseSingleRange/single_byte1353=== PAUSE TestParseSingleRange/single_byte1354=== RUN TestParseSingleRange/start_past_EOF1355=== PAUSE TestParseSingleRange/start_past_EOF1356=== RUN TestParseSingleRange/start_far_past_EOF1357=== PAUSE TestParseSingleRange/start_far_past_EOF1358=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1359=== NAME TestClientMultipleUploads1360 client_integration_test.go:406: Created store path 0: /build/TestClientMultipleUploads2023686078/001/store/5j4s9359fvd5s66p2gpaxpg4cq7k343w-test-file-0.txt1361--- PASS: TestGCSweepSkipsPendingObjects (3.66s)1362=== CONT TestReadProxyDisabled13632026/11/11 23:23:13 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1364--- PASS: TestService_AuthMiddleware (2.59s)1365=== CONT TestPresentNotReportedWhileGCDeletesClosure1366=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1367=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1368=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1369=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1370=== CONT TestMultipartCleanup13712026/11/11 23:23:13 INFO lead: released remote=192.0.2.1:1234 generation=21372--- PASS: TestLeadElectsOneAndHandsOver (4.97s)1373=== CONT TestReadProxyRootRedirectsToIndexHTML13742026/11/11 23:23:13 INFO Received uploads request method=POST path=/api/pending_closures13752026/11/11 23:23:13 INFO Received uploads request method=POST path=/api/pending_closures13762026/11/11 23:23:13 INFO Installed lifecycle rule aborting incomplete NAR uploads bucket=bucket61 days=21377--- PASS: TestEnsureAbortUploadsRule (2.40s)1378=== CONT TestPresentRefreshesOnlyStaleClosures13792026/11/11 23:23:13 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1380--- PASS: TestReadProxyNarinfo (2.41s)1381=== CONT TestServerTLSConfig1382=== RUN TestServerTLSConfig/no_client_CA1383=== PAUSE TestServerTLSConfig/no_client_CA1384=== RUN TestServerTLSConfig/missing_CA_file1385=== PAUSE TestServerTLSConfig/missing_CA_file1386=== RUN TestServerTLSConfig/not_a_PEM_file1387=== PAUSE TestServerTLSConfig/not_a_PEM_file1388=== CONT TestReadProxyConditionalGet13892026/11/11 23:23:13 INFO Received cleanup request method=DELETE path=/api/pending_closures13902026/11/11 23:23:13 INFO Received uploads request method=POST path=/api/pending_closures1391--- PASS: TestObjectStatsTrigger (2.57s)1392=== CONT TestPresentReportsOnlyClosureRoots1393--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (2.90s)1394=== CONT TestService_NativeMTLS1395--- PASS: TestCacheStatsHandler (2.96s)1396=== CONT TestReadProxyOutlastsServerWriteTimeout13972026/11/11 23:23:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1398--- PASS: TestService_ReadScope_PublicByDefault (2.96s)1399=== CONT TestCreatePin_ReservedPins14002026/11/11 23:23:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43487/oidc1401--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.72s)1402=== CONT TestMetricsCommit1403--- PASS: TestReadRedirectNar (1.38s)1404=== CONT TestReadProxyHead1405=== NAME TestPinProtectsFromGC1406 client_integration_test.go:779: Pinned store path: /build/TestPinProtectsFromGC2850044921/001/store/96w9dwx2shadgi3s68ikl15jhy1bwzq9-pinned-file.txt1407 client_integration_test.go:780: Unpinned store path: /build/TestPinProtectsFromGC2850044921/001/store/jk8b2jww89vvkvk0bhhrrvmcm6xzbb3l-unpinned-file.txt1408=== NAME TestClientIntegration1409 client_integration_test.go:292: Created store path: /build/TestClientIntegration3842570989/002/store/gs51vd0cvqslqz6ih060dss37n6v41vg-test-file.txt1410--- PASS: TestConnectWaitsForAPeerMigration (5.40s)1411=== CONT TestOrphanedObjectsGCStressTest1412=== NAME TestClientMultipleUploads1413 client_integration_test.go:406: Created store path 1: /build/TestClientMultipleUploads2023686078/001/store/5cs07f0c6d1dmqyha4zpjmghn0dszrzr-test-file-1.txt1414=== NAME TestClientWithDependencies1415 client_integration_test.go:661: Built derivation: /build/TestClientWithDependencies2669082684/001/store/bijc9plvv5r1p4wa9qzvnqkqxf49kljh-test-script14162026/11/11 23:23:14 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14172026/11/11 23:23:14 WARN Refused reserved pin name=worker-x86_64-linux14182026/11/11 23:23:14 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1419 client_integration_test.go:663: Found 1 dependencies (including self)14202026/11/11 23:23:14 INFO Received create pin request method=POST path=/api/pins/my-app14212026/11/11 23:23:14 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1422=== NAME TestClientMultipleUploads1423 client_integration_test.go:406: Created store path 2: /build/TestClientMultipleUploads2023686078/001/store/nnka53frxghclyz9s7cvvvwf0svvlc62-test-file-2.txt1424--- PASS: TestCreatePin_ReservedPins (0.34s)1425=== CONT TestReadProxyInvalidPath14262026/11/11 23:23:14 WARN mTLS auth: subject not in bound subjects subject="CN=reader"14272026/11/11 23:23:14 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1428--- PASS: TestService_NativeMTLS (0.44s)1429=== CONT TestMetricsInventory1430=== NAME TestClientCADerivations1431 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations865681996/001/store/py7cvv66mwwbmpzfd6s1z5bd9vrm3i8f-ca-test1432--- PASS: TestReadProxyConditionalGet (0.55s)1433=== CONT TestOrphanedObjectsGC14342026/11/11 23:23:14 INFO Received push request method=POST path=/api/pushes14352026/11/11 23:23:14 INFO Received complete push request method=POST path=/api/pushes/1/complete1436--- PASS: TestPresentReportsOnlyClosureRoots (0.57s)1437=== CONT TestReadProxy4041438--- PASS: TestReadProxyDisabled (0.81s)1439=== CONT TestNARDeduplicationMetadataUploadBug1440--- PASS: TestPresentRefreshesOnlyStaleClosures (0.67s)1441=== CONT TestReadProxyNarStreaming1442--- PASS: TestReadProxyHead (0.43s)1443=== CONT TestObjectStatsUpdatedOncePerCommit14442026/11/11 23:23:14 INFO Received uploads request method=POST path=/api/pending_closures14452026/11/11 23:23:14 INFO Completed push id=1 objects=4 duration=179.32895ms14462026/11/11 23:23:14 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1447=== NAME TestClientCADerivations1448 client_ca_test.go:139: Found 1 dependencies (including self)14492026/11/11 23:23:14 INFO Completed upload id=2 objects=2 duration=2.471664ms1450--- PASS: TestMetricsCommit (0.55s)1451=== CONT TestCreatePendingClosureRejectsOversizedNAR14522026/11/11 23:23:14 INFO Received uploads request method=POST path=/api/pending_closures1453--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1454=== CONT TestReadProxyContentNegotiation1455--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (1.12s)1456=== CONT TestCacheConfigHandlerMaxNarSize1457--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1458=== CONT TestGCTaskStore_GetReturnsLatest1459--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1460=== CONT TestGCTaskStore_Fail1461--- PASS: TestGCTaskStore_Fail (0.00s)1462=== CONT TestGCTaskStore_PhaseUpdates1463--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1464=== CONT TestGCTaskStore_CompletedAllowsNewTask1465--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1466=== CONT TestGenerateLandingPage1467--- PASS: TestGenerateLandingPage (0.01s)1468=== CONT TestGCTaskStore_GetEmpty1469--- PASS: TestGCTaskStore_GetEmpty (0.00s)1470=== CONT TestService_healthCheckHandler14712026/11/11 23:23:14 INFO Received uploads request method=POST path=/api/pending_closures14722026/11/11 23:23:14 INFO Received push request method=POST path=/api/pushes14732026/11/11 23:23:14 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14742026/11/11 23:23:14 INFO Uploading gs51vd0cvqslqz6ih060dss37n6v41vg-test-file.txt (152B)14752026/11/11 23:23:14 INFO Received push request method=POST path=/api/pushes14762026/11/11 23:23:14 INFO Received uploads request method=POST path=/api/pending_closures14772026/11/11 23:23:14 WARN Failed to register uploaded object key=gs51vd0cvqslqz6ih060dss37n6v41vg.ls error="server returned 404: 404 page not found\n"14782026/11/11 23:23:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14792026/11/11 23:23:14 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"14802026/11/11 23:23:14 INFO Signed narinfos id=1 count=114812026/11/11 23:23:14 INFO Uploading 1 narinfos14822026/11/11 23:23:14 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14832026/11/11 23:23:14 INFO Uploading 39j51acn4izb9dlrk899qy2igw7jk0g5-shared-dep (136B)14842026/11/11 23:23:14 INFO Uploading qaw53618ndwk6bihnsfmk0953pqi7chk-b (216B)14852026/11/11 23:23:14 INFO Received uploads request method=POST path=/api/pending_closures14862026/11/11 23:23:14 INFO Received complete push request method=POST path=/api/pushes/1/complete14872026/11/11 23:23:14 WARN Failed to register uploaded object key=gs51vd0cvqslqz6ih060dss37n6v41vg.narinfo error="server returned 404: 404 page not found\n"14882026/11/11 23:23:14 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14892026/11/11 23:23:14 INFO Uploading s1inwly175yxdr8iq9c9a1zq1zw7c5w5-b (216B)14902026/11/11 23:23:14 INFO Uploading 6h5igi1j7kj5fh85j3f4vc6dkrffbg84-shared-dep (136B)14912026/11/11 23:23:14 WARN Failed to register uploaded object key=kw2cnc1pnffrar1cbzbb5rpvzscz8nhs.ls error="server returned 404: 404 page not found\n"14922026/11/11 23:23:14 WARN Failed to register uploaded object key=nar/0myx3c1cl0kriwqf58wb0v12m78189zwvb19yajfbjvynyp1phmv.nar.zst error="server returned 404: 404 page not found\n"14932026/11/11 23:23:14 WARN Failed to register uploaded object key=39j51acn4izb9dlrk899qy2igw7jk0g5.ls error="server returned 404: 404 page not found\n"14942026/11/11 23:23:14 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14952026/11/11 23:23:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14962026/11/11 23:23:14 WARN Failed to register uploaded object key=qaw53618ndwk6bihnsfmk0953pqi7chk.ls error="server returned 404: 404 page not found\n"14972026/11/11 23:23:14 INFO Signed narinfos id=1 count=314982026/11/11 23:23:14 INFO Uploading 3 narinfos14992026/11/11 23:23:14 WARN Failed to register uploaded object key=0dfqyfcnyy7h5rcrsl5k5jcsifj4y56f.ls error="server returned 404: 404 page not found\n"1500--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.04s)1501=== CONT TestService_readinessHandler15022026/11/11 23:23:14 WARN Failed to register uploaded object key=nar/1g43p4sijwlv0qnygrpb7ighdllb54drgvwdhid3y504487yzlfk.nar.zst error="server returned 404: 404 page not found\n"15032026/11/11 23:23:14 WARN Failed to register uploaded object key=s1inwly175yxdr8iq9c9a1zq1zw7c5w5.ls error="server returned 404: 404 page not found\n"15042026/11/11 23:23:14 INFO Completed push id=1 objects=3 duration=9.674612ms15052026/11/11 23:23:14 WARN Failed to register uploaded object key=6h5igi1j7kj5fh85j3f4vc6dkrffbg84.ls error="server returned 404: 404 page not found\n"15062026/11/11 23:23:14 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15072026/11/11 23:23:14 INFO Upload complete. (182ms)15082026/11/11 23:23:14 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15092026/11/11 23:23:14 INFO Signed narinfos id=2 count=215102026/11/11 23:23:14 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15112026/11/11 23:23:14 WARN Failed to register uploaded object key=qaw53618ndwk6bihnsfmk0953pqi7chk.narinfo error="server returned 404: 404 page not found\n"15122026/11/11 23:23:14 WARN Failed to register uploaded object key=kw2cnc1pnffrar1cbzbb5rpvzscz8nhs.narinfo error="server returned 404: 404 page not found\n"15132026/11/11 23:23:14 INFO Received complete push request method=POST path=/api/pushes/1/complete15142026/11/11 23:23:14 INFO Signed narinfos id=1 count=215152026/11/11 23:23:14 WARN Failed to register uploaded object key=39j51acn4izb9dlrk899qy2igw7jk0g5.narinfo error="server returned 404: 404 page not found\n"15162026/11/11 23:23:14 INFO Uploading 4 narinfos15172026/11/11 23:23:14 WARN Failed to register uploaded object key=0dfqyfcnyy7h5rcrsl5k5jcsifj4y56f.narinfo error="server returned 404: 404 page not found\n"15182026/11/11 23:23:14 WARN Failed to register uploaded object key=s1inwly175yxdr8iq9c9a1zq1zw7c5w5.narinfo error="server returned 404: 404 page not found\n"15192026/11/11 23:23:14 WARN Failed to register uploaded object key=6h5igi1j7kj5fh85j3f4vc6dkrffbg84.narinfo error="server returned 404: 404 page not found\n"15202026/11/11 23:23:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15212026/11/11 23:23:14 WARN Failed to register uploaded object key=6h5igi1j7kj5fh85j3f4vc6dkrffbg84.narinfo error="server returned 404: 404 page not found\n"15222026/11/11 23:23:14 INFO Completed push id=1 objects=8 duration=18.009612ms15232026/11/11 23:23:14 INFO Upload complete. (205ms)1524=== NAME TestClientPushesUseOnePush1525 client_pushes_test.go:97: Retrieved narinfo from S3:1526 StorePath: /build/TestClientPushesUseOnePush3712678541/001/store/39j51acn4izb9dlrk899qy2igw7jk0g5-shared-dep1527 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1528 Compression: zstd1529 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821530 NarSize: 1361531 References: 1532 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1533 client_pushes_test.go:97: Retrieved narinfo from S3:1534 StorePath: /build/TestClientPushesUseOnePush3712678541/001/store/kw2cnc1pnffrar1cbzbb5rpvzscz8nhs-a1535 URL: nar/0myx3c1cl0kriwqf58wb0v12m78189zwvb19yajfbjvynyp1phmv.nar.zst1536 Compression: zstd1537 NarHash: sha256:0myx3c1cl0kriwqf58wb0v12m78189zwvb19yajfbjvynyp1phmv1538 NarSize: 2161539 References: /build/TestClientPushesUseOnePush3712678541/001/store/39j51acn4izb9dlrk899qy2igw7jk0g5-shared-dep1540 CA: text:sha256:0dj2km6xcpy9fasp07lmsm47p2zqyfszgps7mh4as0c20niqy5sd1541 client_pushes_test.go:97: Retrieved narinfo from S3:1542 StorePath: /build/TestClientPushesUseOnePush3712678541/001/store/qaw53618ndwk6bihnsfmk0953pqi7chk-b15432026/11/11 23:23:14 INFO Completed upload id=1 objects=6 duration=19.168602ms1544 URL: nar/0myx3c1cl0kriwqf58wb0v12m78189zwvb19yajfbjvynyp1phmv.nar.zst1545 Compression: zstd1546 NarHash: sha256:0myx3c1cl0kriwqf58wb0v12m78189zwvb19yajfbjvynyp1phmv1547 NarSize: 2161548 References: /build/TestClientPushesUseOnePush3712678541/001/store/39j51acn4izb9dlrk899qy2igw7jk0g5-shared-dep1549 CA: text:sha256:0dj2km6xcpy9fasp07lmsm47p2zqyfszgps7mh4as0c20niqy5sd15502026/11/11 23:23:14 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1551--- PASS: TestClientPushesUseOnePush (3.92s)1552=== CONT TestGCTaskStore_ConflictDifferentParams1553--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1554=== CONT TestGracefulShutdownDrainsInflight15552026/11/11 23:23:14 INFO Completed upload id=2 objects=6 duration=6.123818ms15562026/11/11 23:23:14 INFO Upload complete. (230ms)15572026/11/11 23:23:14 INFO Starting HTTP server address=127.0.0.1:4459115582026/11/11 23:23:14 INFO Shutdown signal received, draining in-flight requests timeout=10s1559=== NAME TestClientFallsBackToClosures1560 client_pushes_test.go:112: Retrieved narinfo from S3:1561 StorePath: /build/TestClientFallsBackToClosures2604024022/001/store/6h5igi1j7kj5fh85j3f4vc6dkrffbg84-shared-dep1562 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1563 Compression: zstd1564 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821565 NarSize: 1361566 References: 1567 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1568 client_pushes_test.go:112: Retrieved narinfo from S3:1569 StorePath: /build/TestClientFallsBackToClosures2604024022/001/store/0dfqyfcnyy7h5rcrsl5k5jcsifj4y56f-a1570 URL: nar/1g43p4sijwlv0qnygrpb7ighdllb54drgvwdhid3y504487yzlfk.nar.zst1571 Compression: zstd1572 NarHash: sha256:1g43p4sijwlv0qnygrpb7ighdllb54drgvwdhid3y504487yzlfk1573 NarSize: 2161574 References: /build/TestClientFallsBackToClosures2604024022/001/store/6h5igi1j7kj5fh85j3f4vc6dkrffbg84-shared-dep1575 CA: text:sha256:1r1mdcx41z58ks6k4waa01bn9yn4vsnci6pjp221ck9wcnwsqww51576 client_pushes_test.go:112: Retrieved narinfo from S3:1577 StorePath: /build/TestClientFallsBackToClosures2604024022/001/store/s1inwly175yxdr8iq9c9a1zq1zw7c5w5-b1578 URL: nar/1g43p4sijwlv0qnygrpb7ighdllb54drgvwdhid3y504487yzlfk.nar.zst1579 Compression: zstd1580 NarHash: sha256:1g43p4sijwlv0qnygrpb7ighdllb54drgvwdhid3y504487yzlfk1581 NarSize: 2161582 References: /build/TestClientFallsBackToClosures2604024022/001/store/6h5igi1j7kj5fh85j3f4vc6dkrffbg84-shared-dep1583 CA: text:sha256:1r1mdcx41z58ks6k4waa01bn9yn4vsnci6pjp221ck9wcnwsqww515842026/11/11 23:23:14 INFO Received cleanup request method=DELETE path=/api/pending_closures1585--- PASS: TestClientFallsBackToClosures (4.47s)1586=== CONT TestGCEndsOnShutdown/before_the_run15872026/11/11 23:23:14 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket81/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""15882026/11/11 23:23:14 INFO Aborted multipart uploads count=0 kept=115892026/11/11 23:23:14 INFO Received cleanup request method=DELETE path=/api/pending_closures15902026/11/11 23:23:14 INFO Aborted multipart uploads count=1 kept=01591--- PASS: TestMultipartCleanup (1.15s)1592=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1593--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1594=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete15952026/11/11 23:23:14 INFO Received push request method=POST path=/api/pushes15962026/11/11 23:23:14 INFO Received push request method=POST path=/api/pushes15972026/11/11 23:23:14 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)15982026/11/11 23:23:14 INFO Uploading 0x149r5qscw8fk769xhw2i56r6aq6bjb-top (224B)15992026/11/11 23:23:14 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16002026/11/11 23:23:14 INFO Uploading 96w9dwx2shadgi3s68ikl15jhy1bwzq9-pinned-file.txt (128B)16012026/11/11 23:23:14 INFO Uploading 89hcy14c3vay6782y85w9mjykf96lxs0-shared-dep (136B)16022026/11/11 23:23:14 WARN Failed to register uploaded object key=96w9dwx2shadgi3s68ikl15jhy1bwzq9.ls error="server returned 404: 404 page not found\n"1603--- PASS: TestReadProxyInvalidPath (0.63s)1604=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed16052026/11/11 23:23:14 WARN Failed to register uploaded object key=0x149r5qscw8fk769xhw2i56r6aq6bjb.ls error="server returned 404: 404 page not found\n"16062026/11/11 23:23:14 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"16072026/11/11 23:23:14 WARN Failed to register uploaded object key=nar/1fr37xxb02wnxrwfs68gfn014zi7zgnp63az4h111fbl9b734ks3.nar.zst error="server returned 404: 404 page not found\n"16082026/11/11 23:23:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16092026/11/11 23:23:14 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16102026/11/11 23:23:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16112026/11/11 23:23:14 WARN Failed to register uploaded object key=89hcy14c3vay6782y85w9mjykf96lxs0.ls error="server returned 404: 404 page not found\n"16122026/11/11 23:23:14 INFO Signed narinfos id=1 count=116132026/11/11 23:23:14 INFO Signed narinfos id=1 count=216142026/11/11 23:23:14 INFO Uploading 1 narinfos16152026/11/11 23:23:14 INFO Uploading 2 narinfos16162026/11/11 23:23:14 WARN Failed to register uploaded object key=96w9dwx2shadgi3s68ikl15jhy1bwzq9.narinfo error="server returned 404: 404 page not found\n"16172026/11/11 23:23:14 WARN Failed to register uploaded object key=0x149r5qscw8fk769xhw2i56r6aq6bjb.narinfo error="server returned 404: 404 page not found\n"16182026/11/11 23:23:14 INFO Received complete push request method=POST path=/api/pushes/1/complete16192026/11/11 23:23:14 INFO Received complete push request method=POST path=/api/pushes/1/complete16202026/11/11 23:23:14 WARN Failed to register uploaded object key=89hcy14c3vay6782y85w9mjykf96lxs0.narinfo error="server returned 404: 404 page not found\n"16212026/11/11 23:23:14 INFO Completed push id=1 objects=3 duration=9.810173ms16222026/11/11 23:23:14 INFO Upload complete. (386ms)16232026/11/11 23:23:14 INFO Completed push id=1 objects=6 duration=10.899444ms16242026/11/11 23:23:14 INFO Upload complete. (384ms)1625=== NAME TestClientSharedPathCommittedMidPush1626 client_integration_test.go:728: Retrieved narinfo from S3:1627 StorePath: /build/TestClientSharedPathCommittedMidPush2851927798/001/store/89hcy14c3vay6782y85w9mjykf96lxs0-shared-dep1628 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1629 Compression: zstd1630 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821631 NarSize: 1361632 References: 1633 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1634 client_integration_test.go:728: Retrieved narinfo from S3:1635 StorePath: /build/TestClientSharedPathCommittedMidPush2851927798/001/store/0x149r5qscw8fk769xhw2i56r6aq6bjb-top1636 URL: nar/1fr37xxb02wnxrwfs68gfn014zi7zgnp63az4h111fbl9b734ks3.nar.zst1637 Compression: zstd1638 NarHash: sha256:1fr37xxb02wnxrwfs68gfn014zi7zgnp63az4h111fbl9b734ks31639 NarSize: 2241640 References: /build/TestClientSharedPathCommittedMidPush2851927798/001/store/89hcy14c3vay6782y85w9mjykf96lxs0-shared-dep1641 CA: text:sha256:0qrz8m642bfkzzb8i2823ddz32vy6212234jgjbavriac17h0j8w1642--- PASS: TestClientSharedPathCommittedMidPush (4.59s)1643=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed1644--- PASS: TestReadProxy404 (0.55s)1645=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed1646--- PASS: TestMetricsInventory (0.71s)1647=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost1648--- PASS: TestReadProxyNarStreaming (0.60s)1649=== CONT TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed1650--- PASS: TestObjectStatsUpdatedOncePerCommit (0.58s)1651=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16522026/11/11 23:23:15 INFO Received uploads request method=POST path=/16532026/11/11 23:23:15 WARN readiness check failed error="closed pool"1654--- PASS: TestService_readinessHandler (0.37s)1655=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16562026/11/11 23:23:15 INFO Received request for more parts method=POST path=/1657--- PASS: TestService_healthCheckHandler (0.46s)1658=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16592026/11/11 23:23:15 INFO Received complete multipart upload request method=POST path=/1660--- PASS: TestReadProxyContentNegotiation (0.59s)1661=== CONT TestPush_RejectsBadRequests/bad_root16622026/11/11 23:23:15 INFO Received push request method=POST path=/api/pushes1663=== CONT TestPush_RejectsBadRequests/no_roots16642026/11/11 23:23:15 INFO Received push request method=POST path=/api/pushes1665=== CONT TestPush_RejectsBadRequests/no_objects16662026/11/11 23:23:15 INFO Received push request method=POST path=/api/pushes1667=== CONT TestPush_RejectsBadRequests/root_not_in_objects16682026/11/11 23:23:15 INFO Received push request method=POST path=/api/pushes1669=== CONT TestResolveDBConnectionString/flag_wins1670--- PASS: TestPush_RejectsBadRequests (2.60s)1671 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1672 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1673 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1674 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1675=== CONT TestResolveDBConnectionString/missing_file_is_an_error1676=== CONT TestResolveDBConnectionString/file_when_flag_empty1677=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1678=== CONT TestResolveDBConnectionString/nothing_configured1679=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1680--- PASS: TestResolveDBConnectionString (0.00s)1681 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1682 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1683 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1684 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1685 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1686=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1687=== CONT TestClientErrorHandling/InvalidStorePath16882026/11/11 23:23:15 INFO All 1 paths already cached1689=== NAME TestClientIntegration1690 client_integration_test.go:318: Retrieved narinfo from S3:1691 StorePath: /build/TestClientIntegration3842570989/002/store/gs51vd0cvqslqz6ih060dss37n6v41vg-test-file.txt1692 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1693 Compression: zstd1694 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11695 NarSize: 1521696 References: 1697 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11698 client_integration_test.go:319: Retrieved .ls file from S3 (compressed size: 77 bytes)1699 client_integration_test.go:319: Decompressed .ls content (64 bytes):1700 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1701=== NAME TestNARDeduplicationMetadataUploadBug1702 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2690816282/001/store/xa4g42md7jb13qmq88i366qbwrndnrxb-file1.txt17032026/11/11 23:23:15 INFO Received uploads request method=POST path=/api/pending_closures17042026/11/11 23:23:15 INFO Received uploads request method=POST path=/api/pending_closures17052026/11/11 23:23:15 INFO Received uploads request method=POST path=/api/pending_closures17062026/11/11 23:23:15 INFO Received uploads request method=POST path=/api/pending_closures17072026/11/11 23:23:15 INFO Received uploads request method=POST path=/api/pending_closures17082026/11/11 23:23:16 INFO Received push request method=POST path=/api/pushes17092026/11/11 23:23:16 INFO Received push request method=POST path=/api/pushes17102026/11/11 23:23:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17112026/11/11 23:23:16 INFO Uploading bijc9plvv5r1p4wa9qzvnqkqxf49kljh-test-script (136B)17122026/11/11 23:23:16 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)17132026/11/11 23:23:16 INFO Uploading 5cs07f0c6d1dmqyha4zpjmghn0dszrzr-test-file-1.txt (160B)17142026/11/11 23:23:16 INFO Uploading 5j4s9359fvd5s66p2gpaxpg4cq7k343w-test-file-0.txt (160B)17152026/11/11 23:23:16 INFO Uploading nnka53frxghclyz9s7cvvvwf0svvlc62-test-file-2.txt (160B)17162026/11/11 23:23:16 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"17172026/11/11 23:23:16 WARN Failed to register uploaded object key=5j4s9359fvd5s66p2gpaxpg4cq7k343w.ls error="server returned 404: 404 page not found\n"17182026/11/11 23:23:16 WARN Failed to register uploaded object key=bijc9plvv5r1p4wa9qzvnqkqxf49kljh.ls error="server returned 404: 404 page not found\n"17192026/11/11 23:23:16 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"17202026/11/11 23:23:16 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"17212026/11/11 23:23:16 WARN Failed to register uploaded object key=nnka53frxghclyz9s7cvvvwf0svvlc62.ls error="server returned 404: 404 page not found\n"17222026/11/11 23:23:16 WARN Failed to register uploaded object key=5cs07f0c6d1dmqyha4zpjmghn0dszrzr.ls error="server returned 404: 404 page not found\n"17232026/11/11 23:23:16 WARN Failed to register uploaded object key=log/n04kb3v0pynwf9crwvqyqg8hl434gjk2-test-script.drv error="server returned 404: 404 page not found\n"17242026/11/11 23:23:16 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"17252026/11/11 23:23:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17262026/11/11 23:23:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17272026/11/11 23:23:16 INFO Signed narinfos id=1 count=117282026/11/11 23:23:16 INFO Uploading 1 narinfos17292026/11/11 23:23:16 INFO Signed narinfos id=1 count=317302026/11/11 23:23:16 INFO Uploading 3 narinfos17312026/11/11 23:23:16 INFO Received complete push request method=POST path=/api/pushes/1/complete17322026/11/11 23:23:16 WARN Failed to register uploaded object key=bijc9plvv5r1p4wa9qzvnqkqxf49kljh.narinfo error="server returned 404: 404 page not found\n"17332026/11/11 23:23:16 WARN Failed to register uploaded object key=nnka53frxghclyz9s7cvvvwf0svvlc62.narinfo error="server returned 404: 404 page not found\n"17342026/11/11 23:23:16 WARN Failed to register uploaded object key=5j4s9359fvd5s66p2gpaxpg4cq7k343w.narinfo error="server returned 404: 404 page not found\n"17352026/11/11 23:23:16 INFO Received complete push request method=POST path=/api/pushes/1/complete17362026/11/11 23:23:16 WARN Failed to register uploaded object key=5cs07f0c6d1dmqyha4zpjmghn0dszrzr.narinfo error="server returned 404: 404 page not found\n"17372026/11/11 23:23:16 INFO Completed push id=1 objects=4 duration=14.365797ms17382026/11/11 23:23:16 INFO Upload complete. (1.812s)17392026/11/11 23:23:16 INFO Completed push id=1 objects=9 duration=15.73107ms17402026/11/11 23:23:16 INFO Upload complete. (1.931s)1741=== NAME TestClientMultipleUploads1742 client_integration_test.go:417: Uploaded 3 paths in 2.189847818s1743=== NAME TestClientWithDependencies1744 client_integration_test.go:665: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2669082684/001/store) requires matching store prefix1745=== CONT TestClientErrorHandling/ServerNotAvailable1746--- PASS: TestClientWithDependencies (6.11s)1747--- PASS: TestClientMultipleUploads (5.61s)1748=== CONT TestClientErrorHandling/InvalidAuthToken17492026/11/11 23:23:16 INFO Received push request method=POST path=/api/pushes17502026/11/11 23:23:16 INFO Received push request method=POST path=/api/pushes17512026/11/11 23:23:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1752=== NAME TestOrphanedObjectsGC1753 orphaned_objects_gc_test.go:287: GC Test Summary:17542026/11/11 23:23:16 INFO Uploading xa4g42md7jb13qmq88i366qbwrndnrxb-file1.txt (160B)1755 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1756 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1757 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1758 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1759 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1760--- PASS: TestOrphanedObjectsGC (2.20s)1761=== CONT TestPendingClosureWriteTimeout/empty1762=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline17632026/11/11 23:23:16 INFO Object in database but missing from S3 key=gs51vd0cvqslqz6ih060dss37n6v41vg.ls17642026/11/11 23:23:16 WARN Found objects in DB but missing from S3, will re-upload count=117652026/11/11 23:23:16 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17662026/11/11 23:23:16 WARN Failed to register uploaded object key=xa4g42md7jb13qmq88i366qbwrndnrxb.ls error="server returned 404: 404 page not found\n"17672026/11/11 23:23:16 INFO Received complete push request method=POST path=/api/pushes/2/complete17682026/11/11 23:23:16 WARN Failed to register uploaded object key=gs51vd0cvqslqz6ih060dss37n6v41vg.ls error="server returned 404: 404 page not found\n"17692026/11/11 23:23:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17702026/11/11 23:23:16 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"17712026/11/11 23:23:16 INFO Signed narinfos id=1 count=117722026/11/11 23:23:16 INFO Uploading 1 narinfos17732026/11/11 23:23:16 INFO Completed push id=2 objects=3 duration=8.509421ms17742026/11/11 23:23:16 INFO Upload complete. (142ms)1775=== NAME TestClientIntegration1776 client_integration_test.go:336: Retrieved .ls file from S3 (compressed size: 62 bytes)1777 client_integration_test.go:336: Decompressed .ls content (49 bytes):1778 {"version":1,"root":{"type":"regular","size":39}}17792026/11/11 23:23:16 INFO Received complete push request method=POST path=/api/pushes/1/complete17802026/11/11 23:23:16 WARN Failed to register uploaded object key=xa4g42md7jb13qmq88i366qbwrndnrxb.narinfo error="server returned 404: 404 page not found\n"17812026/11/11 23:23:16 INFO Received uploads request method=POST path=/api/pending_closures17822026/11/11 23:23:16 INFO Completed push id=1 objects=3 duration=9.885794ms17832026/11/11 23:23:16 INFO Upload complete. (156ms)1784=== NAME TestNARDeduplicationMetadataUploadBug1785 metadata_upload_test.go:54: Retrieved narinfo from S3:1786 StorePath: /build/TestNARDeduplicationMetadataUploadBug2690816282/001/store/xa4g42md7jb13qmq88i366qbwrndnrxb-file1.txt1787 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1788 Compression: zstd1789 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1790 NarSize: 1601791 References: 1792 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf17932026/11/11 23:23:16 INFO Aborted multipart uploads count=0 kept=01794--- PASS: TestUploadHandlersRejectOversizedBody (0.22s)1795 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)1796 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)1797 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.51s)1798=== CONT TestPendingClosureWriteTimeout/670k_objects1799=== CONT TestPendingClosureWriteTimeout/400_objects1800=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18012026/11/11 23:23:16 INFO Received uploads request method=POST path=/1802=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18032026/11/11 23:23:16 INFO Received request for more parts method=POST path=/1804=== NAME TestNARDeduplicationMetadataUploadBug1805 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1806 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1807 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1808=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18092026/11/11 23:23:16 INFO Received complete multipart upload request method=POST path=/1810=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18112026/11/11 23:23:16 INFO Received uploads request method=POST path=/1812--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1813 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1814 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1815 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1816 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1817=== CONT TestIsValidUploadKey/narinfo1818=== CONT TestIsValidUploadKey/unknown_type1819=== CONT TestIsValidUploadKey/empty_key1820=== CONT TestIsValidUploadKey/absolute1821=== CONT TestIsValidUploadKey/traversal_nar1822=== CONT TestIsValidUploadKey/traversal1823=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1824=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1825=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1826=== CONT TestIsValidUploadKey/index.html1827=== CONT TestIsValidUploadKey/nix-cache-info1828=== CONT TestIsValidUploadKey/realisation_plus_in_output1829=== CONT TestIsValidUploadKey/realisation1830=== CONT TestIsValidUploadKey/build_log_equals1831=== CONT TestIsValidUploadKey/listing1832=== CONT TestIsValidUploadKey/nar_plain1833=== CONT TestIsValidUploadKey/nar_xz1834=== CONT TestIsValidUploadKey/nar_zst1835=== CONT TestIsValidUploadKey/build_log_plus_in_name1836=== CONT TestIsValidUploadKey/build_log_question_mark1837=== CONT TestIsValidUploadKey/build_log_home-manager_file1838=== CONT TestIsValidUploadKey/build_log1839--- PASS: TestIsValidUploadKey (0.00s)1840 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1841 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1842 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1843 --- PASS: TestIsValidUploadKey/absolute (0.00s)1844 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1845 --- PASS: TestIsValidUploadKey/traversal (0.00s)1846 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1847 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1848 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1849 --- PASS: TestIsValidUploadKey/index.html (0.00s)1850 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1851 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1852 --- PASS: TestIsValidUploadKey/realisation (0.00s)1853 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1854 --- PASS: TestIsValidUploadKey/listing (0.00s)1855 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1856 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1857 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1858 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1859 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1860 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1861 --- PASS: TestIsValidUploadKey/build_log (0.00s)1862=== CONT TestCacheConfigHandler/full_config,_no_issuer1863=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1864=== CONT TestCacheConfigHandler/no_signing_keys1865=== CONT TestCacheConfigHandler/no_cache_url_configured1866--- PASS: TestCacheConfigHandler (0.00s)1867 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1868 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1869 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1870 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1871=== CONT TestProxyWriteTimeout/narinfo1872=== CONT TestProxyWriteTimeout/10_GiB_nar1873=== CONT TestProxyWriteTimeout/unknown_size1874=== CONT TestProxyWriteTimeout/1_GiB_nar1875--- PASS: TestProxyWriteTimeout (0.00s)1876 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1877 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1878 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1879 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1880=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token18812026/11/11 23:23:16 INFO Received push request method=POST path=/api/pushes18822026/11/11 23:23:16 INFO Received push request method=POST path=/api/pushes18832026/11/11 23:23:16 WARN Force mode enabled - objects will be deleted immediately without grace period18842026/11/11 23:23:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18852026/11/11 23:23:16 INFO Uploading jk8b2jww89vvkvk0bhhrrvmcm6xzbb3l-unpinned-file.txt (128B)1886=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18872026/11/11 23:23:16 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1888=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18892026/11/11 23:23:16 WARN Authentication failed token_preview=eyJhbGciOi...NuDaI1occQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1890=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1891=== CONT TestService_RequireScope_OIDC/builder_may_write1892--- PASS: TestService_AuthMiddleware_OIDC (1.26s)1893 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)1894 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1895 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1896 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)18972026/11/11 23:23:16 INFO Received uploads request method=POST path=/api/pending_closures1898=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1899=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19002026/11/11 23:23:16 WARN Authentication failed token_preview=wrong token_length=5 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1901=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1902=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1903=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1904=== CONT TestService_RequireScope_OIDC/writer_implies_read1905=== CONT TestService_RequireScope_OIDC/reader_may_read1906=== CONT TestService_RequireScope_OIDC/static_token_may_write1907=== CONT TestService_RequireScope_OIDC/static_token_may_admin1908=== CONT TestService_RequireScope_OIDC/reader_may_not_write1909=== CONT TestService_RequireScope_OIDC/ops_may_not_write1910=== CONT TestService_RequireScope_OIDC/ops_may_admin1911=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1912=== CONT TestIsValidCachePath/narinfo1913=== CONT TestIsValidCachePath/index.html1914=== CONT TestIsValidCachePath/short_hash1915=== CONT TestIsValidCachePath/wrong_extension1916=== CONT TestIsValidCachePath/leading_slash1917=== CONT TestIsValidCachePath/empty1918=== CONT TestIsValidCachePath/random_path1919=== CONT TestIsValidCachePath/nar_uncompressed1920=== CONT TestIsValidCachePath/invalid_char_u1921=== CONT TestIsValidCachePath/nix-cache-info1922=== CONT TestIsValidCachePath/invalid_char_e1923=== CONT TestIsValidCachePath/traversal_in_middle1924=== CONT TestIsValidCachePath/realisation1925=== CONT TestIsValidCachePath/log1926=== CONT TestIsValidCachePath/traversal_parent1927=== CONT TestIsValidCachePath/ls1928=== CONT TestIsValidCachePath/nar_xz1929=== CONT TestIsValidCachePath/nar_bz21930=== CONT TestIsValidCachePath/nar_zst1931=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1932=== CONT TestParseSingleRange/none1933=== CONT TestParseSingleRange/open-ended1934=== CONT TestParseSingleRange/malformed_both_empty1935=== CONT TestParseSingleRange/start_far_past_EOF1936=== CONT TestParseSingleRange/start_past_EOF1937=== CONT TestParseSingleRange/closed1938=== CONT TestParseSingleRange/single_byte1939--- PASS: TestService_RequireScope_OIDC (0.92s)1940 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1941 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1942 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1943 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1944 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1945 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1946 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1947 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1948 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1949 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1950 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1951 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1952 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1953 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1954=== CONT TestParseSingleRange/malformed_end_before_start1955=== CONT TestParseSingleRange/suffix_exceeds_size1956=== CONT TestParseSingleRange/suffix1957=== CONT TestParseSingleRange/multi-range_ignored1958=== CONT TestParseSingleRange/end_clamped_to_size1959--- PASS: TestIsValidCachePath (0.00s)1960 --- PASS: TestIsValidCachePath/narinfo (0.00s)1961 --- PASS: TestIsValidCachePath/index.html (0.00s)1962 --- PASS: TestIsValidCachePath/short_hash (0.00s)1963 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1964 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1965 --- PASS: TestIsValidCachePath/empty (0.00s)1966 --- PASS: TestIsValidCachePath/random_path (0.00s)1967 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1968 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1969 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1970 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1971 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1972 --- PASS: TestIsValidCachePath/realisation (0.00s)1973 --- PASS: TestIsValidCachePath/log (0.00s)1974 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1975 --- PASS: TestIsValidCachePath/ls (0.00s)1976 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1977 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1978 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1979 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1980=== CONT TestParseSingleRange/malformed_no_dash1981=== CONT TestParseSingleRange/unknown_unit1982--- PASS: TestParseSingleRange (0.00s)1983 --- PASS: TestParseSingleRange/none (0.00s)1984 --- PASS: TestParseSingleRange/open-ended (0.00s)1985 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1986 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1987 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1988 --- PASS: TestParseSingleRange/closed (0.00s)1989 --- PASS: TestParseSingleRange/single_byte (0.00s)1990 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1991 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1992 --- PASS: TestParseSingleRange/suffix (0.00s)1993 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1994 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1995 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1996 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1997=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale19982026/11/11 23:23:16 WARN Failed to register uploaded object key=jk8b2jww89vvkvk0bhhrrvmcm6xzbb3l.ls error="server returned 404: 404 page not found\n"19992026/11/11 23:23:16 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign20002026/11/11 23:23:16 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"20012026/11/11 23:23:16 INFO Signed narinfos id=2 count=120022026/11/11 23:23:16 INFO Uploading 1 narinfos20032026/11/11 23:23:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20042026/11/11 23:23:16 INFO Uploading py7cvv66mwwbmpzfd6s1z5bd9vrm3i8f-ca-test (144B)20052026/11/11 23:23:16 INFO Received complete push request method=POST path=/api/pushes/2/complete20062026/11/11 23:23:16 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"20072026/11/11 23:23:16 WARN Failed to register uploaded object key=jk8b2jww89vvkvk0bhhrrvmcm6xzbb3l.narinfo error="server returned 404: 404 page not found\n"20082026/11/11 23:23:16 INFO Completed push id=2 objects=3 duration=3.222491ms20092026/11/11 23:23:16 INFO Upload complete. (159ms)20102026/11/11 23:23:16 INFO Aborted multipart uploads count=0 kept=020112026/11/11 23:23:16 WARN Failed to register uploaded object key=py7cvv66mwwbmpzfd6s1z5bd9vrm3i8f.ls error="server returned 404: 404 page not found\n"20122026/11/11 23:23:16 WARN Failed to register uploaded object key=log/z31hb8s1hq7y2iz9kwxmk3d8bl9m0ps9-ca-test.drv error="server returned 404: 404 page not found\n"20132026/11/11 23:23:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20142026/11/11 23:23:16 INFO Signed narinfos id=1 count=120152026/11/11 23:23:16 INFO Uploading 1 narinfos20162026/11/11 23:23:16 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=1 objects-deleted-after-grace-period=1 objects-failed-to-delete=020172026/11/11 23:23:16 INFO Vacuumed table table=pending_closures20182026/11/11 23:23:16 INFO Vacuumed table table=pending_objects20192026/11/11 23:23:16 INFO Vacuumed table table=multipart_uploads20202026/11/11 23:23:16 INFO Vacuumed table table=closures20212026/11/11 23:23:16 INFO Received complete push request method=POST path=/api/pushes/1/complete20222026/11/11 23:23:16 WARN Failed to register uploaded object key=py7cvv66mwwbmpzfd6s1z5bd9vrm3i8f.narinfo error="server returned 404: 404 page not found\n"20232026/11/11 23:23:16 INFO Vacuumed table table=objects20242026/11/11 23:23:16 INFO Aborted multipart uploads count=0 kept=020252026/11/11 23:23:16 INFO Completed push id=1 objects=4 duration=11.746952ms20262026/11/11 23:23:16 INFO Upload complete. (1.942s)2027=== NAME TestClientCADerivations2028 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations865681996/001/store/py7cvv66mwwbmpzfd6s1z5bd9vrm3i8f-ca-test2029 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2030 Compression: zstd2031 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2032 NarSize: 1442033 References: 2034 Deriver: /build/TestClientCADerivations865681996/001/store/z31hb8s1hq7y2iz9kwxmk3d8bl9m0ps9-ca-test.drv2035 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2036 client_ca_test.go:185: Checking for realisation files in S3...20372026/11/11 23:23:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2038=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh20392026/11/11 23:23:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2040=== NAME TestClientCADerivations2041 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2042 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache2043=== CONT TestServerTLSConfig/no_client_CA2044=== CONT TestServerTLSConfig/not_a_PEM_file20452026/11/11 23:23:16 WARN Force mode enabled - objects will be deleted immediately without grace period2046=== CONT TestServerTLSConfig/missing_CA_file2047--- PASS: TestServerTLSConfig (0.00s)2048 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2049 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2050 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)20512026/11/11 23:23:16 WARN Force mode enabled - objects will be deleted immediately without grace period20522026/11/11 23:23:16 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=02053=== NAME TestNARDeduplicationMetadataUploadBug2054 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2690816282/001/store/nbckdzz1arf0phml8wm9llzf8pph0i8l-file2.txt20552026/11/11 23:23:16 INFO Vacuumed table table=pending_closures20562026/11/11 23:23:16 INFO Vacuumed table table=pending_objects20572026/11/11 23:23:16 INFO Vacuumed table table=multipart_uploads20582026/11/11 23:23:16 INFO Vacuumed table table=closures20592026/11/11 23:23:16 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000200000000000000000000.nar.zst upload_id=ZGM4ZDNkMDMtODNjNy00MWQyLTlmN2QtMzZiNTVlMjM4ZDE2LjZhYjRjNzViLWRkMGMtNGU2Yy05Y2UzLWM4YjUwZTc3ZmQ3ZHgxNzk0NDM5Mzk1MzcwOTIyNjA2 parts=1020602026/11/11 23:23:16 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst upload_id=ZGM4ZDNkMDMtODNjNy00MWQyLTlmN2QtMzZiNTVlMjM4ZDE2LmUzOTNkZGRiLTQyZTAtNGM2Yy05NjQ1LWQ5YjY1MjA0NjNmNngxNzk0NDM5Mzk1MzQyNTk2Mzc2 parts=1020612026/11/11 23:23:16 INFO Vacuumed table table=objects2062--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2063 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (1.50s)2064 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (1.55s)20652026/11/11 23:23:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20662026/11/11 23:23:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20672026/11/11 23:23:16 INFO Completed upload id=1 objects=3 duration=9.090207ms20682026/11/11 23:23:16 INFO Received uploads request method=POST path=/api/pending_closures20692026/11/11 23:23:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20702026/11/11 23:23:16 INFO Completed upload id=1 objects=3 duration=4.571804ms20712026/11/11 23:23:16 INFO Received uploads request method=POST path=/api/pending_closures20722026/11/11 23:23:16 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst upload_id=ZGM4ZDNkMDMtODNjNy00MWQyLTlmN2QtMzZiNTVlMjM4ZDE2LmU1ZWIzODZkLTNjNmUtNGNkMC1iYzBjLTE2MTA2NzNiMDUyMXgxNzk0NDM5Mzk1NDMzODU2Nzg2 parts=1020732026/11/11 23:23:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20742026/11/11 23:23:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20752026/11/11 23:23:16 INFO Completed upload id=1 objects=3 duration=4.481782ms20762026/11/11 23:23:16 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst upload_id=ZGM4ZDNkMDMtODNjNy00MWQyLTlmN2QtMzZiNTVlMjM4ZDE2LmE3YzE2ODk5LTI4OWQtNDQ1My05OGE1LTMzMTUwMzU0YjllY3gxNzk0NDM5Mzk1Mzk1MjcyNDk4 parts=1020772026/11/11 23:23:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20782026/11/11 23:23:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20792026/11/11 23:23:16 INFO Received uploads request method=POST path=/api/pending_closures20802026/11/11 23:23:16 INFO Completed upload id=1 objects=3 duration=4.333921ms20812026/11/11 23:23:16 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst20822026/11/11 23:23:16 WARN Found objects in DB but missing from S3, will re-upload count=120832026/11/11 23:23:16 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20842026/11/11 23:23:16 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:38383/bucket102/?delete=\": context canceled"20852026/11/11 23:23:16 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst upload_id=ZGM4ZDNkMDMtODNjNy00MWQyLTlmN2QtMzZiNTVlMjM4ZDE2LmE4ZDkyM2U4LTk0NGQtNGVjMS05NmVlLWE4OGIxNzJlNTUwZngxNzk0NDM5Mzk2NDE5NTEwMjgz parts=1020862026/11/11 23:23:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20872026/11/11 23:23:16 INFO Starting cleanup of old closures method=DELETE path=/api/closures20882026/11/11 23:23:16 INFO Completed upload id=1 objects=3 duration=3.659675ms20892026/11/11 23:23:16 INFO Received uploads request method=POST path=/api/pending_closures20902026/11/11 23:23:16 INFO Garbage collection started20912026/11/11 23:23:16 INFO Received uploads request method=POST path=/api/pending_closures20922026/11/11 23:23:16 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst20932026/11/11 23:23:16 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0001.narinfo20942026/11/11 23:23:16 INFO Aborted multipart uploads count=0 kept=020952026/11/11 23:23:16 INFO Aborted multipart uploads count=0 kept=020962026/11/11 23:23:16 INFO Received uploads request method=POST path=/api/pending_closures20972026/11/11 23:23:16 WARN Request failed, retrying attempt=2 backoff=215.265378ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20982026/11/11 23:23:17 WARN Force mode enabled - objects will be deleted immediately without grace period20992026/11/11 23:23:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21002026/11/11 23:23:17 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100300000000000000000000.nar.zst upload_id=ZGM4ZDNkMDMtODNjNy00MWQyLTlmN2QtMzZiNTVlMjM4ZDE2LjE4NzNjZGVkLTU1MDUtNDI5NS05NWZlLTFmMjM0YTU5YWEwNXgxNzk0NDM5Mzk2NzUzMDA2MzIz parts=1021012026/11/11 23:23:17 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21022026/11/11 23:23:17 INFO Completed upload id=2 objects=3 duration=1.486214ms21032026/11/11 23:23:17 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=021042026/11/11 23:23:17 INFO Vacuumed table table=pending_closures21052026/11/11 23:23:17 INFO Vacuumed table table=pending_objects21062026/11/11 23:23:17 INFO Vacuumed table table=multipart_uploads21072026/11/11 23:23:17 INFO Vacuumed table table=closures21082026/11/11 23:23:17 INFO Vacuumed table table=objects21092026/11/11 23:23:17 INFO Received uploads request method=POST path=/api/pending_closures21102026/11/11 23:23:17 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst21112026/11/11 23:23:17 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0003.narinfo21122026/11/11 23:23:17 WARN Request failed, retrying attempt=3 backoff=435.281334ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21132026/11/11 23:23:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21142026/11/11 23:23:17 INFO Received push request method=POST path=/api/pushes21152026/11/11 23:23:17 WARN Force mode enabled - objects will be deleted immediately without grace period21162026/11/11 23:23:17 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)21172026/11/11 23:23:17 INFO Received complete push request method=POST path=/api/pushes/3/complete21182026/11/11 23:23:17 WARN Failed to register uploaded object key=gs51vd0cvqslqz6ih060dss37n6v41vg.ls error="server returned 404: 404 page not found\n"21192026/11/11 23:23:17 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100400000000000000000000.nar.zst upload_id=ZGM4ZDNkMDMtODNjNy00MWQyLTlmN2QtMzZiNTVlMjM4ZDE2LmZkN2I3Njc0LTRkMmQtNGM1OC1hYzU2LTg2NjM0MjRlNjIzM3gxNzk0NDM5Mzk2ODQ4MjIwODEw parts=1021202026/11/11 23:23:17 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21212026/11/11 23:23:17 INFO Completed push id=3 objects=3 duration=1.554855ms21222026/11/11 23:23:17 INFO Upload complete. (343ms)21232026/11/11 23:23:17 INFO Completed upload id=2 objects=3 duration=1.872758ms2124=== NAME TestClientIntegration2125 client_integration_test.go:353: Retrieved .ls file from S3 (compressed size: 62 bytes)2126 client_integration_test.go:353: Decompressed .ls content (49 bytes):2127 {"version":1,"root":{"type":"regular","size":39}}2128 client_integration_test.go:364: Testing garbage collection...2129--- PASS: TestGCEndsOnShutdown (0.00s)2130 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (1.98s)2131 --- PASS: TestGCEndsOnShutdown/before_the_run (2.09s)2132 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (2.37s)21332026/11/11 23:23:17 INFO Received uploads request method=POST path=/api/pending_closures21342026/11/11 23:23:17 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst21352026/11/11 23:23:17 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0004.narinfo2136--- PASS: TestService_verifyS3ReuploadsStaleNarinfo (0.01s)2137 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed (1.70s)2138 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed (1.87s)2139 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed (1.95s)2140 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost (2.13s)2141 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed (2.26s)21422026/11/11 23:23:17 INFO Received push request method=POST path=/api/pushes21432026/11/11 23:23:17 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21442026/11/11 23:23:17 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)21452026/11/11 23:23:17 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign21462026/11/11 23:23:17 WARN Failed to register uploaded object key=nbckdzz1arf0phml8wm9llzf8pph0i8l.ls error="server returned 404: 404 page not found\n"21472026/11/11 23:23:17 INFO Signed narinfos id=2 count=121482026/11/11 23:23:17 INFO Uploading 1 narinfos21492026/11/11 23:23:17 INFO Received complete push request method=POST path=/api/pushes/2/complete21502026/11/11 23:23:17 WARN Failed to register uploaded object key=nbckdzz1arf0phml8wm9llzf8pph0i8l.narinfo error="server returned 404: 404 page not found\n"21512026/11/11 23:23:17 INFO Completed push id=2 objects=3 duration=3.029709ms21522026/11/11 23:23:17 INFO Upload complete. (260ms)2153=== NAME TestNARDeduplicationMetadataUploadBug2154 metadata_upload_test.go:76: Retrieved narinfo from S3:2155 StorePath: /build/TestNARDeduplicationMetadataUploadBug2690816282/001/store/nbckdzz1arf0phml8wm9llzf8pph0i8l-file2.txt2156 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2157 Compression: zstd2158 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2159 NarSize: 1602160 References: 2161 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2162 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2163 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2164 {"version":1,"root":{"type":"regular","size":44}}2165--- PASS: TestNARDeduplicationMetadataUploadBug (2.91s)21662026/11/11 23:23:17 INFO Starting cleanup of old closures method=DELETE path=/api/closures21672026/11/11 23:23:17 INFO Garbage collection started21682026/11/11 23:23:17 INFO Aborted multipart uploads count=0 kept=02169--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2170 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.88s)2171 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.84s)21722026/11/11 23:23:17 WARN Force mode enabled - objects will be deleted immediately without grace period21732026/11/11 23:23:17 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=021742026/11/11 23:23:17 INFO Vacuumed table table=pending_closures21752026/11/11 23:23:17 INFO Vacuumed table table=pending_objects21762026/11/11 23:23:17 INFO Vacuumed table table=multipart_uploads21772026/11/11 23:23:17 INFO Vacuumed table table=closures21782026/11/11 23:23:17 INFO Vacuumed table table=objects21792026/11/11 23:23:17 WARN Request failed, retrying attempt=4 backoff=868.010184ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21802026/11/11 23:23:17 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2181--- PASS: TestPendingClosureWriteTimeout (0.00s)2182 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2183 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2184 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2185 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.19s)2186=== NAME TestOrphanedObjectsGCStressTest2187 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains21882026/11/11 23:23:17 WARN Rate limiter enabled after throttle name=s3-test rate=521892026/11/11 23:23:17 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2190=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2191 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102192 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002193--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.87s)21942026/11/11 23:23:18 WARN Request failed, retrying attempt=5 backoff=1.67694568s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21952026/11/11 23:23:18 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=021962026/11/11 23:23:18 INFO Received create pin request method=POST path=/api/pins/myapp2197--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.97s)21982026/11/11 23:23:19 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2850044921/001/store/96w9dwx2shadgi3s68ikl15jhy1bwzq9-pinned-file.txt narinfo_key=96w9dwx2shadgi3s68ikl15jhy1bwzq9.narinfo21992026/11/11 23:23:19 INFO Starting cleanup of old closures method=DELETE path=/api/closures22002026/11/11 23:23:19 INFO Garbage collection started22012026/11/11 23:23:19 INFO Aborted multipart uploads count=0 kept=022022026/11/11 23:23:19 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02203=== NAME TestClientIntegration2204 client_integration_test.go:371: Objects in database after GC:2205 client_integration_test.go:371: Successfully deleted all objects with GC --force2206--- PASS: TestClientIntegration (8.48s)22072026/11/11 23:23:19 INFO Aborted multipart uploads count=1 kept=022082026/11/11 23:23:19 INFO Received cleanup request method=DELETE path=/api/pending_closures22092026/11/11 23:23:19 INFO Aborted multipart uploads count=1 kept=02210--- PASS: TestPendingCleanupUsesOneCutoff (6.56s)22112026/11/11 23:23:21 INFO Garbage collection progress phase=cleanup_pending_uploads failed_uploads_deleted=0 old_closures_deleted=0 objects_marked=0 objects_deleted=0 objects_failed=02212=== NAME TestOrphanedObjectsGCStressTest2213 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion22142026/11/11 23:23:21 WARN Force mode enabled - objects will be deleted immediately without grace period22152026/11/11 23:23:21 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=022162026/11/11 23:23:21 INFO Vacuumed table table=pending_closures22172026/11/11 23:23:21 INFO Vacuumed table table=pending_objects22182026/11/11 23:23:21 INFO Vacuumed table table=multipart_uploads22192026/11/11 23:23:21 INFO Vacuumed table table=closures22202026/11/11 23:23:21 INFO Vacuumed table table=objects22212026/11/11 23:23:21 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-config22222026/11/11 23:23:21 WARN Request failed, retrying attempt=2 backoff=194.484736ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22232026/11/11 23:23:21 WARN Request failed, retrying attempt=3 backoff=371.380508ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2224 orphaned_objects_gc_test.go:503: Stress test completed successfully:2225 orphaned_objects_gc_test.go:504: - Active objects preserved: 202226 orphaned_objects_gc_test.go:505: - Objects deleted: 2102227 orphaned_objects_gc_test.go:506: - Total GC'd: 2102228--- PASS: TestOrphanedObjectsGCStressTest (7.61s)22292026/11/11 23:23:21 WARN Request failed, retrying attempt=4 backoff=872.943339ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2230--- PASS: TestDeleteClosuresRacingPins (11.93s)22312026/11/11 23:23:22 WARN Request failed, retrying attempt=5 backoff=1.518922699s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22322026/11/11 23:23:23 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=0 objects_marked=0 objects_deleted=0 objects_failed=02233=== NAME TestPinProtectsFromGC2234 client_integration_test.go:888: Pin successfully protected closure from garbage collection2235--- PASS: TestPinProtectsFromGC (12.15s)22362026/11/11 23:23:24 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"22372026/11/11 23:23:24 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-config22382026/11/11 23:23:24 WARN Request failed, retrying attempt=2 backoff=183.024433ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22392026/11/11 23:23:24 WARN Request failed, retrying attempt=3 backoff=404.025655ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22402026/11/11 23:23:25 WARN Request failed, retrying attempt=4 backoff=759.075048ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22412026/11/11 23:23:25 WARN Request failed, retrying attempt=5 backoff=1.446368109s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22422026/11/11 23:23:27 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_closures22432026/11/11 23:23:27 WARN Request failed, retrying attempt=2 backoff=204.059806ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22442026/11/11 23:23:27 WARN Request failed, retrying attempt=3 backoff=425.673554ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22452026/11/11 23:23:27 WARN Request failed, retrying attempt=4 backoff=838.491515ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22462026/11/11 23:23:28 WARN Request failed, retrying attempt=5 backoff=1.470482061s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2247--- PASS: TestClientErrorHandling (0.00s)2248 --- PASS: TestClientErrorHandling/InvalidStorePath (1.48s)2249 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.18s)2250 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.78s)2251=== NAME TestClientCADerivations2252 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2253 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2254 error: binary cache 's3://bucket66?endpoint=http://localhost:38383®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations865681996/001/store'2255 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12256--- PASS: TestClientCADerivations (27.43s)2257PASS2258{"timestamp":"2026-11-11T23:23:38.397874208Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:43522","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(206)"}2259{"timestamp":"2026-11-11T23:23:38.397870108Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:43534","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(199)"}2260{"timestamp":"2026-11-11T23:23:38.397879408Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:43502","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(198)"}2261{"timestamp":"2026-11-11T23:23:38.397695706Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:43574","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(197)"}2262{"timestamp":"2026-11-11T23:23:38.397884428Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:43514","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(205)"}22632026-11-11 23:23:38.793 UTC [128] LOG: received smart shutdown request22642026-11-11 23:23:38.800 UTC [128] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 122652026-11-11 23:23:38.815 UTC [134] LOG: shutting down22662026-11-11 23:23:38.816 UTC [134] LOG: checkpoint starting: shutdown immediate22672026-11-11 23:23:39.635 UTC [134] LOG: checkpoint complete: wrote 9396 buffers (57.3%), wrote 8 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.315 s, sync=0.451 s, total=0.820 s; sync files=36846, longest=0.004 s, average=0.001 s; distance=532511 kB, estimate=532511 kB; lsn=0/21F6DC08, redo lsn=0/21F6DC0822682026-11-11 23:23:39.803 UTC [128] LOG: database system is shut down2269Running OIDC tests...2270=== RUN TestAudienceForIssuer2271=== PAUSE TestAudienceForIssuer2272=== RUN TestGlobMatch2273=== PAUSE TestGlobMatch2274=== RUN TestValidateToken_ValidToken2275=== PAUSE TestValidateToken_ValidToken2276=== RUN TestValidateToken_WrongAudience2277=== PAUSE TestValidateToken_WrongAudience2278=== RUN TestValidateToken_Expired2279=== PAUSE TestValidateToken_Expired2280=== RUN TestValidateToken_BoundClaimsMismatch2281=== PAUSE TestValidateToken_BoundClaimsMismatch2282=== RUN TestValidateToken_BoundSubjectMismatch2283=== PAUSE TestValidateToken_BoundSubjectMismatch2284=== RUN TestValidateToken_MultipleProviders2285=== PAUSE TestValidateToken_MultipleProviders2286=== RUN TestValidateToken_NoMatchingProvider2287=== PAUSE TestValidateToken_NoMatchingProvider2288=== RUN TestValidateToken_KubernetesServiceAccount2289=== PAUSE TestValidateToken_KubernetesServiceAccount2290=== RUN TestNewValidator_KubernetesRequiresCA2291=== PAUSE TestNewValidator_KubernetesRequiresCA2292=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2293=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2294=== RUN TestPins_ReservedForMatchingRule2295=== PAUSE TestPins_ReservedForMatchingRule2296=== RUN TestPins_TopLevelShorthand2297=== PAUSE TestPins_TopLevelShorthand2298=== RUN TestPins_ConfigValidation2299=== PAUSE TestPins_ConfigValidation2300=== RUN TestScopes_LegacyProviderDefaultsToWrite2301=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2302=== RUN TestScopes_Rules2303=== PAUSE TestScopes_Rules2304=== RUN TestScopes_ConfigValidation2305=== PAUSE TestScopes_ConfigValidation2306=== CONT TestAudienceForIssuer2307=== CONT TestValidateToken_BoundClaimsMismatch2308--- PASS: TestAudienceForIssuer (0.00s)2309=== CONT TestNewValidator_KubernetesRequiresCA2310=== CONT TestValidateToken_WrongAudience2311=== CONT TestPins_TopLevelShorthand2312=== CONT TestPins_ReservedForMatchingRule2313=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2314=== CONT TestScopes_Rules2315=== CONT TestScopes_ConfigValidation2316=== CONT TestScopes_LegacyProviderDefaultsToWrite2317=== CONT TestValidateToken_ValidToken2318=== CONT TestValidateToken_NoMatchingProvider2319=== CONT TestValidateToken_KubernetesServiceAccount2320=== CONT TestGlobMatch2321=== RUN TestGlobMatch/foo_foo2322=== PAUSE TestGlobMatch/foo_foo2323=== CONT TestValidateToken_MultipleProviders2324=== CONT TestValidateToken_BoundSubjectMismatch2325=== RUN TestGlobMatch/foo_bar2326=== PAUSE TestGlobMatch/foo_bar2327=== CONT TestPins_ConfigValidation2328=== CONT TestValidateToken_Expired2329=== RUN TestGlobMatch/*_2330=== PAUSE TestGlobMatch/*_2331=== RUN TestGlobMatch/*_anything2332=== PAUSE TestGlobMatch/*_anything2333=== RUN TestGlobMatch/foo*_foo2334=== PAUSE TestGlobMatch/foo*_foo2335=== RUN TestGlobMatch/foo*_foobar2336=== PAUSE TestGlobMatch/foo*_foobar2337=== RUN TestGlobMatch/foo*_bar2338=== PAUSE TestGlobMatch/foo*_bar2339=== RUN TestGlobMatch/*bar_bar2340=== PAUSE TestGlobMatch/*bar_bar2341=== RUN TestGlobMatch/*bar_foobar2342=== PAUSE TestGlobMatch/*bar_foobar2343=== RUN TestGlobMatch/*bar_foo2344=== PAUSE TestGlobMatch/*bar_foo2345=== RUN TestGlobMatch/foo*bar_foobar2346=== PAUSE TestGlobMatch/foo*bar_foobar2347=== RUN TestGlobMatch/foo*bar_foo123bar2348=== PAUSE TestGlobMatch/foo*bar_foo123bar2349=== RUN TestGlobMatch/foo*bar_foobarbaz2350=== PAUSE TestGlobMatch/foo*bar_foobarbaz2351=== RUN TestGlobMatch/*/*_foo/bar2352=== PAUSE TestGlobMatch/*/*_foo/bar2353=== RUN TestGlobMatch/*/*_foo2354=== PAUSE TestGlobMatch/*/*_foo2355=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2356=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2357=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02358=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02359=== RUN TestGlobMatch/refs/*/main_refs/heads/main2360=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2361=== RUN TestGlobMatch/fo?_foo2362=== PAUSE TestGlobMatch/fo?_foo2363=== RUN TestGlobMatch/fo?_fo2364=== PAUSE TestGlobMatch/fo?_fo2365=== RUN TestGlobMatch/fo?_fooo2366=== PAUSE TestGlobMatch/fo?_fooo2367=== RUN TestGlobMatch/?oo_foo2368=== PAUSE TestGlobMatch/?oo_foo2369=== RUN TestGlobMatch/?oo_boo2370=== PAUSE TestGlobMatch/?oo_boo2371=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2372=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2373=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2374=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2375=== CONT TestGlobMatch/foo_foo2376=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2377=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2378=== CONT TestGlobMatch/?oo_boo2379=== CONT TestGlobMatch/?oo_foo2380=== CONT TestGlobMatch/fo?_fooo2381=== CONT TestGlobMatch/fo?_fo2382=== CONT TestGlobMatch/fo?_foo2383=== CONT TestGlobMatch/refs/*/main_refs/heads/main2384=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02385=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2386=== CONT TestGlobMatch/*/*_foo2387=== CONT TestGlobMatch/*/*_foo/bar2388=== CONT TestGlobMatch/foo*bar_foobarbaz2389=== CONT TestGlobMatch/foo*bar_foo123bar2390=== CONT TestGlobMatch/*_anything2391=== CONT TestGlobMatch/foo*bar_foobar2392=== CONT TestGlobMatch/foo_bar2393=== CONT TestGlobMatch/*bar_foo2394=== CONT TestGlobMatch/*bar_foobar2395=== CONT TestGlobMatch/*bar_bar2396=== CONT TestGlobMatch/foo*_bar2397=== CONT TestGlobMatch/foo*_foobar2398=== CONT TestGlobMatch/foo*_foo2399=== CONT TestGlobMatch/*_2400--- PASS: TestGlobMatch (0.00s)2401 --- PASS: TestGlobMatch/foo_foo (0.00s)2402 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2403 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2404 --- PASS: TestGlobMatch/?oo_boo (0.00s)2405 --- PASS: TestGlobMatch/?oo_foo (0.00s)2406 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2407 --- PASS: TestGlobMatch/fo?_fo (0.00s)2408 --- PASS: TestGlobMatch/fo?_foo (0.00s)2409 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2410 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2411 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2412 --- PASS: TestGlobMatch/*/*_foo (0.00s)2413 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2414 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2415 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2416 --- PASS: TestGlobMatch/*_anything (0.00s)2417 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2418 --- PASS: TestGlobMatch/foo_bar (0.00s)2419 --- PASS: TestGlobMatch/*bar_foo (0.00s)2420 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2421 --- PASS: TestGlobMatch/*bar_bar (0.00s)2422 --- PASS: TestGlobMatch/foo*_bar (0.00s)2423 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2424 --- PASS: TestGlobMatch/foo*_foo (0.00s)2425 --- PASS: TestGlobMatch/*_ (0.00s)2426--- PASS: TestPins_ConfigValidation (1.59s)2427--- PASS: TestScopes_ConfigValidation (5.59s)24282026/11/11 23:23:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33055/oidc24292026/11/11 23:23:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40273/oidc24302026/11/11 23:23:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44353/oidc24312026/11/11 23:23:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36227/oidc24322026/11/11 23:23:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42755/oidc2433--- PASS: TestScopes_LegacyProviderDefaultsToWrite (9.54s)2434--- PASS: TestValidateToken_WrongAudience (9.59s)2435--- PASS: TestPins_TopLevelShorthand (9.59s)2436--- PASS: TestValidateToken_BoundClaimsMismatch (9.59s)2437--- PASS: TestScopes_Rules (9.57s)24382026/11/11 23:23:53 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12324392026/11/11 23:23:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36579/oidc2440--- PASS: TestValidateToken_BoundSubjectMismatch (5.59s)2441--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (9.60s)24422026/11/11 23:23:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44173/oidc2443--- PASS: TestPins_ReservedForMatchingRule (9.61s)24442026/11/11 23:23:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37329/oidc2445--- PASS: TestValidateToken_Expired (5.63s)24462026/11/11 23:23:53 http: TLS handshake error from 127.0.0.1:42618: remote error: tls: bad certificate2447--- PASS: TestNewValidator_KubernetesRequiresCA (9.70s)24482026/11/11 23:23:53 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:382752449--- PASS: TestValidateToken_KubernetesServiceAccount (5.74s)24502026/11/11 23:23:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46729/oidc2451--- PASS: TestValidateToken_ValidToken (5.76s)24522026/11/11 23:23:53 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:42249/oidc24532026/11/11 23:23:53 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:40533/oidc2454--- PASS: TestValidateToken_MultipleProviders (5.82s)24552026/11/11 23:23:54 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:34745/oidc2456--- PASS: TestValidateToken_NoMatchingProvider (5.98s)2457PASS2458Running hook tests...2459=== RUN TestSendPathsEmpty2460=== PAUSE TestSendPathsEmpty2461=== RUN TestQueueEnqueueAndFetch2462=== PAUSE TestQueueEnqueueAndFetch2463=== RUN TestQueueDeduplication2464=== PAUSE TestQueueDeduplication2465=== RUN TestQueueRemove2466=== PAUSE TestQueueRemove2467=== RUN TestQueueFetchBatchLimit2468=== PAUSE TestQueueFetchBatchLimit2469=== RUN TestQueueRetryMovesToBack2470=== PAUSE TestQueueRetryMovesToBack2471=== RUN TestQueueFetchRemoveLifecycle2472=== PAUSE TestQueueFetchRemoveLifecycle2473=== RUN TestQueueConcurrentWriters2474=== PAUSE TestQueueConcurrentWriters2475=== RUN TestQueueRemoveLargeClosure2476=== PAUSE TestQueueRemoveLargeClosure2477=== RUN TestServerClientIntegration2478--- PASS: TestServerClientIntegration (0.01s)2479=== RUN TestServerQueueError24802026/11/11 23:23:54 ERROR Failed to queue paths error="permission denied" count=12481--- PASS: TestServerQueueError (0.00s)2482=== RUN TestGetListenerSocketActivation2483 server_test.go:219: === RUN TestGetListenerSocketActivation2484 --- PASS: TestGetListenerSocketActivation (0.00s)2485 PASS2486 2487--- PASS: TestGetListenerSocketActivation (0.36s)2488=== RUN TestServerStalledClientDoesNotBlockShutdown2489=== PAUSE TestServerStalledClientDoesNotBlockShutdown2490=== RUN TestServerBacksOffOnAcceptErrors2491=== PAUSE TestServerBacksOffOnAcceptErrors2492=== RUN TestDrainIsolatesPoisonPath2493=== PAUSE TestDrainIsolatesPoisonPath2494=== RUN TestRunNotBlockedByPoisonHead2495=== PAUSE TestRunNotBlockedByPoisonHead2496=== RUN TestDrainGivesUpWhenServerDown2497=== PAUSE TestDrainGivesUpWhenServerDown2498=== RUN TestFailedPathPrunedByLaterClosure2499=== PAUSE TestFailedPathPrunedByLaterClosure2500=== RUN TestWorkerUploadsAndRemoves2501=== PAUSE TestWorkerUploadsAndRemoves2502=== RUN TestWorkerSkipsGCdPaths2503=== PAUSE TestWorkerSkipsGCdPaths2504=== RUN TestWorkerPrunesClosureDeps2505=== PAUSE TestWorkerPrunesClosureDeps2506=== RUN TestDrainTimeout2507=== PAUSE TestDrainTimeout2508=== RUN TestWorkerRemoveFailureIsNotProgress2509=== PAUSE TestWorkerRemoveFailureIsNotProgress2510=== RUN TestWorkerKeepsPathItCannotStat2511=== PAUSE TestWorkerKeepsPathItCannotStat2512=== CONT TestSendPathsEmpty2513--- PASS: TestSendPathsEmpty (0.00s)2514=== CONT TestWorkerKeepsPathItCannotStat2515=== CONT TestWorkerRemoveFailureIsNotProgress2516=== CONT TestServerBacksOffOnAcceptErrors25172026/11/11 23:23:54 ERROR Accept failed error="too many open files"2518=== CONT TestQueueRetryMovesToBack2519=== CONT TestDrainTimeout2520=== CONT TestServerStalledClientDoesNotBlockShutdown2521=== CONT TestQueueRemoveLargeClosure2522=== CONT TestWorkerPrunesClosureDeps2523=== CONT TestWorkerSkipsGCdPaths2524=== CONT TestQueueFetchBatchLimit25252026/11/11 23:23:54 ERROR Accept failed error="too many open files"2526=== CONT TestWorkerUploadsAndRemoves2527=== CONT TestQueueRemove25282026/11/11 23:23:54 INFO Upload queue status pending=225292026/11/11 23:23:54 INFO Uploading batch count=22530=== CONT TestQueueDeduplication2531=== CONT TestFailedPathPrunedByLaterClosure2532=== CONT TestDrainGivesUpWhenServerDown2533=== CONT TestQueueConcurrentWriters2534=== CONT TestQueueEnqueueAndFetch2535=== CONT TestQueueFetchRemoveLifecycle25362026/11/11 23:23:54 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3765390997/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat3765390997/002/locked/aaa: permission denied"2537=== CONT TestRunNotBlockedByPoisonHead25382026/11/11 23:23:54 ERROR Accept failed error="too many open files"2539=== CONT TestDrainIsolatesPoisonPath2540--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2541--- PASS: TestQueueDeduplication (0.01s)2542--- PASS: TestQueueRetryMovesToBack (0.02s)25432026/11/11 23:23:54 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3765390997/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat3765390997/002/locked/aaa: permission denied"25442026/11/11 23:23:54 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3765390997/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat3765390997/002/locked/aaa: permission denied"25452026/11/11 23:23:54 ERROR Drain finished with paths left in queue remaining=125462026/11/11 23:23:54 INFO Upload queue status pending=225472026/11/11 23:23:54 INFO Uploading batch count=125482026/11/11 23:23:54 INFO Upload queue status pending=225492026/11/11 23:23:54 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2912906207/002/nonexistent25502026/11/11 23:23:54 INFO Uploading batch count=125512026/11/11 23:23:54 ERROR Upload failed error="upload failed" count=125522026/11/11 23:23:54 INFO Uploading batch count=125532026/11/11 23:23:54 INFO Uploading batch count=125542026/11/11 23:23:54 INFO Upload queue status pending=325552026/11/11 23:23:54 INFO Uploading batch count=125562026/11/11 23:23:54 ERROR Upload failed error="upload failed" count=125572026/11/11 23:23:54 INFO Uploading batch count=22558--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)2559--- PASS: TestWorkerUploadsAndRemoves (0.02s)2560--- PASS: TestQueueFetchBatchLimit (0.03s)25612026/11/11 23:23:54 INFO Uploading batch count=12562--- PASS: TestWorkerKeepsPathItCannotStat (0.16s)25632026/11/11 23:23:54 ERROR Accept failed error="too many open files"2564--- PASS: TestWorkerPrunesClosureDeps (0.15s)2565--- PASS: TestQueueRemove (0.15s)25662026/11/11 23:23:54 INFO Uploading batch count=425672026/11/11 23:23:54 ERROR Upload failed error="upload failed" count=425682026/11/11 23:23:54 INFO Uploading batch count=225692026/11/11 23:23:54 ERROR Upload failed error="upload failed" count=225702026/11/11 23:23:54 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown980426461/002/a2571--- PASS: TestQueueEnqueueAndFetch (0.14s)25722026/11/11 23:23:54 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3618629487/002/bbb25732026/11/11 23:23:54 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown980426461/002/b2574--- PASS: TestWorkerSkipsGCdPaths (0.15s)25752026/11/11 23:23:54 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress2448449925/002/nonexistent25762026/11/11 23:23:54 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125772026/11/11 23:23:54 INFO Uploading batch count=225782026/11/11 23:23:54 ERROR Upload failed error="upload failed" count=225792026/11/11 23:23:54 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown980426461/002/c25802026/11/11 23:23:54 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress2448449925/002/nonexistent25812026/11/11 23:23:54 INFO Uploading batch count=125822026/11/11 23:23:54 ERROR Upload failed error="upload failed" count=125832026/11/11 23:23:54 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125842026/11/11 23:23:54 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress2448449925/002/nonexistent25852026/11/11 23:23:54 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125862026/11/11 23:23:54 ERROR Drain finished with paths left in queue remaining=125872026/11/11 23:23:54 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown980426461/002/d25882026/11/11 23:23:54 INFO Uploading batch count=125892026/11/11 23:23:54 ERROR Upload failed error="upload failed" count=125902026/11/11 23:23:54 INFO Uploading batch count=225912026/11/11 23:23:54 ERROR Upload failed error="upload failed" count=225922026/11/11 23:23:54 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown980426461/002/e25932026/11/11 23:23:54 INFO Uploading batch count=125942026/11/11 23:23:54 ERROR Upload failed error="upload failed" count=12595--- PASS: TestWorkerRemoveFailureIsNotProgress (0.16s)25962026/11/11 23:23:54 ERROR Drain finished with paths left in queue remaining=125972026/11/11 23:23:54 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown980426461/002/f25982026/11/11 23:23:54 ERROR Drain finished with paths left in queue remaining=102599--- PASS: TestDrainIsolatesPoisonPath (0.14s)2600--- PASS: TestDrainGivesUpWhenServerDown (0.15s)26012026/11/11 23:23:54 ERROR Accept failed error="too many open files"26022026/11/11 23:23:54 ERROR Failed to decode request error="read unix /build/hook396228367/test.sock->@: i/o timeout"26032026/11/11 23:23:54 ERROR Failed to write response error="write unix /build/hook396228367/test.sock->@: i/o timeout"26042026/11/11 23:23:54 ERROR Upload failed error="context deadline exceeded" count=226052026/11/11 23:23:54 ERROR Drain finished with paths left in queue remaining=42606--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.24s)2607--- PASS: TestDrainTimeout (0.24s)26082026/11/11 23:23:54 ERROR Accept failed error="too many open files"2609--- PASS: TestQueueConcurrentWriters (0.31s)26102026/11/11 23:23:54 ERROR Accept failed error="too many open files"2611--- PASS: TestQueueRemoveLargeClosure (0.58s)26122026/11/11 23:23:55 ERROR Accept failed error="too many open files"2613--- PASS: TestServerBacksOffOnAcceptErrors (0.75s)26142026/11/11 23:23:55 INFO Uploading batch count=126152026/11/11 23:23:55 INFO Uploading batch count=126162026/11/11 23:23:55 INFO Uploading batch count=126172026/11/11 23:23:55 ERROR Upload failed error="upload failed" count=126182026/11/11 23:23:55 INFO Uploading batch count=126192026/11/11 23:23:55 ERROR Upload failed error="upload failed" count=126202026/11/11 23:23:55 INFO Uploading batch count=126212026/11/11 23:23:55 ERROR Upload failed error="upload failed" count=126222026/11/11 23:23:55 INFO Uploading batch count=126232026/11/11 23:23:55 ERROR Upload failed error="upload failed" count=126242026/11/11 23:23:55 ERROR Drain finished with paths left in queue remaining=12625--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2626PASS2627Running signing tests...2628=== RUN TestExternalSigner2629=== PAUSE TestExternalSigner2630=== RUN TestExternalSignerWrongPublicKey2631=== PAUSE TestExternalSignerWrongPublicKey2632=== RUN TestExternalSignerErrors2633=== PAUSE TestExternalSignerErrors2634=== RUN TestExternalSignerRestartsAfterCrash2635=== PAUSE TestExternalSignerRestartsAfterCrash2636=== RUN TestExternalSignerProgramErrorKeepsProcess2637=== PAUSE TestExternalSignerProgramErrorKeepsProcess2638=== RUN TestExternalSignerClose2639=== PAUSE TestExternalSignerClose2640=== RUN TestExternalSignerRejectsInvalidPublicKey2641=== PAUSE TestExternalSignerRejectsInvalidPublicKey2642=== RUN TestExternalSignerCancellation2643=== PAUSE TestExternalSignerCancellation2644=== RUN TestGenerateFingerprint2645=== PAUSE TestGenerateFingerprint2646=== RUN TestParseSigningKey2647=== PAUSE TestParseSigningKey2648=== RUN TestSign2649=== PAUSE TestSign2650=== RUN TestSignBatch2651=== PAUSE TestSignBatch2652=== RUN TestNilKeyPublicKey2653=== PAUSE TestNilKeyPublicKey2654=== RUN TestSignErrors2655=== PAUSE TestSignErrors2656=== CONT TestExternalSigner2657=== CONT TestExternalSignerCancellation2658=== CONT TestSignBatch2659=== CONT TestSign2660=== CONT TestParseSigningKey2661=== RUN TestParseSigningKey/valid_32-byte_key2662=== PAUSE TestParseSigningKey/valid_32-byte_key2663=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2664=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2665=== RUN TestParseSigningKey/no_colon2666=== PAUSE TestParseSigningKey/no_colon2667=== RUN TestParseSigningKey/empty_name2668=== PAUSE TestParseSigningKey/empty_name2669=== RUN TestParseSigningKey/invalid_base642670=== PAUSE TestParseSigningKey/invalid_base642671=== RUN TestParseSigningKey/wrong_length2672=== PAUSE TestParseSigningKey/wrong_length2673=== CONT TestParseSigningKey/valid_32-byte_key2674=== CONT TestGenerateFingerprint2675=== RUN TestGenerateFingerprint/basic_with_references2676=== PAUSE TestGenerateFingerprint/basic_with_references2677=== RUN TestGenerateFingerprint/no_references2678=== PAUSE TestGenerateFingerprint/no_references2679=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2680=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2681=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2682=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2683=== RUN TestGenerateFingerprint/invalid_nar_hash_length2684=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2685=== RUN TestGenerateFingerprint/invalid_store_path_prefix2686=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2687=== RUN TestGenerateFingerprint/invalid_reference_prefix2688=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2689=== CONT TestGenerateFingerprint/basic_with_references2690=== CONT TestParseSigningKey/wrong_length2691=== CONT TestParseSigningKey/invalid_base642692=== CONT TestParseSigningKey/empty_name2693=== CONT TestParseSigningKey/no_colon2694=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2695=== CONT TestGenerateFingerprint/invalid_reference_prefix2696=== CONT TestGenerateFingerprint/invalid_store_path_prefix2697=== CONT TestGenerateFingerprint/invalid_nar_hash_length2698=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2699=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2700=== CONT TestGenerateFingerprint/no_references2701--- PASS: TestGenerateFingerprint (0.00s)2702 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2703 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2704 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2705 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2706 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2707 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2708 --- PASS: TestGenerateFingerprint/no_references (0.00s)2709=== CONT TestSignErrors2710=== CONT TestExternalSignerErrors2711=== RUN TestExternalSignerErrors/null2712=== PAUSE TestExternalSignerErrors/null2713=== RUN TestExternalSignerErrors/null_signatures2714=== CONT TestExternalSignerRejectsInvalidPublicKey2715=== RUN TestExternalSignerRejectsInvalidPublicKey/#002716=== CONT TestExternalSignerWrongPublicKey2717=== PAUSE TestExternalSignerErrors/null_signatures2718=== RUN TestExternalSignerErrors/wrong_signatures_shape2719=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2720=== RUN TestExternalSignerErrors/wrong_signature_name2721=== PAUSE TestExternalSignerErrors/wrong_signature_name2722=== RUN TestExternalSignerErrors/wrong_signature_length2723=== PAUSE TestExternalSignerErrors/wrong_signature_length2724=== RUN TestExternalSignerErrors/wrong_shape2725=== PAUSE TestExternalSignerErrors/wrong_shape2726=== RUN TestExternalSignerErrors/missing_signatures2727=== PAUSE TestExternalSignerErrors/missing_signatures2728=== RUN TestExternalSignerErrors/unrequested_key2729=== PAUSE TestExternalSignerErrors/unrequested_key2730=== RUN TestExternalSignerErrors/missing_signature_name2731=== PAUSE TestExternalSignerErrors/missing_signature_name2732=== RUN TestExternalSignerErrors/exit_at_startup2733=== PAUSE TestExternalSignerErrors/exit_at_startup2734=== RUN TestExternalSignerErrors/invalid_JSON2735=== PAUSE TestExternalSignerErrors/invalid_JSON2736=== RUN TestExternalSignerErrors/wrong_id2737=== PAUSE TestExternalSignerErrors/wrong_id2738=== RUN TestExternalSignerErrors/too_few_signatures2739=== PAUSE TestExternalSignerErrors/too_few_signatures2740=== RUN TestExternalSignerErrors/exit_on_request2741=== PAUSE TestExternalSignerErrors/exit_on_request2742=== RUN TestExternalSignerErrors/invalid_signature_base642743=== PAUSE TestExternalSignerErrors/invalid_signature_base642744=== RUN TestExternalSignerErrors/program_error2745=== PAUSE TestExternalSignerErrors/program_error2746=== CONT TestExternalSignerErrors/null2747=== CONT TestExternalSignerErrors/exit_at_startup2748=== CONT TestExternalSignerErrors/missing_signature_name2749--- PASS: TestSign (0.00s)2750=== CONT TestExternalSignerErrors/invalid_JSON2751--- PASS: TestSignBatch (0.00s)2752--- PASS: TestParseSigningKey (0.00s)2753 --- PASS: TestParseSigningKey/wrong_length (0.00s)2754 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2755 --- PASS: TestParseSigningKey/empty_name (0.00s)2756 --- PASS: TestParseSigningKey/no_colon (0.00s)2757 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2758 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2759=== RUN TestSignErrors/nil_key2760=== PAUSE TestSignErrors/nil_key2761=== RUN TestSignErrors/nil_narinfo2762=== PAUSE TestSignErrors/nil_narinfo2763=== RUN TestSignErrors/invalid_narinfo2764=== PAUSE TestSignErrors/invalid_narinfo2765=== RUN TestSignErrors/canceled2766=== PAUSE TestSignErrors/canceled2767=== CONT TestExternalSignerRestartsAfterCrash2768=== CONT TestExternalSignerErrors/null_signatures2769=== CONT TestExternalSignerProgramErrorKeepsProcess2770=== CONT TestExternalSignerClose2771=== CONT TestNilKeyPublicKey2772--- PASS: TestNilKeyPublicKey (0.00s)2773=== CONT TestSignErrors/nil_key2774=== CONT TestExternalSignerErrors/exit_on_request2775=== CONT TestExternalSignerErrors/program_error2776=== CONT TestExternalSignerErrors/invalid_signature_base642777=== CONT TestExternalSignerErrors/wrong_id2778=== CONT TestSignErrors/canceled2779=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002780=== CONT TestExternalSignerErrors/wrong_signature_length2781=== CONT TestExternalSignerErrors/wrong_signatures_shape2782=== CONT TestExternalSignerErrors/unrequested_key2783=== CONT TestExternalSignerErrors/wrong_signature_name2784=== CONT TestExternalSignerErrors/missing_signatures2785=== CONT TestExternalSignerErrors/wrong_shape2786=== CONT TestExternalSignerErrors/too_few_signatures2787=== CONT TestSignErrors/invalid_narinfo2788=== CONT TestSignErrors/nil_narinfo2789--- PASS: TestSignErrors (0.00s)2790 --- PASS: TestSignErrors/nil_key (0.00s)2791 --- PASS: TestSignErrors/canceled (0.00s)2792 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2793 --- PASS: TestSignErrors/nil_narinfo (0.00s)2794=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2795=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2796=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2797=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2798=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2799=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2800=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2801=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2802=== CONT TestExternalSignerRejectsInvalidPublicKey/#002803=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2804=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2805=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2806=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2807--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.01s)2808 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2809 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2810 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2811 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2812 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2813--- PASS: TestExternalSignerWrongPublicKey (0.01s)2814--- PASS: TestExternalSignerClose (0.03s)2815--- PASS: TestExternalSignerCancellation (0.03s)2816--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.03s)2817--- PASS: TestExternalSigner (0.03s)2818--- PASS: TestExternalSignerErrors (0.00s)2819 --- PASS: TestExternalSignerErrors/null (0.01s)2820 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2821 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2822 --- PASS: TestExternalSignerErrors/exit_at_startup (0.02s)2823 --- PASS: TestExternalSignerErrors/wrong_shape (0.02s)2824 --- PASS: TestExternalSignerErrors/invalid_JSON (0.02s)2825 --- PASS: TestExternalSignerErrors/exit_on_request (0.02s)2826 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.02s)2827 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.02s)2828 --- PASS: TestExternalSignerErrors/unrequested_key (0.02s)2829 --- PASS: TestExternalSignerErrors/too_few_signatures (0.03s)2830 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.03s)2831 --- PASS: TestExternalSignerErrors/null_signatures (0.03s)2832 --- PASS: TestExternalSignerErrors/missing_signature_name (0.03s)2833 --- PASS: TestExternalSignerErrors/program_error (0.03s)2834 --- PASS: TestExternalSignerErrors/wrong_id (0.03s)2835--- PASS: TestExternalSignerRestartsAfterCrash (0.03s)2836PASS2837Running OpenBao signer tests...2838=== RUN TestSign2839=== PAUSE TestSign2840=== RUN TestSignErrors2841=== PAUSE TestSignErrors2842=== RUN TestServe2843=== PAUSE TestServe2844=== RUN TestServeRejectsGarbage2845=== PAUSE TestServeRejectsGarbage2846=== CONT TestSign2847=== CONT TestServe2848--- PASS: TestServe (0.00s)2849=== CONT TestSignErrors2850=== RUN TestSignErrors/http_error2851=== PAUSE TestSignErrors/http_error2852=== RUN TestSignErrors/invalid_json2853=== PAUSE TestSignErrors/invalid_json2854=== RUN TestSignErrors/no_prefix2855=== PAUSE TestSignErrors/no_prefix2856=== RUN TestSignErrors/invalid_base642857=== PAUSE TestSignErrors/invalid_base642858=== CONT TestSignErrors/http_error2859=== CONT TestSignErrors/invalid_base642860=== CONT TestSignErrors/no_prefix2861=== CONT TestSignErrors/invalid_json2862=== CONT TestServeRejectsGarbage2863--- PASS: TestServeRejectsGarbage (0.00s)2864--- PASS: TestSign (5.79s)2865--- PASS: TestSignErrors (0.00s)2866 --- PASS: TestSignErrors/no_prefix (5.78s)2867 --- PASS: TestSignErrors/invalid_json (5.78s)2868 --- PASS: TestSignErrors/invalid_base64 (5.78s)2869 --- PASS: TestSignErrors/http_error (5.78s)2870PASS