niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #485
· 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.12s)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=== CONT TestScriptTokenScriptFails116=== CONT TestDoWithRetry_BodyReplayedViaGetBody117=== CONT TestScriptTokenBadJSON118=== CONT TestScriptTokenEmptyToken119--- PASS: TestScriptTokenEmptyCommand (0.00s)120=== CONT TestScriptTokenNoExpiryRerunsEveryCall121=== CONT TestScriptTokenCachesUntilRefresh122=== CONT TestFileTokenMissing1232026/11/11 23:01:31 WARN Rate limiter enabled after throttle name=server-test rate=5124=== CONT TestFileTokenReadsAndCaches125=== CONT TestStaticToken126=== CONT TestSetClientTLSErrors127=== CONT TestSetClientTLSDoesNotMutateDefaultTransport128=== CONT TestSetClientTLS129=== CONT TestEncodeNixBase32130=== CONT TestResolveStorePath131=== CONT TestRegisterUploadedObject_OutlivesPush132=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer133=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess134=== CONT TestRateLimiterFeedback135=== CONT TestPathInfoCACompatibility136=== CONT TestParsePathInfoJSONMultiplePaths137=== CONT TestParsePathInfoJSON138=== CONT TestStreamPushStopsWhenCanceled139=== CONT TestFileTokenEmpty140--- PASS: TestScriptTokenScriptFails (0.04s)141--- PASS: TestScriptTokenBadJSON (0.04s)142--- PASS: TestScriptTokenEmptyToken (0.04s)143--- PASS: TestFileTokenMissing (0.03s)144=== CONT TestPathInfoHashCompatibility145=== CONT TestGetStorePathHash146=== RUN TestGetStorePathHash/valid_store_path147=== CONT TestConvertHashToNix32148=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)149=== RUN TestConvertHashToNix32/SRI_format_to_Nix32150=== CONT TestEncodeNixBase32WithRealHash1512026/11/11 23:01:31 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:40521152--- PASS: TestEncodeNixBase32WithRealHash (0.00s)153=== CONT TestUploadMultipart_PartsInParallel154--- PASS: TestStaticToken (0.00s)155=== CONT TestDumpPathWriterError156=== RUN TestEncodeNixBase32/test_string_hash157=== PAUSE TestEncodeNixBase32/test_string_hash158=== RUN TestEncodeNixBase32/empty_input159=== PAUSE TestEncodeNixBase32/empty_input1602026/11/11 23:01:31 WARN Rate limiter enabled after throttle name=server-test rate=5161--- PASS: TestStreamPushStopsWhenCanceled (0.00s)162--- PASS: TestFileTokenReadsAndCaches (0.01s)163=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32164=== CONT TestDumpPathSingleFile1652026/11/11 23:01:31 WARN Rate limiter backed off name=server-test rate=51662026/11/11 23:01:31 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:40521167=== RUN TestRateLimiterFeedback/429_enables_limiter168=== RUN TestPathInfoCACompatibility/null_ca_field169=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths170=== RUN TestParsePathInfoJSON/Nix_format171=== PAUSE TestRateLimiterFeedback/429_enables_limiter172=== PAUSE TestPathInfoCACompatibility/null_ca_field173=== RUN TestPathInfoCACompatibility/old_string_format_-_text174=== RUN TestConvertHashToNix32/already_Nix32_format175=== PAUSE TestConvertHashToNix32/already_Nix32_format176=== RUN TestConvertHashToNix32/invalid_format177=== PAUSE TestConvertHashToNix32/invalid_format178=== CONT TestUploadMultipart_ReturnsAfterDroppedBody179=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths180=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths181=== PAUSE TestParsePathInfoJSON/Nix_format182=== RUN TestParsePathInfoJSON/Lix_format183=== PAUSE TestParsePathInfoJSON/Lix_format184=== RUN TestParsePathInfoJSON/empty_input185=== PAUSE TestParsePathInfoJSON/empty_input186=== RUN TestParsePathInfoJSON/whitespace_only187=== PAUSE TestParsePathInfoJSON/whitespace_only188=== RUN TestParsePathInfoJSON/invalid_JSON189=== PAUSE TestParsePathInfoJSON/invalid_JSON190=== RUN TestRateLimiterFeedback/503_enables_limiter191=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun192--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.09s)193=== CONT TestFilterOversizedClosures194=== PAUSE TestGetStorePathHash/valid_store_path195--- PASS: TestFileTokenEmpty (0.00s)196=== CONT TestCaseHackSuffix1972026/11/11 23:01:31 INFO Garbage collection started198--- PASS: TestResolveStorePath (0.00s)199=== CONT TestStreamPushIsolatesFailures200=== PAUSE TestRateLimiterFeedback/503_enables_limiter201=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths202=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)203=== CONT TestClientSignaturesByStorePath204--- PASS: TestClientSignaturesByStorePath (0.00s)205=== CONT TestStreamPushReportsSignatures206--- PASS: TestRegisterUploadedObject_OutlivesPush (0.04s)207=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text208=== CONT TestDumpPathMatchesNix209=== RUN TestGetStorePathHash/basename_without_hyphen_should_error210=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error211=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error212=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error213=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error214=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error215=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter216=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter217=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter218=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter219=== CONT TestStreamPushRequestLine220=== RUN TestFilterOversizedClosures/no_limit_keeps_everything221=== CONT TestStreamPushReportsSkippedPaths222=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon223=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon224=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI225=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI226=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512227=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512228=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive229=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive230=== RUN TestPathInfoCACompatibility/new_structured_format_-_text231=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text232=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method233=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method234=== CONT TestShellSplitErrors235--- PASS: TestShellSplitErrors (0.00s)236=== CONT TestStreamPushReportsEveryPath237=== CONT TestStreamPushBatchesUnderLoad238=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false239=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false240=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true241=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true242=== CONT TestRegisterUploadedObjectReusesConnections2432026/11/11 23:01:31 ERROR Upload failed error="bad path" count=3244=== CONT TestStreamPushGivesUpOnDeadServer2452026/11/11 23:01:31 ERROR Upload failed error="connection refused" count=202462026/11/11 23:01:31 ERROR Server seems unavailable, giving up on batch untried=172472026/11/11 23:01:31 ERROR Upload failed error=boom count=1248--- PASS: TestStreamPushReportsSignatures (0.01s)249=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica250--- PASS: TestStreamPushReportsEveryPath (0.01s)251=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry252=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything253=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped254=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped255=== RUN TestFilterOversizedClosures/all_closures_skipped256=== PAUSE TestFilterOversizedClosures/all_closures_skipped257=== CONT TestDoWithRetry_FinalResponseBodyReadable2582026/11/11 23:01:31 ERROR Upload failed error=boom count=1259=== RUN TestSetClientTLSErrors/missing_cert_file260=== PAUSE TestSetClientTLSErrors/missing_cert_file261=== RUN TestSetClientTLSErrors/missing_key_file2622026/11/11 23:01:31 INFO Garbage collection started2632026/11/11 23:01:31 WARN Rate limiter enabled after throttle name=server-test rate=5264=== PAUSE TestSetClientTLSErrors/missing_key_file2652026/11/11 23:01:31 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:36567266=== RUN TestSetClientTLSErrors/missing_ca_file267=== PAUSE TestSetClientTLSErrors/missing_ca_file268=== RUN TestSetClientTLSErrors/invalid_ca_file269=== CONT TestEncodeNixBase32/empty_input270=== CONT TestConvertHashToNix32/SRI_format_to_Nix32271=== RUN TestSetClientTLS/rejects_connection_without_client_cert272=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert273=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA274=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA275=== RUN TestSetClientTLS/preserves_debug_logging_transport276=== PAUSE TestSetClientTLS/preserves_debug_logging_transport277=== CONT TestParsePathInfoJSON/Nix_format278=== CONT TestConvertHashToNix32/invalid_format279=== CONT TestParsePathInfoJSON/whitespace_only280=== CONT TestParsePathInfoJSON/empty_input281=== CONT TestParsePathInfoJSON/Lix_format282=== CONT TestParsePathInfoJSON/invalid_JSON283=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths284=== CONT TestGetStorePathHash/valid_store_path2852026/11/11 23:01:31 WARN Rate limiter backed off name=server-test rate=5286=== CONT TestRateLimiterFeedback/429_enables_limiter287=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error288=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error289=== CONT TestGetStorePathHash/basename_without_hyphen_should_error290=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)291=== CONT TestPathInfoCACompatibility/null_ca_field292=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512293=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI294=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon295=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false296=== PAUSE TestSetClientTLSErrors/invalid_ca_file297=== CONT TestConvertHashToNix32/already_Nix32_format298=== CONT TestPathInfoCACompatibility/new_structured_format_-_text299=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive300=== CONT TestPathInfoCACompatibility/old_string_format_-_text301=== CONT TestRateLimiterFeedback/503_enables_limiter3022026/11/11 23:01:31 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=0303=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method304=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter3052026/11/11 23:01:31 WARN Rate limiter enabled after throttle name=server-test rate=5306=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths3072026/11/11 23:01:31 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:33297308=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter309=== CONT TestRetryTimeoutOutlastsMaxRetries3102026/11/11 23:01:33 WARN Garbage collection finished on another replica. Its statistics are not available here311=== CONT TestFilterOversizedClosures/no_limit_keeps_everything312=== CONT TestFilterOversizedClosures/all_closures_skipped313=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3142026/11/11 23:01:33 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=2000315=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true316=== CONT TestSetClientTLS/rejects_connection_without_client_cert317=== CONT TestEncodeNixBase32/test_string_hash318=== CONT TestSetClientTLS/preserves_debug_logging_transport3192026/11/11 23:01:34 WARN Rate limiter enabled after throttle name=server-test rate=5320--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.02s)3212026/11/11 23:01:34 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:34663322--- PASS: TestUploadMultipart_ReturnsAfterDroppedBody (0.02s)323--- PASS: TestStreamPushIsolatesFailures (0.02s)324--- PASS: TestStreamPushReportsSkippedPaths (0.02s)325=== CONT TestShellSplit326=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA3272026/11/11 23:01:33 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50328--- PASS: TestShellSplit (0.00s)329=== CONT TestSetClientTLSErrors/invalid_ca_file3302026/11/11 23:01:34 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:33387/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:33387/api/uploads/complete3312026/11/11 23:01:34 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"3322026/11/11 23:01:34 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:33387/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:33387/api/uploads/complete3332026/11/11 23:01:34 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"334--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)335=== CONT TestSetClientTLSErrors/missing_cert_file336=== CONT TestSetClientTLSErrors/missing_key_file337--- PASS: TestParsePathInfoJSON (0.00s)338 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)339 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)340 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)341 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)342 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)343--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.01s)344--- PASS: TestGetStorePathHash (0.05s)345 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)346 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)347 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)348 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)349=== CONT TestSetClientTLSErrors/missing_ca_file3502026/11/11 23:01:34 WARN Rate limiter backed off name=server-test rate=5351--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (2.48s)352=== CONT TestPartSizeForNAR353=== RUN TestPartSizeForNAR/zero_stays_at_minimum354=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum355=== RUN TestPartSizeForNAR/small_stays_at_minimum356=== PAUSE TestPartSizeForNAR/small_stays_at_minimum357=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum358=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum3592026/11/11 23:01:34 WARN Rate limiter backed off name=server-test rate=5360=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts361=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts362=== RUN TestPartSizeForNAR/1_TiB363=== PAUSE TestPartSizeForNAR/1_TiB364=== RUN TestPartSizeForNAR/5_TiB_S3_max_object365=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object366=== RUN TestPartSizeForNAR/capped_at_5_GiB367=== PAUSE TestPartSizeForNAR/capped_at_5_GiB368=== CONT TestPartSizeForNAR/zero_stays_at_minimum369=== CONT TestPartSizeForNAR/capped_at_5_GiB370=== CONT TestPartSizeForNAR/5_TiB_S3_max_object371=== CONT TestPartSizeForNAR/1_TiB372=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts373=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum374=== CONT TestPartSizeForNAR/small_stays_at_minimum3752026/11/11 23:01:34 WARN Rate limiter enabled after throttle name=s3-test rate=53762026/11/11 23:01:34 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:444853772026/11/11 23:01:34 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:412393782026/11/11 23:01:34 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:33387/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:33387/api/uploads/complete3792026/11/11 23:01:34 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"380--- PASS: TestPathInfoHashCompatibility (0.05s)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)385--- PASS: TestFilterOversizedClosures (0.02s)386 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)387 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)388 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)389--- PASS: TestDoServerRequestAttachesToken (2.62s)390--- PASS: TestPathInfoCACompatibility (0.01s)391 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)392 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)393 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)394 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)395 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)396--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)397 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)398 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)399--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (2.61s)400--- PASS: TestStreamPushBatchesUnderLoad (0.00s)401 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (2.47s)402 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)403--- PASS: TestScriptTokenCachesUntilRefresh (2.61s)404--- PASS: TestRateLimiterFeedback (0.00s)405 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (2.47s)406 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (2.47s)407 --- PASS: TestRateLimiterFeedback/503_enables_limiter (2.50s)408 --- PASS: TestRateLimiterFeedback/429_enables_limiter (2.50s)409--- PASS: TestPartSizeForNAR (0.01s)410 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)411 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)412 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)413 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)414 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)415 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)416 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)417--- PASS: TestSetClientTLSErrors (0.07s)418 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)419 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)420 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.02s)421 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.02s)422--- PASS: TestConvertHashToNix32 (0.05s)423 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)424 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)425 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)426--- PASS: TestDumpPathSingleFile (2.52s)427--- PASS: TestEncodeNixBase32 (0.01s)428 --- PASS: TestEncodeNixBase32/empty_input (0.00s)429 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)430--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (2.56s)431--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (2.51s)432--- PASS: TestCaseHackSuffix (2.53s)433--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (2.57s)434--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (2.53s)4352026/11/11 23:01:34 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:412394362026/11/11 23:01:34 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:412394372026/11/11 23:01:34 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:412394382026/11/11 23:01:34 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:412394392026/11/11 23:01:34 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:412394402026/11/11 23:01:34 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:412394412026/11/11 23:01:34 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:412394422026/11/11 23:01:34 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:412394432026/11/11 23:01:34 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:412394442026/11/11 23:01:34 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:412394452026/11/11 23:01:34 http: TLS handshake error from 127.0.0.1:44582: remote error: tls: bad certificate446--- PASS: TestSetClientTLS (0.07s)447 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.04s)448 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.04s)449 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.05s)4502026/11/11 23:01:34 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:41239451--- PASS: TestStreamPushRequestLine (2.54s)4522026/11/11 23:01:34 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:412394532026/11/11 23:01:34 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:41239454--- PASS: TestDumpPathWriterError (2.59s)455--- PASS: TestRegisterUploadedObjectReusesConnections (2.54s)4562026/11/11 23:01:34 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:412394572026/11/11 23:01:34 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:412394582026/11/11 23:01:34 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:412394592026/11/11 23:01:34 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:412394602026/11/11 23:01:34 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:41239461--- PASS: TestRetryTimeoutOutlastsMaxRetries (2.53s)462--- PASS: TestDumpPathMatchesNix (2.64s)463--- PASS: TestUploadMultipart_PartsInParallel (3.18s)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/postgres2805803424/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/postgres2805803424/data -l logfile start492493/build/postgres2805803424:5432 - no response494/build/postgres2805803424:5432 - no response495/build/postgres2805803424:5432 - no response496/build/postgres2805803424:5432 - no response497/build/postgres2805803424:5432 - no response498/build/postgres2805803424:5432 - no response499/build/postgres2805803424:5432 - no response500/build/postgres2805803424:5432 - no response501/build/postgres2805803424:5432 - no response502/build/postgres2805803424:5432 - no response503/build/postgres2805803424:5432 - no response504/build/postgres2805803424:5432 - no response505/build/postgres2805803424:5432 - no response5062026-11-11 23:01:49.521 UTC [130] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit5072026-11-11 23:01:49.521 UTC [130] LOG: listening on Unix socket "/build/postgres2805803424/.s.PGSQL.5432"5082026-11-11 23:01:49.530 UTC [149] LOG: database system was shut down at 2026-11-11 23:01:48 UTC5092026-11-11 23:01:49.536 UTC [130] LOG: database system is ready to accept connections510/build/postgres2805803424:5432 - accepting connections511{"timestamp":"2026-11-11T23:01:59.913043051Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"fea5c207-a48d-4a83-9881-c04c6d9ac7c2","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":6,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(202)"}512{"timestamp":"2026-11-11T23:02:00.028081633Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"b6070f73-0443-4a22-9751-935e63a05457","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(205)"}513=== RUN TestAbortSucceeded514=== PAUSE TestAbortSucceeded515=== RUN TestService_AuthMiddleware516=== PAUSE TestService_AuthMiddleware517=== RUN TestService_AuthMiddleware_MTLSProxyHeader518=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader519=== RUN TestService_AuthMiddleware_MTLSBoundSubjects520=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects521=== RUN TestService_ReadAuthMiddleware522=== PAUSE TestService_ReadAuthMiddleware523=== RUN TestService_AuthMiddleware_OIDC524=== PAUSE TestService_AuthMiddleware_OIDC525=== RUN TestService_RequireScope_OIDC526=== PAUSE TestService_RequireScope_OIDC527=== RUN TestService_ReadScope_PublicByDefault528=== PAUSE TestService_ReadScope_PublicByDefault529=== RUN TestCacheConfigHandler530=== PAUSE TestCacheConfigHandler531=== RUN TestCacheStatsHandler532=== PAUSE TestCacheStatsHandler533=== RUN TestClientCADerivations534=== PAUSE TestClientCADerivations535=== RUN TestClientErrorHandling536=== PAUSE TestClientErrorHandling537=== RUN TestClientIntegration538=== PAUSE TestClientIntegration539=== RUN TestClientMultipleUploads540=== PAUSE TestClientMultipleUploads541=== RUN TestClientWithDependencies542=== PAUSE TestClientWithDependencies543=== RUN TestClientSharedPathCommittedMidPush544=== PAUSE TestClientSharedPathCommittedMidPush545=== RUN TestPinProtectsFromGC546=== PAUSE TestPinProtectsFromGC547=== RUN TestClientPushesUseOnePush548=== PAUSE TestClientPushesUseOnePush549=== RUN TestClientFallsBackToClosures550=== PAUSE TestClientFallsBackToClosures551=== RUN TestDeleteClosuresRacingPins552=== PAUSE TestDeleteClosuresRacingPins553=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock554=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock555=== RUN TestResolveDBConnectionString556=== PAUSE TestResolveDBConnectionString557=== RUN TestConnectWaitsForAPeerMigration558=== PAUSE TestConnectWaitsForAPeerMigration559=== RUN TestLeadElectsOneAndHandsOver560=== PAUSE TestLeadElectsOneAndHandsOver561=== RUN TestLeadIncumbentWinsAfterRestart5622026/11/11 23:02:02 INFO lead: acquired remote=192.0.2.1:1234 generation=15632026/11/11 23:02:03 INFO lead: released remote=192.0.2.1:1234 generation=15642026/11/11 23:02:03 INFO lead: acquired remote=192.0.2.1:1234 generation=25652026/11/11 23:02:04 INFO lead: released remote=192.0.2.1:1234 generation=2566--- PASS: TestLeadIncumbentWinsAfterRestart (3.85s)567=== RUN TestLeadUnannouncedStandbyYieldsToIncumbent568=== PAUSE TestLeadUnannouncedStandbyYieldsToIncumbent569=== RUN TestLeadIncumbentAnnouncesAtOnce570=== PAUSE TestLeadIncumbentAnnouncesAtOnce571=== RUN TestLeadGenerationGrowsWithEveryGrant572=== PAUSE TestLeadGenerationGrowsWithEveryGrant573=== RUN TestLeadEndsOnShutdown574=== PAUSE TestLeadEndsOnShutdown575=== RUN TestLeadEndsWhenItsConnectionHangs5762026/11/11 23:02:05 INFO lead: acquired remote=192.0.2.1:1234 generation=15772026-11-11 23:02:06.487 UTC [399] FATAL: terminating connection due to administrator command5782026/11/11 23:02:06 INFO lead: acquired remote=192.0.2.1:1234 generation=25792026/11/11 23:02:07 WARN lead: lock connection lost error="timeout: context deadline exceeded"5802026/11/11 23:02:07 INFO lead: released remote=192.0.2.1:1234 generation=15812026/11/11 23:02:08 INFO lead: released remote=192.0.2.1:1234 generation=2582--- PASS: TestLeadEndsWhenItsConnectionHangs (3.65s)583=== RUN TestGCAdvisoryLockBlocksConcurrentRun584=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun585=== RUN TestGCBugBareHashReferences586=== PAUSE TestGCBugBareHashReferences587=== RUN TestGCMetrics588=== PAUSE TestGCMetrics589=== RUN TestPushDedupSurvivesConcurrentGC590=== PAUSE TestPushDedupSurvivesConcurrentGC591=== RUN TestDeduplicatedObjectsRecordedAsPending592=== PAUSE TestDeduplicatedObjectsRecordedAsPending593=== RUN TestGCSweepSkipsPendingObjects594=== PAUSE TestGCSweepSkipsPendingObjects595=== RUN TestTombstonedObjectOfferedWithoutWaiting596=== PAUSE TestTombstonedObjectOfferedWithoutWaiting597=== RUN TestGCSweepDeliversEachKeyOnce598=== PAUSE TestGCSweepDeliversEachKeyOnce599=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection600=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection601=== RUN TestForceGCDuringPushOffersSweptObject602=== PAUSE TestForceGCDuringPushOffersSweptObject603=== RUN TestFailedS3DeleteKeepsTombstone604=== PAUSE TestFailedS3DeleteKeepsTombstone605=== RUN TestSweepSkipsRowsLockedByPush606=== PAUSE TestSweepSkipsRowsLockedByPush607=== RUN TestRegisterCompletedObjectNeedsPendingRow608=== PAUSE TestRegisterCompletedObjectNeedsPendingRow609=== RUN TestGetExistingObjectsLocksRows610=== PAUSE TestGetExistingObjectsLocksRows611=== RUN TestSweepRechecksPendingAfterLocking612=== PAUSE TestSweepRechecksPendingAfterLocking613=== RUN TestPushWaitsForSweepHoldingRow614=== PAUSE TestPushWaitsForSweepHoldingRow615=== RUN TestCommitRacingPendingCleanupKeepsObjects616=== PAUSE TestCommitRacingPendingCleanupKeepsObjects617=== RUN TestGCEndsOnShutdown618=== PAUSE TestGCEndsOnShutdown619=== RUN TestGCTaskStore_StartNew620=== PAUSE TestGCTaskStore_StartNew621=== RUN TestGCTaskStore_DeduplicateSameParams622=== PAUSE TestGCTaskStore_DeduplicateSameParams623=== RUN TestGCTaskStore_ConflictDifferentParams624=== PAUSE TestGCTaskStore_ConflictDifferentParams625=== RUN TestGCTaskStore_GetEmpty626=== PAUSE TestGCTaskStore_GetEmpty627=== RUN TestGCTaskStore_GetReturnsLatest628=== PAUSE TestGCTaskStore_GetReturnsLatest629=== RUN TestGCTaskStore_CompletedAllowsNewTask630=== PAUSE TestGCTaskStore_CompletedAllowsNewTask631=== RUN TestGCTaskStore_PhaseUpdates632=== PAUSE TestGCTaskStore_PhaseUpdates633=== RUN TestGCTaskStore_Fail634=== PAUSE TestGCTaskStore_Fail635=== RUN TestGracefulShutdownDrainsInflight636=== PAUSE TestGracefulShutdownDrainsInflight637=== RUN TestService_healthCheckHandler638=== PAUSE TestService_healthCheckHandler639=== RUN TestService_readinessHandler640=== PAUSE TestService_readinessHandler641=== RUN TestGenerateLandingPage642=== PAUSE TestGenerateLandingPage643=== RUN TestEnsureAbortUploadsRule644=== PAUSE TestEnsureAbortUploadsRule645=== RUN TestCacheConfigHandlerMaxNarSize646=== PAUSE TestCacheConfigHandlerMaxNarSize647=== RUN TestCreatePendingClosureRejectsOversizedNAR648=== PAUSE TestCreatePendingClosureRejectsOversizedNAR649=== RUN TestNARDeduplicationMetadataUploadBug650=== PAUSE TestNARDeduplicationMetadataUploadBug651=== RUN TestMetricsInventory652=== PAUSE TestMetricsInventory653=== RUN TestMetricsCommit654=== PAUSE TestMetricsCommit655=== RUN TestService_NativeMTLS656=== PAUSE TestService_NativeMTLS657=== RUN TestServerTLSConfig658=== PAUSE TestServerTLSConfig659=== RUN TestMultipartCleanup660=== PAUSE TestMultipartCleanup661=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded662=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded663=== RUN TestPendingCleanupUsesOneCutoff664=== PAUSE TestPendingCleanupUsesOneCutoff665=== RUN TestObjectStatsTrigger666=== PAUSE TestObjectStatsTrigger667=== RUN TestObjectStatsUpdatedOncePerCommit668=== PAUSE TestObjectStatsUpdatedOncePerCommit669=== RUN TestOrphanedObjectsGC670=== PAUSE TestOrphanedObjectsGC671=== RUN TestOrphanedObjectsGCStressTest672=== PAUSE TestOrphanedObjectsGCStressTest673=== RUN TestCreatePin_ReservedPins674=== PAUSE TestCreatePin_ReservedPins675=== RUN TestPresentReportsOnlyClosureRoots676=== PAUSE TestPresentReportsOnlyClosureRoots677=== RUN TestPresentRefreshesOnlyStaleClosures678=== PAUSE TestPresentRefreshesOnlyStaleClosures679=== RUN TestPresentNotReportedWhileGCDeletesClosure680=== PAUSE TestPresentNotReportedWhileGCDeletesClosure681=== RUN TestParseSingleRange682=== PAUSE TestParseSingleRange683=== RUN TestProxyHeadersOnlyTrustedOnSocket6842026/11/11 23:02:08 INFO Starting HTTP server address=127.0.0.1:459856852026/11/11 23:02:08 INFO Starting HTTP server address=proxy.sock6862026/11/11 23:02:08 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6872026/11/11 23:02:08 INFO Shutdown signal received, draining in-flight requests timeout=10s688--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.51s)689=== RUN TestIsValidCachePath690=== PAUSE TestIsValidCachePath691=== RUN TestReadProxyNarinfo692=== PAUSE TestReadProxyNarinfo693=== RUN TestReadProxyNarinfoAlreadyDecompressed694=== PAUSE TestReadProxyNarinfoAlreadyDecompressed695=== RUN TestReadProxyContentNegotiation696=== PAUSE TestReadProxyContentNegotiation697=== RUN TestReadProxyNarStreaming698=== PAUSE TestReadProxyNarStreaming699=== RUN TestReadProxy404700=== PAUSE TestReadProxy404701=== RUN TestReadProxyInvalidPath702=== PAUSE TestReadProxyInvalidPath703=== RUN TestReadProxyHead704=== PAUSE TestReadProxyHead705=== RUN TestReadProxyOutlastsServerWriteTimeout706=== PAUSE TestReadProxyOutlastsServerWriteTimeout707=== RUN TestReadProxyConditionalGet708=== PAUSE TestReadProxyConditionalGet709=== RUN TestReadProxyRootRedirectsToIndexHTML710=== PAUSE TestReadProxyRootRedirectsToIndexHTML711=== RUN TestReadProxyDisabled712=== PAUSE TestReadProxyDisabled713=== RUN TestReadRedirectNar714=== PAUSE TestReadRedirectNar715=== RUN TestReadRedirectKeepsNarinfoProxied716=== PAUSE TestReadRedirectKeepsNarinfoProxied717=== RUN TestReadProxyRangeRequest718=== PAUSE TestReadProxyRangeRequest719=== RUN TestReadRedirectUsesPublicS3URL720=== PAUSE TestReadRedirectUsesPublicS3URL721=== RUN TestPush_OverlappingRootsStoreOneRowPerKey722=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey723=== RUN TestPush_CompleteCommitsEveryRoot724=== PAUSE TestPush_CompleteCommitsEveryRoot725=== RUN TestPush_RepeatedRootCommitsOnce726=== PAUSE TestPush_RepeatedRootCommitsOnce727=== RUN TestPush_CompleteWaitsForCleanupOfThePush728=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush729=== RUN TestPush_RootsAreLockedInByteOrder730=== PAUSE TestPush_RootsAreLockedInByteOrder731=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit732=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit733=== RUN TestPush_RejectsBadRequests734=== PAUSE TestPush_RejectsBadRequests735=== RUN TestPush_SignsNarinfosOfItsPendingObjects736=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects737=== RUN TestSharedNarBothUploadsComplete738=== PAUSE TestSharedNarBothUploadsComplete739=== RUN TestCompleteMultipartUpload_ErrorButObjectExists740=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists741=== RUN TestCompletedNarNotReofferedAcrossClosures742=== PAUSE TestCompletedNarNotReofferedAcrossClosures743=== RUN TestPresignedUploadRegisteredBeforeCommit744=== PAUSE TestPresignedUploadRegisteredBeforeCommit745=== RUN TestService_Rustfstest746=== PAUSE TestService_Rustfstest747=== RUN TestParseSize748=== PAUSE TestParseSize749=== RUN TestSkippedUploadsHandler750=== PAUSE TestSkippedUploadsHandler751=== RUN TestSystemdListenerNotActivated752--- PASS: TestSystemdListenerNotActivated (0.00s)753=== RUN TestWatchdogBeatsWhenHealthy754--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)755=== RUN TestWatchdogSkipsWhenUnhealthy7562026/11/11 23:02:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7572026/11/11 23:02:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7582026/11/11 23:02:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7592026/11/11 23:02:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7602026/11/11 23:02:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7612026/11/11 23:02:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7622026/11/11 23:02:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7632026/11/11 23:02:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7642026/11/11 23:02:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7652026/11/11 23:02:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"766--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)767=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle768=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle769=== RUN TestProxyWriteTimeout770=== PAUSE TestProxyWriteTimeout771=== RUN TestPendingClosureWriteTimeout772=== PAUSE TestPendingClosureWriteTimeout773=== RUN TestIsValidUploadKey774=== PAUSE TestIsValidUploadKey775=== RUN TestUploadHandlersRejectInvalidKeys776=== PAUSE TestUploadHandlersRejectInvalidKeys777=== RUN TestUploadHandlersRejectOversizedBody778=== PAUSE TestUploadHandlersRejectOversizedBody779=== RUN TestService_cleanupPendingClosuresHandler780=== PAUSE TestService_cleanupPendingClosuresHandler781=== RUN TestService_createPendingClosureHandler782=== PAUSE TestService_createPendingClosureHandler783=== RUN TestService_verifyS3Integrity784=== PAUSE TestService_verifyS3Integrity785=== RUN TestService_verifyS3ReuploadsStaleNarinfo786=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo787=== RUN TestCompleteMultipartUnregistered788=== PAUSE TestCompleteMultipartUnregistered789=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT790=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT791=== CONT TestIsValidUploadKey792=== CONT TestAbortSucceeded793=== CONT TestPendingClosureWriteTimeout794=== RUN TestPendingClosureWriteTimeout/empty795=== CONT TestProxyWriteTimeout796=== RUN TestProxyWriteTimeout/narinfo797=== PAUSE TestProxyWriteTimeout/narinfo798=== RUN TestProxyWriteTimeout/1_GiB_nar799=== PAUSE TestProxyWriteTimeout/1_GiB_nar800=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle801=== CONT TestSkippedUploadsHandler802=== CONT TestParseSize803=== CONT TestService_verifyS3Integrity804=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT805=== CONT TestCompleteMultipartUnregistered806=== CONT TestService_verifyS3ReuploadsStaleNarinfo807=== CONT TestService_Rustfstest808=== CONT TestService_cleanupPendingClosuresHandler809=== CONT TestPresignedUploadRegisteredBeforeCommit810=== CONT TestService_createPendingClosureHandler811=== CONT TestCompletedNarNotReofferedAcrossClosures812=== CONT TestCompleteMultipartUpload_ErrorButObjectExists813=== CONT TestLeadGenerationGrowsWithEveryGrant814=== CONT TestLeadIncumbentAnnouncesAtOnce815=== CONT TestGCTaskStore_CompletedAllowsNewTask816=== CONT TestLeadUnannouncedStandbyYieldsToIncumbent817=== CONT TestGCTaskStore_GetReturnsLatest818=== CONT TestLeadElectsOneAndHandsOver819=== CONT TestGCTaskStore_GetEmpty820=== RUN TestIsValidUploadKey/narinfo821=== PAUSE TestIsValidUploadKey/narinfo822=== RUN TestIsValidUploadKey/nar_zst823=== PAUSE TestIsValidUploadKey/nar_zst824=== RUN TestIsValidUploadKey/nar_xz825=== PAUSE TestIsValidUploadKey/nar_xz826=== RUN TestIsValidUploadKey/nar_plain827=== PAUSE TestIsValidUploadKey/nar_plain828=== RUN TestIsValidUploadKey/listing829=== PAUSE TestIsValidUploadKey/listing830=== RUN TestIsValidUploadKey/build_log831=== PAUSE TestIsValidUploadKey/build_log832=== RUN TestIsValidUploadKey/build_log_home-manager_file833=== PAUSE TestIsValidUploadKey/build_log_home-manager_file834=== RUN TestIsValidUploadKey/build_log_plus_in_name835=== PAUSE TestIsValidUploadKey/build_log_plus_in_name836=== RUN TestIsValidUploadKey/build_log_question_mark837=== PAUSE TestIsValidUploadKey/build_log_question_mark838=== RUN TestIsValidUploadKey/build_log_equals839=== PAUSE TestIsValidUploadKey/build_log_equals840=== RUN TestIsValidUploadKey/realisation841=== PAUSE TestIsValidUploadKey/realisation842=== RUN TestIsValidUploadKey/realisation_plus_in_output843=== PAUSE TestIsValidUploadKey/realisation_plus_in_output844=== RUN TestIsValidUploadKey/nix-cache-info845=== PAUSE TestIsValidUploadKey/nix-cache-info846=== RUN TestIsValidUploadKey/index.html847=== PAUSE TestIsValidUploadKey/index.html848=== RUN TestIsValidUploadKey/narinfo_key,_nar_type849=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type850=== RUN TestIsValidUploadKey/nar_key,_narinfo_type851=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type852=== RUN TestIsValidUploadKey/listing_key,_narinfo_type853=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type854=== RUN TestIsValidUploadKey/traversal855=== PAUSE TestIsValidUploadKey/traversal856=== RUN TestIsValidUploadKey/traversal_nar857=== PAUSE TestIsValidUploadKey/traversal_nar858=== RUN TestIsValidUploadKey/absolute859=== PAUSE TestIsValidUploadKey/absolute860=== RUN TestIsValidUploadKey/empty_key861=== PAUSE TestIsValidUploadKey/empty_key862=== RUN TestIsValidUploadKey/unknown_type863=== PAUSE TestIsValidUploadKey/unknown_type864=== CONT TestGCTaskStore_DeduplicateSameParams865=== CONT TestGCTaskStore_PhaseUpdates866=== CONT TestGCTaskStore_StartNew867=== CONT TestSharedNarBothUploadsComplete8682026/11/11 23:02:08 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000869=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock870=== CONT TestGCEndsOnShutdown871=== RUN TestGCEndsOnShutdown/before_the_run872=== PAUSE TestGCEndsOnShutdown/before_the_run873=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete874=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete875=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark876=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark877=== CONT TestPush_SignsNarinfosOfItsPendingObjects878=== PAUSE TestPendingClosureWriteTimeout/empty879=== RUN TestPendingClosureWriteTimeout/400_objects880=== PAUSE TestPendingClosureWriteTimeout/400_objects881=== RUN TestPendingClosureWriteTimeout/670k_objects882=== PAUSE TestPendingClosureWriteTimeout/670k_objects883=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline884=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline885=== CONT TestCommitRacingPendingCleanupKeepsObjects886=== CONT TestGCTaskStore_ConflictDifferentParams887=== CONT TestClientFallsBackToClosures888=== RUN TestProxyWriteTimeout/10_GiB_nar889=== PAUSE TestProxyWriteTimeout/10_GiB_nar890=== RUN TestProxyWriteTimeout/unknown_size891=== PAUSE TestProxyWriteTimeout/unknown_size892=== CONT TestDeleteClosuresRacingPins893=== CONT TestConnectWaitsForAPeerMigration894=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed895=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed896=== RUN TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed897=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed898=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost899=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost900=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed901=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed902=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed903=== CONT TestPushWaitsForSweepHoldingRow904--- PASS: TestAbortSucceeded (0.00s)905=== CONT TestResolveDBConnectionString906=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed907=== CONT TestClientPushesUseOnePush908--- PASS: TestParseSize (0.00s)909--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)910--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)911--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)912--- PASS: TestGCTaskStore_StartNew (0.00s)913--- PASS: TestSkippedUploadsHandler (0.01s)914--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)915--- PASS: TestGCTaskStore_GetEmpty (0.00s)916--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)917=== RUN TestResolveDBConnectionString/flag_wins918=== PAUSE TestResolveDBConnectionString/flag_wins919=== RUN TestResolveDBConnectionString/file_when_flag_empty920=== PAUSE TestResolveDBConnectionString/file_when_flag_empty921=== RUN TestResolveDBConnectionString/missing_file_is_an_error922=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error923=== RUN TestResolveDBConnectionString/PGHOST_allows_empty924=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty925=== RUN TestResolveDBConnectionString/nothing_configured926=== PAUSE TestResolveDBConnectionString/nothing_configured927=== CONT TestSweepRechecksPendingAfterLocking9282026/11/11 23:02:12 INFO Received uploads request method=POST path=/api/pending_closures9292026/11/11 23:02:12 INFO Received cleanup request method=DELETE path=/api/pending_closures9302026/11/11 23:02:12 INFO Aborted multipart uploads count=0 kept=09312026/11/11 23:02:12 INFO Received uploads request method=POST path=/api/pending_closures9322026/11/11 23:02:12 INFO Received cleanup request method=DELETE path=/api/pending_closures933=== CONT TestPush_RejectsBadRequests934--- PASS: TestService_Rustfstest (3.54s)9352026/11/11 23:02:12 INFO Aborted multipart uploads count=1 kept=09362026/11/11 23:02:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9372026-11-11 23:02:12.374 UTC [439] ERROR: Closure does not exist: id=19382026-11-11 23:02:12.374 UTC [439] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9392026-11-11 23:02:12.374 UTC [439] STATEMENT: -- name: CommitPendingClosure :one940 SELECT commit_pending_closure($1::bigint)::bigint941 942--- PASS: TestService_cleanupPendingClosuresHandler (3.54s)943=== CONT TestPinProtectsFromGC9442026/11/11 23:02:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9452026/11/11 23:02:12 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst946--- PASS: TestCompleteMultipartUnregistered (3.56s)947=== CONT TestGetExistingObjectsLocksRows9482026/11/11 23:02:12 INFO Received uploads request method=POST path=/api/pending_closures9492026/11/11 23:02:12 INFO Received uploads request method=POST path=/api/pending_closures9502026/11/11 23:02:12 INFO Received uploads request method=POST path=/api/pending_closures9512026/11/11 23:02:12 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9522026/11/11 23:02:12 INFO Received uploads request method=POST path=/api/pending_closures953--- PASS: TestPresignedUploadRegisteredBeforeCommit (3.66s)954=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit955--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (3.66s)956=== CONT TestClientSharedPathCommittedMidPush9572026/11/11 23:02:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9582026/11/11 23:02:12 INFO Received uploads request method=POST path=/api/pending_closures9592026/11/11 23:02:12 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Njg5NWZiMjUtYjFmOS00MDgxLTkxOTgtNWJlMzliNDdmZmEyLjNmYTQ1YzFkLTI2MDMtNDYxZS04NTE5LWE0MTJmYTkwOGZkOHgxNzk0NDM4MTMyNDQxMzYwMTQ49602026/11/11 23:02:12 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Njg5NWZiMjUtYjFmOS00MDgxLTkxOTgtNWJlMzliNDdmZmEyLjNmYTQ1YzFkLTI2MDMtNDYxZS04NTE5LWE0MTJmYTkwOGZkOHgxNzk0NDM4MTMyNDQxMzYwMTQ4 parts=1961--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (3.68s)962=== CONT TestRegisterCompletedObjectNeedsPendingRow9632026/11/11 23:02:12 INFO lead: acquired remote=192.0.2.1:1234 generation=19642026/11/11 23:02:12 INFO Received uploads request method=POST path=/api/pending_closures9652026/11/11 23:02:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9662026/11/11 23:02:12 INFO Received uploads request method=POST path=/api/pending_closures9672026/11/11 23:02:12 INFO Aborted multipart uploads count=0 kept=09682026/11/11 23:02:12 INFO Received uploads request method=POST path=/api/pending_closures9692026/11/11 23:02:12 INFO lead: acquired remote=192.0.2.1:1234 generation=19702026/11/11 23:02:12 INFO lead: released remote=192.0.2.1:1234 generation=1971--- PASS: TestLeadIncumbentAnnouncesAtOnce (3.76s)972=== CONT TestPush_RootsAreLockedInByteOrder9732026/11/11 23:02:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9742026/11/11 23:02:12 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=Njg5NWZiMjUtYjFmOS00MDgxLTkxOTgtNWJlMzliNDdmZmEyLjU2NzJmMmZlLWM4MTEtNGE5Yi1hODkyLTUzNjlkODUwYmRiMHgxNzk0NDM4MTMyMzI2OTYzMTMz parts=109752026/11/11 23:02:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9762026/11/11 23:02:12 INFO lead: acquired remote=192.0.2.1:1234 generation=19772026/11/11 23:02:12 INFO Completed upload id=1 objects=2 duration=4.658325ms9782026/11/11 23:02:12 INFO Received uploads request method=POST path=/api/pending_closures9792026/11/11 23:02:12 INFO Received uploads request method=POST path=/api/pending_closures9802026/11/11 23:02:12 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9812026/11/11 23:02:12 WARN Found objects in DB but missing from S3, will re-upload count=1982--- PASS: TestService_verifyS3Integrity (4.00s)983=== CONT TestClientWithDependencies9842026/11/11 23:02:12 WARN Force mode enabled - objects will be deleted immediately without grace period9852026/11/11 23:02:12 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=09862026/11/11 23:02:12 INFO Vacuumed table table=pending_closures9872026/11/11 23:02:12 INFO Vacuumed table table=pending_objects9882026/11/11 23:02:12 INFO Vacuumed table table=multipart_uploads9892026/11/11 23:02:13 INFO Vacuumed table table=closures9902026/11/11 23:02:13 INFO Vacuumed table table=objects9912026/11/11 23:02:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9922026/11/11 23:02:13 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=Njg5NWZiMjUtYjFmOS00MDgxLTkxOTgtNWJlMzliNDdmZmEyLjdjNTA2YzI3LWI2MzQtNGFjZC05Y2E3LTQyNjY2NzE1NmIwZXgxNzk0NDM4MTMyNTgyMTI3Mjk2 parts=129932026/11/11 23:02:13 INFO Received push request method=POST path=/api/pushes994=== RUN TestPush_RejectsBadRequests/no_roots995=== PAUSE TestPush_RejectsBadRequests/no_roots996=== RUN TestPush_RejectsBadRequests/no_objects997=== PAUSE TestPush_RejectsBadRequests/no_objects998=== RUN TestPush_RejectsBadRequests/bad_root999=== PAUSE TestPush_RejectsBadRequests/bad_root1000=== RUN TestPush_RejectsBadRequests/root_not_in_objects1001=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1002=== CONT TestSweepSkipsRowsLockedByPush10032026/11/11 23:02:13 INFO Received uploads request method=POST path=/api/pending_closures10042026/11/11 23:02:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10052026/11/11 23:02:13 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=Njg5NWZiMjUtYjFmOS00MDgxLTkxOTgtNWJlMzliNDdmZmEyLmZmM2Q2N2NlLTlmODctNDhmNi1iZWRkLTIxMmUzYjVhNmY0MXgxNzk0NDM4MTMyNjg1MTQ5MDIy parts=1210062026/11/11 23:02:13 INFO Received push request method=POST path=/api/pushes10072026/11/11 23:02:13 INFO Received uploads request method=POST path=/api/pending_closures1008--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (4.48s)1009=== CONT TestPush_CompleteWaitsForCleanupOfThePush1010--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.56s)1011=== CONT TestClientMultipleUploads1012--- PASS: TestCommitRacingPendingCleanupKeepsObjects (3.56s)1013=== CONT TestFailedS3DeleteKeepsTombstone10142026/11/11 23:02:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10152026/11/11 23:02:13 INFO Signed narinfos id=1 count=110162026/11/11 23:02:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10172026/11/11 23:02:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10182026/11/11 23:02:13 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"10192026/11/11 23:02:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10202026/11/11 23:02:13 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"10212026/11/11 23:02:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10222026/11/11 23:02:13 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=110232026/11/11 23:02:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10242026/11/11 23:02:13 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1025--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (3.57s)1026=== CONT TestPush_RepeatedRootCommitsOnce10272026-11-11 23:02:13.351 UTC [562] ERROR: could not obtain lock on row in relation "closures"10282026-11-11 23:02:13.351 UTC [562] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10292026-11-11 23:02:13.352 UTC [562] ERROR: could not obtain lock on row in relation "closures"10302026-11-11 23:02:13.352 UTC [562] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10312026-11-11 23:02:13.352 UTC [562] ERROR: could not obtain lock on row in relation "closures"10322026-11-11 23:02:13.352 UTC [562] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10332026-11-11 23:02:13.352 UTC [562] ERROR: could not obtain lock on row in relation "closures"10342026-11-11 23:02:13.352 UTC [562] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10352026-11-11 23:02:13.352 UTC [562] ERROR: could not obtain lock on row in relation "closures"10362026-11-11 23:02:13.352 UTC [562] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1037--- PASS: TestPush_RootsAreLockedInByteOrder (0.66s)1038=== CONT TestClientIntegration10392026/11/11 23:02:13 INFO lead: acquired remote=192.0.2.1:1234 generation=11040--- PASS: TestGetExistingObjectsLocksRows (1.10s)1041=== CONT TestForceGCDuringPushOffersSweptObject1042=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1043=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1044=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1045=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1046=== CONT TestPush_CompleteCommitsEveryRoot10472026/11/11 23:02:13 INFO Received push request method=POST path=/api/pushes10482026/11/11 23:02:13 INFO Aborted multipart uploads count=0 kept=010492026/11/11 23:02:13 INFO Received uploads request method=POST path=/api/pending_closures10502026/11/11 23:02:13 INFO Received uploads request method=POST path=/api/pending_closures10512026/11/11 23:02:13 INFO Received uploads request method=POST path=/api/pending_closures10522026/11/11 23:02:13 INFO Received complete push request method=POST path=/api/pushes/1/complete10532026/11/11 23:02:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10542026/11/11 23:02:13 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=Njg5NWZiMjUtYjFmOS00MDgxLTkxOTgtNWJlMzliNDdmZmEyLjBmYzNlZjhmLWUzZmUtNDZiYi05ZTI4LWU4ODAyYmE2MGU3OHgxNzk0NDM4MTMyNTk0OTU5NjM5 parts=121055--- PASS: TestSharedNarBothUploadsComplete (4.80s)1056=== CONT TestClientErrorHandling1057=== RUN TestClientErrorHandling/InvalidStorePath1058=== PAUSE TestClientErrorHandling/InvalidStorePath1059=== RUN TestClientErrorHandling/InvalidAuthToken1060=== PAUSE TestClientErrorHandling/InvalidAuthToken1061=== RUN TestClientErrorHandling/ServerNotAvailable1062=== PAUSE TestClientErrorHandling/ServerNotAvailable1063=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10642026/11/11 23:02:13 INFO Aborted multipart uploads count=0 kept=01065=== CONT TestPush_OverlappingRootsStoreOneRowPerKey1066--- PASS: TestRegisterCompletedObjectNeedsPendingRow (1.15s)10672026/11/11 23:02:13 INFO lead: released remote=192.0.2.1:1234 generation=110682026/11/11 23:02:13 INFO lead: acquired remote=192.0.2.1:1234 generation=210692026/11/11 23:02:13 WARN Force mode enabled - objects will be deleted immediately without grace period1070--- PASS: TestPushWaitsForSweepHoldingRow (2.29s)1071=== CONT TestGCSweepDeliversEachKeyOnce10722026/11/11 23:02: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=010732026/11/11 23:02:13 INFO Vacuumed table table=pending_closures10742026/11/11 23:02:13 INFO Vacuumed table table=pending_objects10752026/11/11 23:02:13 INFO Vacuumed table table=multipart_uploads10762026/11/11 23:02:13 INFO Vacuumed table table=closures10772026/11/11 23:02:13 INFO Vacuumed table table=objects1078--- PASS: TestSweepRechecksPendingAfterLocking (2.36s)1079=== CONT TestClientCADerivations10802026/11/11 23:02:13 WARN Force mode enabled - objects will be deleted immediately without grace period10812026/11/11 23:02: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=010822026/11/11 23:02:13 INFO Vacuumed table table=pending_closures10832026/11/11 23:02:13 INFO Vacuumed table table=pending_objects10842026/11/11 23:02:13 INFO Vacuumed table table=multipart_uploads10852026/11/11 23:02:13 INFO Vacuumed table table=closures10862026/11/11 23:02:13 INFO Vacuumed table table=objects10872026/11/11 23:02:13 INFO Completed push id=1 objects=4 duration=262.15711ms10882026/11/11 23:02:13 INFO Received push request method=POST path=/api/pushes10892026/11/11 23:02:13 INFO Aborted multipart uploads count=0 kept=010902026/11/11 23:02:13 INFO Received uploads request method=POST path=/api/pending_closures10912026/11/11 23:02:13 INFO Aborted multipart uploads count=0 kept=010922026/11/11 23:02:13 WARN Force mode enabled - objects will be deleted immediately without grace period10932026/11/11 23:02:13 INFO Received push request method=POST path=/api/pushes10942026/11/11 23:02:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10952026/11/11 23:02:13 INFO Received push request method=POST path=/api/pushes10962026/11/11 23:02:13 INFO Aborted multipart uploads count=0 kept=010972026/11/11 23:02:13 INFO Received complete push request method=POST path=/api/pushes/1/complete10982026/11/11 23:02:13 INFO Received uploads request method=POST path=/api/pending_closures10992026/11/11 23:02:13 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=Njg5NWZiMjUtYjFmOS00MDgxLTkxOTgtNWJlMzliNDdmZmEyLjNiY2ExNmEyLTkwMTEtNDgzNC1iZmYwLTA4MTZjNDQ0YWJjN3gxNzk0NDM4MTMzNTY5NTQwMTkw parts=1011002026/11/11 23:02:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11012026/11/11 23:02:14 INFO Completed upload id=1 objects=2 duration=10.644762ms11022026/11/11 23:02:14 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000011032026/11/11 23:02:14 INFO Received push request method=POST path=/api/pushes11042026/11/11 23:02:14 INFO Received uploads request method=POST path=/api/pending_closures11052026/11/11 23:02:14 INFO Starting cleanup of old closures method=DELETE path=/api/closures11062026/11/11 23:02:14 INFO Aborted multipart uploads count=0 kept=011072026/11/11 23:02:14 INFO lead: released remote=192.0.2.1:1234 generation=11108--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.37s)1109=== CONT TestReadRedirectUsesPublicS3URL11102026/11/11 23:02:14 INFO Received push request method=POST path=/api/pushes11112026/11/11 23:02:14 INFO Received complete push request method=POST path=/api/pushes/1/complete1112=== NAME TestClientMultipleUploads1113 client_integration_test.go:405: Created store path 0: /build/TestClientMultipleUploads3484662786/001/store/vcgvlp1wdaibpbdmgvkrrcljygy3r3xz-test-file-0.txt11142026/11/11 23:02:14 INFO lead: acquired remote=192.0.2.1:1234 generation=21115=== NAME TestPinProtectsFromGC1116 client_integration_test.go:778: Pinned store path: /build/TestPinProtectsFromGC3782865662/001/store/djar668ln3s28j2kzzz4czm5l7505dfl-pinned-file.txt1117 client_integration_test.go:779: Unpinned store path: /build/TestPinProtectsFromGC3782865662/001/store/9x70pkrcbx6k066b99jhsp1sgw1pjmby-unpinned-file.txt11182026/11/11 23:02:14 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011192026/11/11 23:02:14 WARN Force mode enabled - objects will be deleted immediately without grace period11202026/11/11 23:02:14 WARN Force mode enabled - objects will be deleted immediately without grace period11212026/11/11 23:02:14 INFO Vacuumed table table=pending_closures11222026/11/11 23:02:14 INFO Vacuumed table table=pending_objects11232026/11/11 23:02:14 INFO Vacuumed table table=multipart_uploads11242026/11/11 23:02:14 INFO Vacuumed table table=closures11252026/11/11 23:02:14 INFO Vacuumed table table=objects1126=== NAME TestClientIntegration1127 client_integration_test.go:291: Created store path: /build/TestClientIntegration713536596/002/store/7wva3dkrxl94hmwpv0alsmi4l8h6av5b-test-file.txt11282026/11/11 23:02:14 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."11292026/11/11 23:02:14 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1130--- PASS: TestFailedS3DeleteKeepsTombstone (0.82s)1131=== CONT TestTombstonedObjectOfferedWithoutWaiting11322026/11/11 23:02:14 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001133--- PASS: TestService_createPendingClosureHandler (4.40s)1134=== CONT TestCacheStatsHandler11352026/11/11 23:02:14 INFO Completed push id=1 objects=6 duration=120.710836ms1136--- PASS: TestPush_CompleteCommitsEveryRoot (0.68s)1137=== CONT TestReadProxyRangeRequest11382026/11/11 23:02:14 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=011392026/11/11 23:02:14 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=2 objects-failed-to-delete=011402026/11/11 23:02:14 INFO Vacuumed table table=pending_closures11412026/11/11 23:02:14 INFO Vacuumed table table=pending_objects11422026/11/11 23:02:14 INFO Vacuumed table table=multipart_uploads11432026/11/11 23:02:14 INFO Vacuumed table table=closures11442026/11/11 23:02:14 INFO Vacuumed table table=objects1145--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.56s)1146=== CONT TestGCSweepSkipsPendingObjects1147--- PASS: TestSweepSkipsRowsLockedByPush (1.06s)1148=== CONT TestCacheConfigHandler1149=== RUN TestCacheConfigHandler/full_config,_no_issuer1150=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1151=== RUN TestCacheConfigHandler/no_cache_url_configured1152=== PAUSE TestCacheConfigHandler/no_cache_url_configured1153=== RUN TestCacheConfigHandler/no_signing_keys1154=== PAUSE TestCacheConfigHandler/no_signing_keys1155=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1156=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1157=== CONT TestReadRedirectKeepsNarinfoProxied11582026/11/11 23:02:14 INFO Vacuumed table table=pending_closures11592026/11/11 23:02:14 INFO Aborted multipart uploads count=0 kept=011602026/11/11 23:02:14 INFO Vacuumed table table=pending_objects11612026/11/11 23:02:14 INFO Vacuumed table table=multipart_uploads1162--- PASS: TestReadRedirectUsesPublicS3URL (0.19s)1163=== CONT TestDeduplicatedObjectsRecordedAsPending11642026/11/11 23:02:14 INFO Completed push id=1 objects=4 duration=242.098498ms1165--- PASS: TestPush_RepeatedRootCommitsOnce (0.89s)1166=== CONT TestService_ReadScope_PublicByDefault11672026-11-11 23:02:14.227 UTC [722] ERROR: Push does not exist: id=111682026-11-11 23:02:14.227 UTC [722] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE11692026-11-11 23:02:14.227 UTC [722] STATEMENT: SELECT commit_push($1)1170--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.91s)1171=== CONT TestPushDedupSurvivesConcurrentGC11722026/11/11 23:02:14 INFO Vacuumed table table=closures1173=== NAME TestClientWithDependencies1174 client_integration_test.go:660: Built derivation: /build/TestClientWithDependencies1823410639/001/store/jnwkpmrdyb10n3lkpr34sl6q883ajikr-test-script11752026/11/11 23:02:14 INFO Vacuumed table table=objects11762026/11/11 23:02:14 INFO Received complete push request method=POST path=/api/pushes/2/complete11772026/11/11 23:02:14 INFO Completed push id=2 objects=4 duration=4.494023ms1178--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (1.77s)1179=== CONT TestReadRedirectNar11802026/11/11 23:02:14 WARN Force mode enabled - objects will be deleted immediately without grace period11812026/11/11 23:02:14 INFO Received push request method=POST path=/api/pushes1182=== NAME TestClientWithDependencies1183 client_integration_test.go:662: Found 1 dependencies (including self)11842026/11/11 23:02:14 INFO Received push request method=POST path=/api/pushes11852026/11/11 23:02:14 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11862026/11/11 23:02:14 INFO Uploading 7wva3dkrxl94hmwpv0alsmi4l8h6av5b-test-file.txt (152B)11872026/11/11 23:02:14 INFO Received push request method=POST path=/api/pushes1188=== NAME TestClientMultipleUploads1189 client_integration_test.go:405: Created store path 1: /build/TestClientMultipleUploads3484662786/001/store/rz98iwk1vjvh8azy1a9yamimlaw9p1h3-test-file-1.txt11902026/11/11 23:02:14 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11912026/11/11 23:02:14 INFO Uploading djar668ln3s28j2kzzz4czm5l7505dfl-pinned-file.txt (128B)11922026/11/11 23:02:14 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)11932026/11/11 23:02:14 INFO Uploading sm8cjvsiqdwcqzsip2bb25h1bzkz1r86-top (224B)11942026/11/11 23:02:14 INFO Uploading k9ga6vf703hf26022xz2f7mjd2hj5jcl-shared-dep (136B)11952026/11/11 23:02:14 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"11962026/11/11 23:02:14 WARN Failed to register uploaded object key=7wva3dkrxl94hmwpv0alsmi4l8h6av5b.ls error="server returned 404: 404 page not found\n"11972026/11/11 23:02:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11982026/11/11 23:02:14 INFO Signed narinfos id=1 count=111992026/11/11 23:02:14 INFO Uploading 1 narinfos1200=== NAME TestClientCADerivations12012026/11/11 23:02:14 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"1202 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2480234542/001/store/chfkdc6hmgdfbxsfw410ggmqsb122cb9-ca-test12032026/11/11 23:02:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12042026/11/11 23:02:14 WARN Failed to register uploaded object key=sm8cjvsiqdwcqzsip2bb25h1bzkz1r86.ls error="server returned 404: 404 page not found\n"12052026/11/11 23:02:14 INFO Signed narinfos id=1 count=112062026/11/11 23:02:14 WARN Failed to register uploaded object key=k9ga6vf703hf26022xz2f7mjd2hj5jcl.ls error="server returned 404: 404 page not found\n"12072026/11/11 23:02:14 INFO Uploading 1 narinfos12082026/11/11 23:02:14 WARN Failed to register uploaded object key=djar668ln3s28j2kzzz4czm5l7505dfl.ls error="server returned 404: 404 page not found\n"12092026/11/11 23:02:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12102026/11/11 23:02:14 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12112026/11/11 23:02:14 INFO Signed narinfos id=1 count=212122026/11/11 23:02:14 WARN Failed to register uploaded object key=nar/1ln52yq9jyqrwwnb9cwffj4b94pmlkcm09cjkppqyx2fyibk5lnv.nar.zst error="server returned 404: 404 page not found\n"12132026/11/11 23:02:14 INFO Uploading 2 narinfos12142026/11/11 23:02:14 WARN Failed to register uploaded object key=7wva3dkrxl94hmwpv0alsmi4l8h6av5b.narinfo error="server returned 404: 404 page not found\n"12152026/11/11 23:02:14 INFO Received complete push request method=POST path=/api/pushes/1/complete12162026/11/11 23:02:14 INFO Received complete push request method=POST path=/api/pushes/1/complete12172026/11/11 23:02:14 WARN Failed to register uploaded object key=djar668ln3s28j2kzzz4czm5l7505dfl.narinfo error="server returned 404: 404 page not found\n"12182026/11/11 23:02:14 WARN Failed to register uploaded object key=sm8cjvsiqdwcqzsip2bb25h1bzkz1r86.narinfo error="server returned 404: 404 page not found\n"12192026/11/11 23:02:14 INFO Received complete push request method=POST path=/api/pushes/1/complete12202026/11/11 23:02:14 WARN Failed to register uploaded object key=k9ga6vf703hf26022xz2f7mjd2hj5jcl.narinfo error="server returned 404: 404 page not found\n"12212026/11/11 23:02:14 INFO Completed push id=1 objects=3 duration=8.852305ms12222026/11/11 23:02:14 INFO Upload complete. (185ms)12232026/11/11 23:02:14 INFO Completed push id=1 objects=3 duration=11.961994ms12242026/11/11 23:02:14 INFO Upload complete. (189ms)12252026/11/11 23:02:14 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=012262026/11/11 23:02:14 INFO Completed push id=1 objects=6 duration=10.638142ms12272026/11/11 23:02:14 INFO Upload complete. (246ms)12282026/11/11 23:02:14 INFO Vacuumed table table=pending_closures12292026/11/11 23:02:14 INFO Vacuumed table table=pending_objects12302026/11/11 23:02:14 INFO Vacuumed table table=multipart_uploads12312026/11/11 23:02:14 INFO Vacuumed table table=closures12322026/11/11 23:02:14 INFO Vacuumed table table=objects1233--- PASS: TestGCSweepDeliversEachKeyOnce (0.75s)1234=== CONT TestService_AuthMiddleware_OIDC1235=== NAME TestClientSharedPathCommittedMidPush1236 client_integration_test.go:727: Retrieved narinfo from S3:1237 StorePath: /build/TestClientSharedPathCommittedMidPush271151964/001/store/k9ga6vf703hf26022xz2f7mjd2hj5jcl-shared-dep1238 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1239 Compression: zstd1240 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821241 NarSize: 1361242 References: 1243 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1244 client_integration_test.go:727: Retrieved narinfo from S3:1245 StorePath: /build/TestClientSharedPathCommittedMidPush271151964/001/store/sm8cjvsiqdwcqzsip2bb25h1bzkz1r86-top1246 URL: nar/1ln52yq9jyqrwwnb9cwffj4b94pmlkcm09cjkppqyx2fyibk5lnv.nar.zst1247 Compression: zstd1248 NarHash: sha256:1ln52yq9jyqrwwnb9cwffj4b94pmlkcm09cjkppqyx2fyibk5lnv1249 NarSize: 2241250 References: /build/TestClientSharedPathCommittedMidPush271151964/001/store/k9ga6vf703hf26022xz2f7mjd2hj5jcl-shared-dep1251 CA: text:sha256:18qzbhhqw6lm4sccx989cvnii1py82snx5qkhp68ljrp585aki8r1252--- PASS: TestClientSharedPathCommittedMidPush (2.00s)1253=== CONT TestGCMetrics1254--- PASS: TestCacheStatsHandler (0.32s)1255=== CONT TestService_RequireScope_OIDC12562026/11/11 23:02:14 INFO Received push request method=POST path=/api/pushes1257=== NAME TestClientCADerivations1258 client_ca_test.go:139: Found 1 dependencies (including self)1259=== NAME TestClientMultipleUploads1260 client_integration_test.go:405: Created store path 2: /build/TestClientMultipleUploads3484662786/001/store/fd64adhiiz7sw9p65mphnl3cjqic1r9i-test-file-2.txt12612026/11/11 23:02:14 INFO lead: released remote=192.0.2.1:1234 generation=112622026/11/11 23:02:14 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12632026/11/11 23:02:14 INFO Uploading qjxfgylh6w2fah5q29wd5jp9b4h4i0kw-shared-dep (136B)12642026/11/11 23:02:14 INFO Uploading libig30646drag9pypmy29mcjsdmrxin-a (208B)1265--- PASS: TestReadRedirectNar (0.27s)1266=== CONT TestService_ReadAuthMiddleware12672026/11/11 23:02:14 INFO Received uploads request method=POST path=/api/pending_closures12682026/11/11 23:02:14 INFO All 1 paths already cached1269=== NAME TestClientIntegration1270 client_integration_test.go:317: Retrieved narinfo from S3:1271 StorePath: /build/TestClientIntegration713536596/002/store/7wva3dkrxl94hmwpv0alsmi4l8h6av5b-test-file.txt1272 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1273 Compression: zstd1274 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11275 NarSize: 1521276 References: 1277 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk112782026/11/11 23:02:14 WARN Failed to register uploaded object key=qjxfgylh6w2fah5q29wd5jp9b4h4i0kw.ls error="server returned 404: 404 page not found\n"12792026/11/11 23:02:14 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12802026/11/11 23:02:14 WARN Failed to register uploaded object key=nar/03kkg3dd5p02s2pwbfdsbqm5q5i3fzx0lr9wq2an1gny79zcncdl.nar.zst error="server returned 404: 404 page not found\n"12812026/11/11 23:02:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12822026/11/11 23:02:14 WARN Failed to register uploaded object key=libig30646drag9pypmy29mcjsdmrxin.ls error="server returned 404: 404 page not found\n"12832026/11/11 23:02:14 WARN Failed to register uploaded object key=7f151wd0ylf5cayniydys22il9qdisq3.ls error="server returned 404: 404 page not found\n"12842026/11/11 23:02:14 INFO Signed narinfos id=1 count=31285 client_integration_test.go:318: Retrieved .ls file from S3 (compressed size: 77 bytes)12862026/11/11 23:02:14 INFO Uploading 3 narinfos1287 client_integration_test.go:318: Decompressed .ls content (64 bytes):1288 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}12892026/11/11 23:02:14 INFO Received uploads request method=POST path=/api/pending_closures12902026/11/11 23:02:14 WARN Failed to register uploaded object key=qjxfgylh6w2fah5q29wd5jp9b4h4i0kw.narinfo error="server returned 404: 404 page not found\n"12912026/11/11 23:02:14 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12922026/11/11 23:02:14 INFO Uploading d3i4apfk48jlllby20csrbbfq7pbavrb-a (216B)12932026/11/11 23:02:14 INFO Uploading d4dfw2vydv3c08266gzzd8023k1qsnf6-shared-dep (136B)12942026/11/11 23:02:14 WARN Failed to register uploaded object key=7f151wd0ylf5cayniydys22il9qdisq3.narinfo error="server returned 404: 404 page not found\n"12952026/11/11 23:02:14 INFO Received complete push request method=POST path=/api/pushes/1/complete12962026/11/11 23:02:14 WARN Failed to register uploaded object key=libig30646drag9pypmy29mcjsdmrxin.narinfo error="server returned 404: 404 page not found\n"12972026/11/11 23:02:14 INFO Received uploads request method=POST path=/api/pending_closures12982026/11/11 23:02:14 WARN Failed to register uploaded object key=cl9llpblnslx2pvdmm1alm3yf7pr786z.ls error="server returned 404: 404 page not found\n"12992026/11/11 23:02:14 WARN Failed to register uploaded object key=d4dfw2vydv3c08266gzzd8023k1qsnf6.ls error="server returned 404: 404 page not found\n"13002026/11/11 23:02:14 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13012026/11/11 23:02:14 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13022026/11/11 23:02:14 WARN Failed to register uploaded object key=d3i4apfk48jlllby20csrbbfq7pbavrb.ls error="server returned 404: 404 page not found\n"13032026/11/11 23:02:14 WARN Failed to register uploaded object key=nar/1njhlgj6k8jxa8mxzh5ip960lbl89amcyrnbycdsyblma27015p4.nar.zst error="server returned 404: 404 page not found\n"13042026/11/11 23:02:14 INFO Signed narinfos id=1 count=213052026/11/11 23:02:14 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign1306--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.39s)1307=== CONT TestGCBugBareHashReferences13082026/11/11 23:02:14 INFO Completed push id=1 objects=8 duration=8.188579ms13092026/11/11 23:02:14 INFO Signed narinfos id=2 count=213102026/11/11 23:02:14 INFO Upload complete. (140ms)13112026/11/11 23:02:14 INFO Uploading 4 narinfos1312=== NAME TestClientPushesUseOnePush1313 client_pushes_test.go:97: Retrieved narinfo from S3:1314 StorePath: /build/TestClientPushesUseOnePush586658468/001/store/qjxfgylh6w2fah5q29wd5jp9b4h4i0kw-shared-dep1315 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1316 Compression: zstd1317 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821318 NarSize: 1361319 References: 1320 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1321 client_pushes_test.go:97: Retrieved narinfo from S3:1322 StorePath: /build/TestClientPushesUseOnePush586658468/001/store/libig30646drag9pypmy29mcjsdmrxin-a13232026/11/11 23:02:14 WARN Failed to register uploaded object key=d4dfw2vydv3c08266gzzd8023k1qsnf6.narinfo error="server returned 404: 404 page not found\n"1324 URL: nar/03kkg3dd5p02s2pwbfdsbqm5q5i3fzx0lr9wq2an1gny79zcncdl.nar.zst1325 Compression: zstd1326 NarHash: sha256:03kkg3dd5p02s2pwbfdsbqm5q5i3fzx0lr9wq2an1gny79zcncdl1327 NarSize: 2081328 References: /build/TestClientPushesUseOnePush586658468/001/store/qjxfgylh6w2fah5q29wd5jp9b4h4i0kw-shared-dep1329 CA: text:sha256:17vb7nivrq0zsvd22mqlix6b0yh1iz6jczvmv0c132j0q1zyby1513302026/11/11 23:02:14 WARN Failed to register uploaded object key=cl9llpblnslx2pvdmm1alm3yf7pr786z.narinfo error="server returned 404: 404 page not found\n"13312026/11/11 23:02:14 WARN Failed to register uploaded object key=d3i4apfk48jlllby20csrbbfq7pbavrb.narinfo error="server returned 404: 404 page not found\n"1332 client_pushes_test.go:97: Retrieved narinfo from S3:1333 StorePath: /build/TestClientPushesUseOnePush586658468/001/store/7f151wd0ylf5cayniydys22il9qdisq3-b1334 URL: nar/03kkg3dd5p02s2pwbfdsbqm5q5i3fzx0lr9wq2an1gny79zcncdl.nar.zst1335 Compression: zstd1336 NarHash: sha256:03kkg3dd5p02s2pwbfdsbqm5q5i3fzx0lr9wq2an1gny79zcncdl1337 NarSize: 2081338 References: /build/TestClientPushesUseOnePush586658468/001/store/qjxfgylh6w2fah5q29wd5jp9b4h4i0kw-shared-dep1339 CA: text:sha256:17vb7nivrq0zsvd22mqlix6b0yh1iz6jczvmv0c132j0q1zyby1513402026/11/11 23:02:14 WARN Failed to register uploaded object key=d4dfw2vydv3c08266gzzd8023k1qsnf6.narinfo error="server returned 404: 404 page not found\n"13412026/11/11 23:02:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13422026/11/11 23:02:14 INFO Received push request method=POST path=/api/pushes1343--- PASS: TestClientPushesUseOnePush (3.13s)1344=== CONT TestReadProxyDisabled13452026/11/11 23:02:14 INFO lead: acquired remote=192.0.2.1:1234 generation=213462026/11/11 23:02:14 INFO Received uploads request method=POST path=/api/pending_closures13472026/11/11 23:02:14 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13482026/11/11 23:02:14 INFO Uploading jnwkpmrdyb10n3lkpr34sl6q883ajikr-test-script (136B)13492026/11/11 23:02:14 INFO Completed upload id=1 objects=6 duration=9.513731ms13502026/11/11 23:02:14 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13512026/11/11 23:02:14 INFO Completed upload id=2 objects=6 duration=2.06324ms13522026/11/11 23:02:14 INFO Upload complete. (138ms)1353=== NAME TestClientFallsBackToClosures1354 client_pushes_test.go:112: Retrieved narinfo from S3:1355 StorePath: /build/TestClientFallsBackToClosures297292363/001/store/d4dfw2vydv3c08266gzzd8023k1qsnf6-shared-dep1356 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1357 Compression: zstd1358 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821359 NarSize: 1361360 References: 1361 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n13622026/11/11 23:02:14 WARN Failed to register uploaded object key=jnwkpmrdyb10n3lkpr34sl6q883ajikr.ls error="server returned 404: 404 page not found\n"13632026/11/11 23:02:14 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"13642026/11/11 23:02:14 WARN Failed to register uploaded object key=log/gp8b1ga89kcscv6c110hz17hgyr6chy7-test-script.drv error="server returned 404: 404 page not found\n"13652026/11/11 23:02:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1366 client_pushes_test.go:112: Retrieved narinfo from S3:1367 StorePath: /build/TestClientFallsBackToClosures297292363/001/store/d3i4apfk48jlllby20csrbbfq7pbavrb-a1368 URL: nar/1njhlgj6k8jxa8mxzh5ip960lbl89amcyrnbycdsyblma27015p4.nar.zst1369 Compression: zstd1370 NarHash: sha256:1njhlgj6k8jxa8mxzh5ip960lbl89amcyrnbycdsyblma27015p41371 NarSize: 2161372 References: /build/TestClientFallsBackToClosures297292363/001/store/d4dfw2vydv3c08266gzzd8023k1qsnf6-shared-dep1373 CA: text:sha256:1vjn6a32ma9wkqif4rxv0picjlpg52hldw3g33cwcvrcy5n1awbd13742026/11/11 23:02:14 INFO Signed narinfos id=1 count=113752026/11/11 23:02:14 INFO Uploading 1 narinfos1376 client_pushes_test.go:112: Retrieved narinfo from S3:1377 StorePath: /build/TestClientFallsBackToClosures297292363/001/store/cl9llpblnslx2pvdmm1alm3yf7pr786z-b1378 URL: nar/1njhlgj6k8jxa8mxzh5ip960lbl89amcyrnbycdsyblma27015p4.nar.zst1379 Compression: zstd1380 NarHash: sha256:1njhlgj6k8jxa8mxzh5ip960lbl89amcyrnbycdsyblma27015p41381 NarSize: 2161382 References: /build/TestClientFallsBackToClosures297292363/001/store/d4dfw2vydv3c08266gzzd8023k1qsnf6-shared-dep1383 CA: text:sha256:1vjn6a32ma9wkqif4rxv0picjlpg52hldw3g33cwcvrcy5n1awbd13842026/11/11 23:02:14 INFO Received complete push request method=POST path=/api/pushes/1/complete13852026/11/11 23:02:14 WARN Failed to register uploaded object key=jnwkpmrdyb10n3lkpr34sl6q883ajikr.narinfo error="server returned 404: 404 page not found\n"13862026/11/11 23:02:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43933/oidc13872026/11/11 23:02:14 INFO Received push request method=POST path=/api/pushes1388--- PASS: TestClientFallsBackToClosures (4.81s)1389=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13902026/11/11 23:02:14 INFO Aborted multipart uploads count=0 kept=013912026/11/11 23:02:14 INFO Completed push id=1 objects=4 duration=10.568081ms13922026/11/11 23:02:14 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13932026/11/11 23:02:14 INFO Uploading 9x70pkrcbx6k066b99jhsp1sgw1pjmby-unpinned-file.txt (128B)13942026/11/11 23:02:14 INFO Upload complete. (96ms)1395=== NAME TestClientWithDependencies1396 client_integration_test.go:664: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1823410639/001/store) requires matching store prefix13972026/11/11 23:02:14 WARN Failed to register uploaded object key=9x70pkrcbx6k066b99jhsp1sgw1pjmby.ls error="server returned 404: 404 page not found\n"13982026/11/11 23:02:14 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign1399--- PASS: TestClientWithDependencies (1.77s)1400=== CONT TestGCAdvisoryLockBlocksConcurrentRun14012026/11/11 23:02:14 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"14022026/11/11 23:02:14 INFO Signed narinfos id=2 count=114032026/11/11 23:02:14 INFO Uploading 1 narinfos14042026/11/11 23:02:14 INFO lead: given back to the incumbent remote=192.0.2.1:1234 generation=214052026/11/11 23:02:14 INFO Received complete push request method=POST path=/api/pushes/2/complete14062026/11/11 23:02:14 WARN Failed to register uploaded object key=9x70pkrcbx6k066b99jhsp1sgw1pjmby.narinfo error="server returned 404: 404 page not found\n"14072026/11/11 23:02:14 INFO Completed push id=2 objects=3 duration=4.538183ms14082026/11/11 23:02:14 INFO Upload complete. (102ms)14092026/11/11 23:02:14 INFO lead: acquired remote=192.0.2.1:1234 generation=31410--- PASS: TestReadProxyRangeRequest (0.44s)1411=== CONT TestReadProxyRootRedirectsToIndexHTML1412--- PASS: TestReadRedirectKeepsNarinfoProxied (0.43s)1413=== CONT TestService_AuthMiddleware_MTLSProxyHeader14142026/11/11 23:02:14 WARN Force mode enabled - objects will be deleted immediately without grace period14152026/11/11 23:02:14 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=014162026/11/11 23:02:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33593/oidc14172026/11/11 23:02:14 INFO Received push request method=POST path=/api/pushes14182026/11/11 23:02:14 INFO Vacuumed table table=pending_closures14192026/11/11 23:02:14 INFO Vacuumed table table=pending_objects14202026/11/11 23:02:14 INFO Vacuumed table table=multipart_uploads14212026/11/11 23:02:14 INFO Vacuumed table table=closures1422--- PASS: TestService_ReadScope_PublicByDefault (0.43s)1423=== CONT TestLeadEndsOnShutdown14242026/11/11 23:02:14 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)14252026/11/11 23:02:14 INFO Uploading fd64adhiiz7sw9p65mphnl3cjqic1r9i-test-file-2.txt (160B)14262026/11/11 23:02:14 INFO Uploading vcgvlp1wdaibpbdmgvkrrcljygy3r3xz-test-file-0.txt (160B)14272026/11/11 23:02:14 INFO Uploading rz98iwk1vjvh8azy1a9yamimlaw9p1h3-test-file-1.txt (160B)14282026/11/11 23:02:14 INFO Vacuumed table table=objects1429--- PASS: TestGCSweepSkipsPendingObjects (0.47s)1430=== CONT TestReadProxyConditionalGet14312026/11/11 23:02:14 WARN Failed to register uploaded object key=rz98iwk1vjvh8azy1a9yamimlaw9p1h3.ls error="server returned 404: 404 page not found\n"14322026/11/11 23:02:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14332026/11/11 23:02:14 WARN Failed to register uploaded object key=vcgvlp1wdaibpbdmgvkrrcljygy3r3xz.ls error="server returned 404: 404 page not found\n"14342026/11/11 23:02:14 WARN Failed to register uploaded object key=fd64adhiiz7sw9p65mphnl3cjqic1r9i.ls error="server returned 404: 404 page not found\n"14352026/11/11 23:02:14 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"14362026/11/11 23:02:14 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"14372026/11/11 23:02:14 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"14382026/11/11 23:02:14 INFO Signed narinfos id=1 count=314392026/11/11 23:02:14 INFO Uploading 3 narinfos14402026/11/11 23:02:14 INFO lead: released remote=192.0.2.1:1234 generation=214412026/11/11 23:02:14 WARN Failed to register uploaded object key=rz98iwk1vjvh8azy1a9yamimlaw9p1h3.narinfo error="server returned 404: 404 page not found\n"14422026/11/11 23:02:14 WARN Failed to register uploaded object key=fd64adhiiz7sw9p65mphnl3cjqic1r9i.narinfo error="server returned 404: 404 page not found\n"14432026/11/11 23:02:14 INFO Received complete push request method=POST path=/api/pushes/1/complete14442026/11/11 23:02:14 WARN Failed to register uploaded object key=vcgvlp1wdaibpbdmgvkrrcljygy3r3xz.narinfo error="server returned 404: 404 page not found\n"14452026/11/11 23:02:14 INFO Completed push id=1 objects=9 duration=9.177867ms14462026/11/11 23:02:14 INFO Upload complete. (233ms)1447=== NAME TestClientMultipleUploads1448 client_integration_test.go:416: Uploaded 3 paths in 298.874001ms14492026/11/11 23:02:14 INFO lead: acquired remote=192.0.2.1:1234 generation=314502026/11/11 23:02:14 INFO lead: released remote=192.0.2.1:1234 generation=31451--- PASS: TestLeadGenerationGrowsWithEveryGrant (5.99s)1452=== CONT TestService_AuthMiddleware14532026/11/11 23:02:14 INFO Received uploads request method=POST path=/api/pending_closures14542026/11/11 23:02:14 INFO Starting cleanup of old closures method=DELETE path=/api/closures14552026/11/11 23:02:14 INFO Garbage collection started14562026/11/11 23:02:14 INFO Received push request method=POST path=/api/pushes1457--- PASS: TestClientMultipleUploads (1.50s)1458=== CONT TestUploadHandlersRejectOversizedBody14592026/11/11 23:02:14 INFO Received push request method=POST path=/api/pushes1460--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.60s)1461=== CONT TestObjectStatsUpdatedOncePerCommit14622026/11/11 23:02:14 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14632026/11/11 23:02:14 INFO Uploading chfkdc6hmgdfbxsfw410ggmqsb122cb9-ca-test (144B)14642026/11/11 23:02:14 INFO Object in database but missing from S3 key=7wva3dkrxl94hmwpv0alsmi4l8h6av5b.ls14652026/11/11 23:02:14 WARN Found objects in DB but missing from S3, will re-upload count=114662026/11/11 23:02:14 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)14672026/11/11 23:02:14 INFO Aborted multipart uploads count=0 kept=014682026/11/11 23:02:14 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"14692026/11/11 23:02:14 WARN Failed to register uploaded object key=chfkdc6hmgdfbxsfw410ggmqsb122cb9.ls error="server returned 404: 404 page not found\n"14702026/11/11 23:02:14 WARN Failed to register uploaded object key=log/8zks36f88fb4pnazcybhya4vg27rlwk3-ca-test.drv error="server returned 404: 404 page not found\n"14712026/11/11 23:02:14 INFO Received complete push request method=POST path=/api/pushes/2/complete14722026/11/11 23:02:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14732026/11/11 23:02:14 WARN Failed to register uploaded object key=7wva3dkrxl94hmwpv0alsmi4l8h6av5b.ls error="server returned 404: 404 page not found\n"14742026/11/11 23:02:14 INFO Signed narinfos id=1 count=114752026/11/11 23:02:14 INFO Uploading 1 narinfos14762026/11/11 23:02:14 INFO Completed push id=2 objects=3 duration=9.773973ms14772026/11/11 23:02:14 INFO Upload complete. (233ms)1478=== NAME TestClientIntegration1479 client_integration_test.go:335: Retrieved .ls file from S3 (compressed size: 62 bytes)1480 client_integration_test.go:335: Decompressed .ls content (49 bytes):1481 {"version":1,"root":{"type":"regular","size":39}}14822026/11/11 23:02:14 INFO Received complete push request method=POST path=/api/pushes/1/complete14832026/11/11 23:02:14 WARN Failed to register uploaded object key=chfkdc6hmgdfbxsfw410ggmqsb122cb9.narinfo error="server returned 404: 404 page not found\n"14842026/11/11 23:02:14 INFO Completed push id=1 objects=4 duration=14.437439ms14852026/11/11 23:02:14 INFO Upload complete. (308ms)1486=== NAME TestClientCADerivations1487 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2480234542/001/store/chfkdc6hmgdfbxsfw410ggmqsb122cb9-ca-test1488 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1489 Compression: zstd1490 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1491 NarSize: 1441492 References: 1493 Deriver: /build/TestClientCADerivations2480234542/001/store/8zks36f88fb4pnazcybhya4vg27rlwk3-ca-test.drv1494 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1495 client_ca_test.go:185: Checking for realisation files in S3...14962026/11/11 23:02:14 WARN Force mode enabled - objects will be deleted immediately without grace period1497 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1498 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache14992026/11/11 23:02:14 INFO Received uploads request method=POST path=/api/pending_closures15002026/11/11 23:02:14 INFO Aborted multipart uploads count=0 kept=01501--- PASS: TestService_ReadAuthMiddleware (0.43s)1502=== CONT TestObjectStatsTrigger15032026/11/11 23:02:14 WARN Force mode enabled - objects will be deleted immediately without grace period15042026/11/11 23:02:14 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=015052026/11/11 23:02:14 INFO Vacuumed table table=pending_closures15062026/11/11 23:02:14 INFO Vacuumed table table=pending_objects15072026/11/11 23:02:14 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=015082026/11/11 23:02:14 INFO Vacuumed table table=multipart_uploads15092026/11/11 23:02:14 INFO Vacuumed table table=closures15102026/11/11 23:02:14 INFO Vacuumed table table=objects15112026/11/11 23:02:14 INFO Vacuumed table table=pending_closures1512--- PASS: TestGCMetrics (0.49s)1513=== CONT TestUploadHandlersRejectInvalidKeys1514=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1515=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1516=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1517=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1518=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1519=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1520=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1521=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1522=== CONT TestReadProxyOutlastsServerWriteTimeout15232026/11/11 23:02:14 INFO Vacuumed table table=pending_objects15242026/11/11 23:02:14 INFO Vacuumed table table=multipart_uploads15252026/11/11 23:02:14 INFO Vacuumed table table=closures15262026/11/11 23:02:14 INFO Vacuumed table table=objects15272026/11/11 23:02:15 INFO Aborted multipart uploads count=0 kept=01528=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1529=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1530=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1531=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1532=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1533=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1534=== CONT TestCreatePendingClosureRejectsOversizedNAR15352026/11/11 23:02:15 INFO Received uploads request method=POST path=/api/pending_closures1536--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1537=== CONT TestNARDeduplicationMetadataUploadBug15382026/11/11 23:02:15 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15392026/11/11 23:02:15 WARN mTLS auth: bound subjects configured but subject DN unavailable15402026/11/11 23:02:15 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1541--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.43s)1542=== CONT TestReadProxyHead15432026/11/11 23:02:15 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=015442026/11/11 23:02:15 INFO Vacuumed table table=pending_closures15452026/11/11 23:02:15 INFO Vacuumed table table=pending_objects15462026/11/11 23:02:15 INFO Vacuumed table table=multipart_uploads15472026/11/11 23:02:15 INFO Vacuumed table table=closures15482026/11/11 23:02:15 INFO Vacuumed table table=objects15492026/11/11 23:02:15 INFO Aborted multipart uploads count=0 kept=015502026/11/11 23:02:15 WARN Force mode enabled - objects will be deleted immediately without grace period15512026/11/11 23:02:15 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=01552--- PASS: TestReadProxyDisabled (0.49s)1553=== CONT TestCacheConfigHandlerMaxNarSize1554--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1555=== CONT TestServerTLSConfig1556=== RUN TestServerTLSConfig/no_client_CA1557=== PAUSE TestServerTLSConfig/no_client_CA1558=== RUN TestServerTLSConfig/missing_CA_file1559=== PAUSE TestServerTLSConfig/missing_CA_file1560=== RUN TestServerTLSConfig/not_a_PEM_file1561=== PAUSE TestServerTLSConfig/not_a_PEM_file1562=== CONT TestService_NativeMTLS15632026/11/11 23:02:15 INFO Vacuumed table table=pending_closures15642026/11/11 23:02:15 INFO Vacuumed table table=pending_objects15652026/11/11 23:02:15 INFO Vacuumed table table=multipart_uploads15662026/11/11 23:02:15 INFO Vacuumed table table=closures15672026/11/11 23:02:15 INFO Vacuumed table table=objects1568--- PASS: TestPushDedupSurvivesConcurrentGC (0.85s)1569=== CONT TestReadProxyInvalidPath1570=== RUN TestService_RequireScope_OIDC/builder_may_write1571=== PAUSE TestService_RequireScope_OIDC/builder_may_write1572=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1573=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1574=== RUN TestService_RequireScope_OIDC/ops_may_admin1575=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1576=== RUN TestService_RequireScope_OIDC/ops_may_not_write1577=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1578=== RUN TestService_RequireScope_OIDC/reader_may_not_write1579=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1580=== RUN TestService_RequireScope_OIDC/static_token_may_admin1581=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1582=== RUN TestService_RequireScope_OIDC/static_token_may_write1583=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1584=== RUN TestService_RequireScope_OIDC/reader_may_read1585=== PAUSE TestService_RequireScope_OIDC/reader_may_read1586=== RUN TestService_RequireScope_OIDC/writer_implies_read1587=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1588=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1589=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1590=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1591=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1592=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1593=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1594=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1595=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1596=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1597=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1598=== CONT TestEnsureAbortUploadsRule1599--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.53s)1600=== CONT TestPendingCleanupUsesOneCutoff16012026/11/11 23:02:15 INFO lead: acquired remote=192.0.2.1:1234 generation=116022026/11/11 23:02:15 INFO lead: released remote=192.0.2.1:1234 generation=21603--- PASS: TestLeadElectsOneAndHandsOver (5.43s)1604=== CONT TestMetricsCommit1605=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1606=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1607=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1608=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1609=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1610=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1611=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1612=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1613=== CONT TestGenerateLandingPage1614--- PASS: TestReadProxyConditionalGet (0.53s)1615=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1616--- PASS: TestGenerateLandingPage (0.01s)1617=== CONT TestMetricsInventory16182026/11/11 23:02:15 INFO Received push request method=POST path=/api/pushes16192026/11/11 23:02:15 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16202026/11/11 23:02:15 INFO Received complete push request method=POST path=/api/pushes/3/complete16212026/11/11 23:02:15 WARN Failed to register uploaded object key=7wva3dkrxl94hmwpv0alsmi4l8h6av5b.ls error="server returned 404: 404 page not found\n"16222026/11/11 23:02:15 INFO Completed push id=3 objects=3 duration=3.590914ms16232026/11/11 23:02:15 INFO Upload complete. (210ms)1624=== NAME TestClientIntegration1625 client_integration_test.go:352: Retrieved .ls file from S3 (compressed size: 62 bytes)1626 client_integration_test.go:352: Decompressed .ls content (49 bytes):1627 {"version":1,"root":{"type":"regular","size":39}}1628 client_integration_test.go:363: Testing garbage collection...16292026/11/11 23:02:15 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"1630--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.65s)1631=== CONT TestService_readinessHandler1632--- PASS: TestGCBugBareHashReferences (0.71s)1633=== CONT TestMultipartCleanup1634--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.64s)1635=== CONT TestParseSingleRange1636=== RUN TestParseSingleRange/none1637=== PAUSE TestParseSingleRange/none1638=== RUN TestParseSingleRange/unknown_unit1639=== PAUSE TestParseSingleRange/unknown_unit1640=== RUN TestParseSingleRange/multi-range_ignored1641=== PAUSE TestParseSingleRange/multi-range_ignored1642=== RUN TestParseSingleRange/malformed_no_dash1643=== PAUSE TestParseSingleRange/malformed_no_dash1644=== RUN TestParseSingleRange/malformed_both_empty1645=== PAUSE TestParseSingleRange/malformed_both_empty1646=== RUN TestParseSingleRange/malformed_end_before_start1647=== PAUSE TestParseSingleRange/malformed_end_before_start1648=== RUN TestParseSingleRange/closed1649=== PAUSE TestParseSingleRange/closed1650=== RUN TestParseSingleRange/open-ended1651=== PAUSE TestParseSingleRange/open-ended1652=== RUN TestParseSingleRange/end_clamped_to_size1653=== PAUSE TestParseSingleRange/end_clamped_to_size1654=== RUN TestParseSingleRange/suffix1655=== PAUSE TestParseSingleRange/suffix1656=== RUN TestParseSingleRange/suffix_exceeds_size1657=== PAUSE TestParseSingleRange/suffix_exceeds_size1658=== RUN TestParseSingleRange/single_byte1659=== PAUSE TestParseSingleRange/single_byte1660=== RUN TestParseSingleRange/start_past_EOF1661=== PAUSE TestParseSingleRange/start_past_EOF1662=== RUN TestParseSingleRange/start_far_past_EOF1663=== PAUSE TestParseSingleRange/start_far_past_EOF1664=== CONT TestService_healthCheckHandler16652026/11/11 23:02:15 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1666--- PASS: TestService_AuthMiddleware (0.54s)1667=== CONT TestGracefulShutdownDrainsInflight16682026/11/11 23:02:15 INFO Starting HTTP server address=127.0.0.1:3635916692026/11/11 23:02:15 INFO Shutdown signal received, draining in-flight requests timeout=10s1670--- PASS: TestObjectStatsUpdatedOncePerCommit (0.54s)1671=== CONT TestReadProxy4041672=== CONT TestGCTaskStore_Fail1673--- PASS: TestGCTaskStore_Fail (0.00s)1674=== CONT TestPresentReportsOnlyClosureRoots1675--- PASS: TestObjectStatsTrigger (0.46s)1676--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1677=== CONT TestCreatePin_ReservedPins1678--- PASS: TestReadProxyHead (0.47s)1679=== CONT TestReadProxyNarinfo16802026/11/11 23:02:15 WARN mTLS auth: subject not in bound subjects subject="CN=reader"16812026/11/11 23:02:15 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1682--- PASS: TestService_NativeMTLS (0.45s)1683=== CONT TestPresentNotReportedWhileGCDeletesClosure1684=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1685=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1686=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1687=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1688=== CONT TestReadProxyNarStreaming16892026/11/11 23:02:15 INFO Starting cleanup of old closures method=DELETE path=/api/closures16902026/11/11 23:02:15 INFO Garbage collection started16912026/11/11 23:02:15 INFO Aborted multipart uploads count=0 kept=016922026/11/11 23:02:15 INFO Installed lifecycle rule aborting incomplete NAR uploads bucket=bucket75 days=21693=== CONT TestOrphanedObjectsGCStressTest1694--- PASS: TestEnsureAbortUploadsRule (0.47s)1695--- PASS: TestReadProxyInvalidPath (0.50s)1696=== CONT TestPresentRefreshesOnlyStaleClosures16972026/11/11 23:02:15 WARN Force mode enabled - objects will be deleted immediately without grace period16982026/11/11 23:02:15 INFO Received uploads request method=POST path=/api/pending_closures1699=== NAME TestNARDeduplicationMetadataUploadBug1700 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug213839688/001/store/3f9pvfg6fhwrc00kq84q7dhwx7v616m4-file1.txt17012026/11/11 23:02:15 INFO Received uploads request method=POST path=/api/pending_closures17022026/11/11 23:02:15 INFO Received uploads request method=POST path=/api/pending_closures17032026/11/11 23:02:15 INFO Received cleanup request method=DELETE path=/api/pending_closures1704--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.47s)1705=== CONT TestIsValidCachePath1706=== RUN TestIsValidCachePath/narinfo1707=== PAUSE TestIsValidCachePath/narinfo1708=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1709=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1710=== RUN TestIsValidCachePath/nar_zst1711=== PAUSE TestIsValidCachePath/nar_zst1712=== RUN TestIsValidCachePath/nar_xz1713=== PAUSE TestIsValidCachePath/nar_xz1714=== RUN TestIsValidCachePath/nar_bz21715=== PAUSE TestIsValidCachePath/nar_bz21716=== RUN TestIsValidCachePath/nar_uncompressed1717=== PAUSE TestIsValidCachePath/nar_uncompressed1718=== RUN TestIsValidCachePath/ls1719=== PAUSE TestIsValidCachePath/ls1720=== RUN TestIsValidCachePath/log1721=== PAUSE TestIsValidCachePath/log1722=== RUN TestIsValidCachePath/realisation1723=== PAUSE TestIsValidCachePath/realisation1724=== RUN TestIsValidCachePath/nix-cache-info1725=== PAUSE TestIsValidCachePath/nix-cache-info1726=== RUN TestIsValidCachePath/index.html1727=== PAUSE TestIsValidCachePath/index.html1728=== RUN TestIsValidCachePath/traversal_parent1729=== PAUSE TestIsValidCachePath/traversal_parent1730=== RUN TestIsValidCachePath/traversal_in_middle1731=== PAUSE TestIsValidCachePath/traversal_in_middle1732=== RUN TestIsValidCachePath/invalid_char_e1733=== PAUSE TestIsValidCachePath/invalid_char_e1734=== RUN TestIsValidCachePath/invalid_char_u1735=== PAUSE TestIsValidCachePath/invalid_char_u1736=== RUN TestIsValidCachePath/random_path1737=== PAUSE TestIsValidCachePath/random_path1738=== RUN TestIsValidCachePath/empty1739=== PAUSE TestIsValidCachePath/empty1740=== RUN TestIsValidCachePath/leading_slash1741=== PAUSE TestIsValidCachePath/leading_slash1742=== RUN TestIsValidCachePath/wrong_extension1743=== PAUSE TestIsValidCachePath/wrong_extension1744=== RUN TestIsValidCachePath/short_hash1745=== PAUSE TestIsValidCachePath/short_hash1746=== CONT TestReadProxyContentNegotiation1747--- PASS: TestMetricsInventory (0.47s)1748=== CONT TestOrphanedObjectsGC17492026/11/11 23:02:15 INFO Received uploads request method=POST path=/api/pending_closures17502026/11/11 23:02:15 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=017512026/11/11 23:02:15 INFO Vacuumed table table=pending_closures17522026/11/11 23:02:15 INFO Vacuumed table table=pending_objects17532026/11/11 23:02:15 INFO Vacuumed table table=multipart_uploads17542026/11/11 23:02:15 INFO Vacuumed table table=closures17552026/11/11 23:02:15 INFO Vacuumed table table=objects17562026/11/11 23:02:15 INFO Received push request method=POST path=/api/pushes17572026/11/11 23:02:15 INFO Received complete push request method=POST path=/api/pushes/1/complete17582026/11/11 23:02:15 WARN readiness check failed error="closed pool"1759--- PASS: TestService_readinessHandler (0.54s)1760=== CONT TestReadProxyNarinfoAlreadyDecompressed1761--- PASS: TestService_healthCheckHandler (0.54s)1762=== CONT TestIsValidUploadKey/narinfo1763=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1764=== CONT TestIsValidUploadKey/unknown_type1765=== CONT TestGCEndsOnShutdown/before_the_run17662026/11/11 23:02:15 INFO Received cleanup request method=DELETE path=/api/pending_closures17672026/11/11 23:02:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41873/oidc17682026/11/11 23:02:15 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket80/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""17692026/11/11 23:02:15 INFO Aborted multipart uploads count=0 kept=117702026/11/11 23:02:15 INFO Received cleanup request method=DELETE path=/api/pending_closures17712026/11/11 23:02:15 INFO Aborted multipart uploads count=1 kept=01772--- PASS: TestMultipartCleanup (0.59s)1773=== CONT TestIsValidUploadKey/empty_key1774=== CONT TestIsValidUploadKey/absolute1775=== CONT TestIsValidUploadKey/traversal_nar1776=== CONT TestIsValidUploadKey/traversal1777=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1778=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1779=== CONT TestPendingClosureWriteTimeout/empty1780=== CONT TestIsValidUploadKey/build_log_plus_in_name1781=== CONT TestIsValidUploadKey/index.html1782=== CONT TestIsValidUploadKey/nix-cache-info1783=== CONT TestIsValidUploadKey/realisation_plus_in_output1784=== CONT TestIsValidUploadKey/realisation1785=== CONT TestIsValidUploadKey/build_log_equals1786=== CONT TestIsValidUploadKey/build_log_question_mark1787=== CONT TestIsValidUploadKey/listing1788=== CONT TestIsValidUploadKey/build_log_home-manager_file1789=== CONT TestIsValidUploadKey/build_log1790=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline17912026/11/11 23:02:15 INFO Completed push id=1 objects=4 duration=79.29434ms17922026/11/11 23:02:15 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17932026/11/11 23:02:15 INFO Completed upload id=2 objects=2 duration=2.09646ms1794--- PASS: TestMetricsCommit (0.68s)1795=== CONT TestProxyWriteTimeout/narinfo1796=== CONT TestProxyWriteTimeout/unknown_size1797=== CONT TestIsValidUploadKey/nar_xz1798=== CONT TestIsValidUploadKey/nar_plain1799=== CONT TestPendingClosureWriteTimeout/670k_objects1800=== CONT TestIsValidUploadKey/nar_zst1801=== CONT TestPendingClosureWriteTimeout/400_objects1802--- PASS: TestIsValidUploadKey (0.00s)1803 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1804 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1805 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1806 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1807 --- PASS: TestIsValidUploadKey/absolute (0.00s)1808 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1809 --- PASS: TestIsValidUploadKey/traversal (0.00s)1810 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1811 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1812 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1813 --- PASS: TestIsValidUploadKey/index.html (0.00s)1814 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1815 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1816 --- PASS: TestIsValidUploadKey/realisation (0.00s)1817 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1818 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1819 --- PASS: TestIsValidUploadKey/listing (0.00s)1820 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1821 --- PASS: TestIsValidUploadKey/build_log (0.00s)1822 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1823 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1824 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1825=== CONT TestProxyWriteTimeout/10_GiB_nar1826=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1827--- PASS: TestPresentReportsOnlyClosureRoots (0.50s)1828=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1829--- PASS: TestReadProxyNarStreaming (0.49s)1830=== CONT TestProxyWriteTimeout/1_GiB_nar1831--- PASS: TestProxyWriteTimeout (0.95s)1832 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1833 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1834 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1835 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1836=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed1837--- PASS: TestReadProxy404 (0.64s)1838=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed1839--- PASS: TestPresentRefreshesOnlyStaleClosures (0.46s)1840=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed18412026/11/11 23:02:16 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1842--- PASS: TestReadProxyNarinfo (0.57s)1843=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost1844--- PASS: TestDeleteClosuresRacingPins (6.32s)1845=== CONT TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed1846=== CONT TestResolveDBConnectionString/flag_wins1847=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1848=== CONT TestResolveDBConnectionString/missing_file_is_an_error1849=== CONT TestResolveDBConnectionString/nothing_configured1850=== CONT TestResolveDBConnectionString/file_when_flag_empty1851=== CONT TestPush_RejectsBadRequests/no_roots18522026/11/11 23:02:16 INFO Received push request method=POST path=/api/pushes1853--- PASS: TestResolveDBConnectionString (0.01s)1854 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1855 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1856 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1857 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1858 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1859=== CONT TestPush_RejectsBadRequests/bad_root18602026/11/11 23:02:16 INFO Received push request method=POST path=/api/pushes1861=== CONT TestPush_RejectsBadRequests/root_not_in_objects18622026/11/11 23:02:16 INFO Received push request method=POST path=/api/pushes1863=== CONT TestPush_RejectsBadRequests/no_objects18642026/11/11 23:02:16 INFO Received push request method=POST path=/api/pushes1865=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1866--- PASS: TestPush_RejectsBadRequests (0.77s)1867 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1868 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1869 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1870 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)18712026/11/11 23:02:16 INFO Received uploads request method=POST path=/api/pending_closures18722026/11/11 23:02:16 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18732026/11/11 23:02:16 WARN Refused reserved pin name=worker-x86_64-linux18742026/11/11 23:02:16 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18752026/11/11 23:02:16 INFO Received create pin request method=POST path=/api/pins/my-app18762026/11/11 23:02:16 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1877--- PASS: TestCreatePin_ReservedPins (0.81s)1878=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1879--- PASS: TestReadProxyContentNegotiation (0.57s)1880=== CONT TestClientErrorHandling/InvalidStorePath18812026/11/11 23:02:16 INFO lead: released remote=192.0.2.1:1234 generation=11882--- PASS: TestLeadEndsOnShutdown (1.59s)1883=== CONT TestClientErrorHandling/InvalidAuthToken1884--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.46s)1885=== CONT TestClientErrorHandling/ServerNotAvailable18862026/11/11 23:02:16 INFO Aborted multipart uploads count=0 kept=018872026/11/11 23:02:16 INFO Received push request method=POST path=/api/pushes18882026/11/11 23:02:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18892026/11/11 23:02:16 INFO Uploading 3f9pvfg6fhwrc00kq84q7dhwx7v616m4-file1.txt (160B)18902026/11/11 23:02:16 WARN Failed to register uploaded object key=3f9pvfg6fhwrc00kq84q7dhwx7v616m4.ls error="server returned 404: 404 page not found\n"18912026/11/11 23:02:16 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"18922026/11/11 23:02:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18932026/11/11 23:02:16 INFO Signed narinfos id=1 count=118942026/11/11 23:02:16 INFO Uploading 1 narinfos18952026/11/11 23:02:16 INFO Aborted multipart uploads count=0 kept=018962026/11/11 23:02:16 INFO Received complete push request method=POST path=/api/pushes/1/complete18972026/11/11 23:02:16 WARN Failed to register uploaded object key=3f9pvfg6fhwrc00kq84q7dhwx7v616m4.narinfo error="server returned 404: 404 page not found\n"18982026/11/11 23:02:16 INFO Completed push id=1 objects=3 duration=6.111198ms18992026/11/11 23:02:16 INFO Upload complete. (328ms)1900=== NAME TestNARDeduplicationMetadataUploadBug1901 metadata_upload_test.go:54: Retrieved narinfo from S3:1902 StorePath: /build/TestNARDeduplicationMetadataUploadBug213839688/001/store/3f9pvfg6fhwrc00kq84q7dhwx7v616m4-file1.txt1903 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1904 Compression: zstd1905 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1906 NarSize: 1601907 References: 1908 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1909 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1910 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1911 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}19122026/11/11 23:02:16 INFO Received uploads request method=POST path=/api/pending_closures19132026/11/11 23:02:16 INFO Received uploads request method=POST path=/api/pending_closures19142026/11/11 23:02:16 INFO Received uploads request method=POST path=/api/pending_closures19152026/11/11 23:02:16 WARN Force mode enabled - objects will be deleted immediately without grace period19162026/11/11 23:02:16 INFO Received uploads request method=POST path=/api/pending_closures1917 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug213839688/001/store/p88vl8p6z0n4mw40d3wdz53861mysp6h-file2.txt19182026/11/11 23:02:16 WARN Force mode enabled - objects will be deleted immediately without grace period19192026/11/11 23:02:16 INFO lead: released remote=192.0.2.1:1234 generation=31920--- PASS: TestLeadUnannouncedStandbyYieldsToIncumbent (7.68s)1921=== CONT TestCacheConfigHandler/full_config,_no_issuer1922=== CONT TestCacheConfigHandler/no_signing_keys1923=== CONT TestCacheConfigHandler/no_cache_url_configured1924=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1925--- PASS: TestCacheConfigHandler (0.00s)1926 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1927 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1928 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1929 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1930=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info19312026/11/11 23:02:16 INFO Received uploads request method=POST path=/1932=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1933=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key19342026/11/11 23:02:16 INFO Received request for more parts method=POST path=/1935=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal19362026/11/11 23:02:16 INFO Received complete multipart upload request method=POST path=/19372026/11/11 23:02:16 INFO Received uploads request method=POST path=/1938=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts1939=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19402026/11/11 23:02:16 INFO Received request for more parts method=POST path=/1941--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1942 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1943 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1944 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1945 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)19462026/11/11 23:02:16 INFO Received uploads request method=POST path=/19472026/11/11 23:02:16 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:36397/bucket96/?delete=\": context canceled"1948--- PASS: TestGCEndsOnShutdown (0.00s)1949 --- PASS: TestGCEndsOnShutdown/before_the_run (0.37s)1950 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.63s)1951 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.60s)1952=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19532026/11/11 23:02:16 INFO Received complete multipart upload request method=POST path=/19542026/11/11 23:02:16 INFO Received uploads request method=POST path=/api/pending_closures1955=== CONT TestServerTLSConfig/no_client_CA1956=== CONT TestServerTLSConfig/missing_CA_file1957=== CONT TestServerTLSConfig/not_a_PEM_file1958=== CONT TestService_RequireScope_OIDC/builder_may_write1959--- PASS: TestServerTLSConfig (0.00s)1960 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1961 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1962 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)19632026/11/11 23:02:16 INFO Received uploads request method=POST path=/api/pending_closures1964=== NAME TestOrphanedObjectsGC1965 orphaned_objects_gc_test.go:287: GC Test Summary:1966 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1967 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1968 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1969 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1970 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1971--- PASS: TestOrphanedObjectsGC (0.93s)1972=== CONT TestService_RequireScope_OIDC/reader_may_read1973=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1974=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read19752026/11/11 23:02: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]1976=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1977=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc19782026/11/11 23:02:16 INFO Aborted multipart uploads count=0 kept=01979=== CONT TestService_RequireScope_OIDC/reader_may_not_write1980=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1981=== CONT TestService_RequireScope_OIDC/static_token_may_write1982=== CONT TestService_RequireScope_OIDC/static_token_may_admin1983=== CONT TestService_RequireScope_OIDC/ops_may_not_write1984=== CONT TestService_RequireScope_OIDC/ops_may_admin1985=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1986=== CONT TestService_RequireScope_OIDC/writer_implies_read1987=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1988=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1989=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19902026/11/11 23:02: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]1991--- PASS: TestService_RequireScope_OIDC (0.61s)1992 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.02s)1993 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.02s)1994 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1995 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1996 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1997 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1998 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1999 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2000 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2001 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2002 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2003 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2004 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2005 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2006=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20072026/11/11 23:02:16 WARN Authentication failed token_preview=eyJhbGciOi...YtMUbR32vQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2008=== CONT TestParseSingleRange/none2009=== CONT TestParseSingleRange/start_past_EOF2010=== CONT TestParseSingleRange/single_byte2011=== CONT TestParseSingleRange/suffix_exceeds_size2012=== CONT TestParseSingleRange/suffix2013=== CONT TestParseSingleRange/end_clamped_to_size2014=== CONT TestParseSingleRange/open-ended2015=== CONT TestParseSingleRange/closed2016=== CONT TestParseSingleRange/malformed_end_before_start2017=== CONT TestParseSingleRange/start_far_past_EOF2018=== CONT TestParseSingleRange/malformed_both_empty2019=== CONT TestParseSingleRange/malformed_no_dash2020=== CONT TestParseSingleRange/unknown_unit2021=== CONT TestParseSingleRange/multi-range_ignored2022--- PASS: TestParseSingleRange (0.00s)2023 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2024 --- PASS: TestParseSingleRange/single_byte (0.00s)2025 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2026 --- PASS: TestParseSingleRange/suffix (0.00s)2027 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2028 --- PASS: TestParseSingleRange/open-ended (0.00s)2029 --- PASS: TestParseSingleRange/closed (0.00s)2030 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2031 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2032 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2033 --- PASS: TestParseSingleRange/none (0.00s)2034 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2035 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2036 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2037=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh2038=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale2039--- PASS: TestService_AuthMiddleware_OIDC (0.73s)2040 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2041 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2042 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2043 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)20442026/11/11 23:02:16 INFO Received uploads request method=POST path=/api/pending_closures2045=== CONT TestIsValidCachePath/narinfo2046=== CONT TestIsValidCachePath/wrong_extension2047=== CONT TestIsValidCachePath/leading_slash2048=== CONT TestIsValidCachePath/empty2049=== CONT TestIsValidCachePath/random_path2050=== CONT TestIsValidCachePath/invalid_char_u2051=== CONT TestIsValidCachePath/invalid_char_e2052=== CONT TestIsValidCachePath/traversal_in_middle2053=== CONT TestIsValidCachePath/traversal_parent2054=== CONT TestIsValidCachePath/index.html2055=== CONT TestIsValidCachePath/nix-cache-info2056=== CONT TestIsValidCachePath/realisation2057=== CONT TestIsValidCachePath/log2058=== CONT TestIsValidCachePath/ls2059=== CONT TestIsValidCachePath/nar_uncompressed2060=== CONT TestIsValidCachePath/nar_bz22061=== CONT TestIsValidCachePath/short_hash2062=== CONT TestIsValidCachePath/nar_xz2063=== CONT TestIsValidCachePath/nar_zst2064=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2065--- PASS: TestIsValidCachePath (0.00s)2066 --- PASS: TestIsValidCachePath/narinfo (0.00s)2067 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2068 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2069 --- PASS: TestIsValidCachePath/empty (0.00s)2070 --- PASS: TestIsValidCachePath/random_path (0.00s)2071 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2072 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2073 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2074 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2075 --- PASS: TestIsValidCachePath/index.html (0.00s)2076 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2077 --- PASS: TestIsValidCachePath/realisation (0.00s)2078 --- PASS: TestIsValidCachePath/log (0.00s)2079 --- PASS: TestIsValidCachePath/ls (0.00s)2080 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2081 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2082 --- PASS: TestIsValidCachePath/short_hash (0.00s)2083 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2084 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2085 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)20862026/11/11 23:02:16 INFO Aborted multipart uploads count=0 kept=020872026/11/11 23:02:16 WARN Force mode enabled - objects will be deleted immediately without grace period20882026/11/11 23:02:16 WARN Force mode enabled - objects will be deleted immediately without grace period20892026/11/11 23:02: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=020902026/11/11 23:02:16 INFO Vacuumed table table=pending_closures20912026/11/11 23:02:16 INFO Vacuumed table table=pending_objects20922026/11/11 23:02:16 INFO Vacuumed table table=multipart_uploads20932026/11/11 23:02:16 INFO Vacuumed table table=closures20942026/11/11 23:02: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/present20952026/11/11 23:02:16 INFO Vacuumed table table=objects20962026/11/11 23:02: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=020972026/11/11 23:02:16 INFO Vacuumed table table=pending_closures20982026/11/11 23:02:16 INFO Vacuumed table table=pending_objects20992026/11/11 23:02:16 INFO Vacuumed table table=multipart_uploads21002026/11/11 23:02:16 INFO Vacuumed table table=closures21012026/11/11 23:02:16 INFO Vacuumed table table=objects21022026/11/11 23:02:16 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=021032026/11/11 23:02:16 INFO Received create pin request method=POST path=/api/pins/myapp21042026/11/11 23:02:16 WARN Request failed, retrying attempt=2 backoff=197.452834ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2105--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2106 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.54s)2107 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.69s)21082026/11/11 23:02:16 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3782865662/001/store/djar668ln3s28j2kzzz4czm5l7505dfl-pinned-file.txt narinfo_key=djar668ln3s28j2kzzz4czm5l7505dfl.narinfo21092026/11/11 23:02:16 INFO Starting cleanup of old closures method=DELETE path=/api/closures21102026/11/11 23:02:16 INFO Garbage collection started21112026/11/11 23:02:16 INFO Aborted multipart uploads count=0 kept=021122026/11/11 23:02:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21132026/11/11 23:02:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21142026/11/11 23:02:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21152026/11/11 23:02:16 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst upload_id=Njg5NWZiMjUtYjFmOS00MDgxLTkxOTgtNWJlMzliNDdmZmEyLjBhMGJkZDZhLWQzYTQtNDM0ZS1iODViLTUwYmMwMzJjZWRhM3gxNzk0NDM4MTM2NDIzMTM3MTcy parts=1021162026/11/11 23:02:16 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000200000000000000000000.nar.zst upload_id=Njg5NWZiMjUtYjFmOS00MDgxLTkxOTgtNWJlMzliNDdmZmEyLjFmMjI5MTk1LTkzZmUtNDQxMS04ZDUxLWM0Mzg1YzU3ZTY1NXgxNzk0NDM4MTM2NDAzNTY0NDg0 parts=1021172026/11/11 23:02:16 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst upload_id=Njg5NWZiMjUtYjFmOS00MDgxLTkxOTgtNWJlMzliNDdmZmEyLjhhN2YxMDc4LWJiOTQtNGZiMi04MWRlLThjNWUxOTBmN2U3N3gxNzk0NDM4MTM2Mzg5MDM1NzI1 parts=1021182026/11/11 23:02:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21192026/11/11 23:02:16 INFO Completed upload id=1 objects=3 duration=7.266849ms21202026/11/11 23:02:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21212026/11/11 23:02:16 INFO Received uploads request method=POST path=/api/pending_closures21222026/11/11 23:02:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21232026/11/11 23:02:16 INFO Completed upload id=1 objects=3 duration=4.388502ms21242026/11/11 23:02:16 INFO Completed upload id=1 objects=3 duration=3.876097ms2125--- PASS: TestPendingClosureWriteTimeout (0.95s)2126 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2127 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2128 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2129 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.17s)21302026/11/11 23:02:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21312026/11/11 23:02:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21322026/11/11 23:02:17 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst upload_id=Njg5NWZiMjUtYjFmOS00MDgxLTkxOTgtNWJlMzliNDdmZmEyLjg2NTA1ZjYwLTgzMTAtNGRhNC1hNjg1LTIwNDhlMmE0ODYyNHgxNzk0NDM4MTM2NDk3NjYwMTg1 parts=1021332026/11/11 23:02:17 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst upload_id=Njg5NWZiMjUtYjFmOS00MDgxLTkxOTgtNWJlMzliNDdmZmEyLmQ2ZDBlZDIwLTAzNjktNDY1ZS04ODIzLThmYjI3NjUwY2MyMngxNzk0NDM4MTM2NTQwODE4MDk4 parts=1021342026/11/11 23:02:17 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21352026/11/11 23:02:17 INFO Received uploads request method=POST path=/api/pending_closures21362026/11/11 23:02:17 INFO Received uploads request method=POST path=/api/pending_closures21372026/11/11 23:02:17 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21382026/11/11 23:02:17 INFO Completed upload id=1 objects=3 duration=3.531853ms21392026/11/11 23:02:17 INFO Received uploads request method=POST path=/api/pending_closures21402026/11/11 23:02:17 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst21412026/11/11 23:02:17 WARN Found objects in DB but missing from S3, will re-upload count=121422026/11/11 23:02:17 INFO Completed upload id=1 objects=3 duration=3.441313ms21432026/11/11 23:02:17 INFO Received uploads request method=POST path=/api/pending_closures21442026/11/11 23:02:17 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst21452026/11/11 23:02:17 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0001.narinfo21462026/11/11 23:02:17 WARN Request failed, retrying attempt=3 backoff=432.108694ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21472026/11/11 23:02:17 WARN Force mode enabled - objects will be deleted immediately without grace period21482026/11/11 23:02:17 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=021492026/11/11 23:02:17 INFO Vacuumed table table=pending_closures21502026/11/11 23:02:17 INFO Vacuumed table table=pending_objects21512026/11/11 23:02:17 INFO Vacuumed table table=multipart_uploads21522026/11/11 23:02:17 INFO Vacuumed table table=closures21532026/11/11 23:02:17 INFO Vacuumed table table=objects21542026/11/11 23:02:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21552026/11/11 23:02:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21562026/11/11 23:02:17 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100400000000000000000000.nar.zst upload_id=Njg5NWZiMjUtYjFmOS00MDgxLTkxOTgtNWJlMzliNDdmZmEyLmMwMTZjYTI4LWU4NjktNDQ0Zi05YTFjLWEzNGM5NTI0MmU3OHgxNzk0NDM4MTM3MDQzMzMxODkw parts=1021572026/11/11 23:02:17 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21582026/11/11 23:02:17 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100300000000000000000000.nar.zst upload_id=Njg5NWZiMjUtYjFmOS00MDgxLTkxOTgtNWJlMzliNDdmZmEyLjdlOWUxMTMxLTc2OTEtNGY0Mi1hMWIxLWYxZjc2YTVhNTM2NXgxNzk0NDM4MTM3MDQwNjUzNjg0 parts=1021592026/11/11 23:02:17 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21602026/11/11 23:02:17 INFO Completed upload id=2 objects=3 duration=1.04153ms21612026/11/11 23:02:17 INFO Received push request method=POST path=/api/pushes21622026/11/11 23:02:17 INFO Completed upload id=2 objects=3 duration=1.10123ms2163--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2164 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.81s)2165 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.83s)21662026/11/11 23:02:17 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)21672026/11/11 23:02:17 WARN Request failed, retrying attempt=4 backoff=793.674751ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2168--- PASS: TestConnectWaitsForAPeerMigration (6.07s)21692026/11/11 23:02:17 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign21702026/11/11 23:02:17 INFO Signed narinfos id=2 count=121712026/11/11 23:02:17 INFO Uploading 1 narinfos21722026/11/11 23:02:17 WARN Failed to register uploaded object key=p88vl8p6z0n4mw40d3wdz53861mysp6h.ls error="server returned 404: 404 page not found\n"21732026/11/11 23:02:17 WARN Failed to register uploaded object key=p88vl8p6z0n4mw40d3wdz53861mysp6h.narinfo error="server returned 404: 404 page not found\n"21742026/11/11 23:02:17 INFO Received complete push request method=POST path=/api/pushes/2/complete21752026/11/11 23:02:17 INFO Received uploads request method=POST path=/api/pending_closures21762026/11/11 23:02:17 INFO Received uploads request method=POST path=/api/pending_closures21772026/11/11 23:02:17 INFO Completed push id=2 objects=3 duration=1.756217ms21782026/11/11 23:02:17 INFO Upload complete. (749ms)2179=== NAME TestNARDeduplicationMetadataUploadBug2180 metadata_upload_test.go:76: Retrieved narinfo from S3:2181 StorePath: /build/TestNARDeduplicationMetadataUploadBug213839688/001/store/p88vl8p6z0n4mw40d3wdz53861mysp6h-file2.txt2182 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2183 Compression: zstd2184 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2185 NarSize: 1602186 References: 2187 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf21882026/11/11 23:02:17 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst21892026/11/11 23:02:17 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0003.narinfo21902026/11/11 23:02:17 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst21912026/11/11 23:02:17 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0004.narinfo2192 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2193 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2194 {"version":1,"root":{"type":"regular","size":44}}2195--- PASS: TestService_verifyS3ReuploadsStaleNarinfo (2.60s)2196 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed (0.91s)2197 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed (1.01s)2198 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed (1.06s)2199 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed (1.49s)2200 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost (1.46s)2201--- PASS: TestNARDeduplicationMetadataUploadBug (2.51s)22022026/11/11 23:02:17 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:370: Objects in database after GC:2205 client_integration_test.go:370: Successfully deleted all objects with GC --force2206--- PASS: TestClientIntegration (4.17s)2207--- PASS: TestUploadHandlersRejectOversizedBody (0.18s)2208 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.09s)2209 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.16s)2210 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.08s)22112026/11/11 23:02:17 WARN Rate limiter enabled after throttle name=s3-test rate=522122026/11/11 23:02:17 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2213=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2214 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102215 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002216--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (8.92s)22172026/11/11 23:02:17 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2218=== NAME TestOrphanedObjectsGCStressTest2219 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains22202026/11/11 23:02:18 WARN Request failed, retrying attempt=5 backoff=1.556511799s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22212026/11/11 23:02:18 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2222 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion2223=== NAME TestPinProtectsFromGC2224 client_integration_test.go:887: Pin successfully protected closure from garbage collection2225--- PASS: TestPinProtectsFromGC (6.53s)2226=== NAME TestOrphanedObjectsGCStressTest2227 orphaned_objects_gc_test.go:503: Stress test completed successfully:2228 orphaned_objects_gc_test.go:504: - Active objects preserved: 202229 orphaned_objects_gc_test.go:505: - Objects deleted: 2102230 orphaned_objects_gc_test.go:506: - Total GC'd: 2102231--- PASS: TestOrphanedObjectsGCStressTest (3.74s)2232--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.71s)22332026/11/11 23:02: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-config22342026/11/11 23:02:21 WARN Request failed, retrying attempt=2 backoff=212.431477ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22352026/11/11 23:02:21 WARN Request failed, retrying attempt=3 backoff=375.187889ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22362026/11/11 23:02:21 INFO Aborted multipart uploads count=1 kept=022372026/11/11 23:02:21 INFO Received cleanup request method=DELETE path=/api/pending_closures22382026/11/11 23:02:21 INFO Aborted multipart uploads count=1 kept=02239--- PASS: TestPendingCleanupUsesOneCutoff (6.62s)22402026/11/11 23:02:21 WARN Request failed, retrying attempt=4 backoff=856.178161ms 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:02:22 WARN Request failed, retrying attempt=5 backoff=1.499431885s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2242=== NAME TestClientCADerivations2243 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2244 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2245 error: binary cache 's3://bucket44?endpoint=http://localhost:36397®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2480234542/001/store'2246 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12247--- PASS: TestClientCADerivations (8.99s)22482026/11/11 23:02: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"22492026/11/11 23:02: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-config22502026/11/11 23:02:24 WARN Request failed, retrying attempt=2 backoff=187.537381ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22512026/11/11 23:02:24 WARN Request failed, retrying attempt=3 backoff=378.459239ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22522026/11/11 23:02:24 WARN Request failed, retrying attempt=4 backoff=798.674759ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22532026/11/11 23:02:25 WARN Request failed, retrying attempt=5 backoff=1.458881094s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22542026/11/11 23:02: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_closures22552026/11/11 23:02:27 WARN Request failed, retrying attempt=2 backoff=206.20616ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22562026/11/11 23:02:27 WARN Request failed, retrying attempt=3 backoff=377.153675ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22572026/11/11 23:02:27 WARN Request failed, retrying attempt=4 backoff=735.43293ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22582026/11/11 23:02:28 WARN Request failed, retrying attempt=5 backoff=1.734232374s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2259--- PASS: TestClientErrorHandling (0.00s)2260 --- PASS: TestClientErrorHandling/InvalidStorePath (1.24s)2261 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.37s)2262 --- PASS: TestClientErrorHandling/ServerNotAvailable (14.10s)2263PASS22642026-11-11 23:02:30.731 UTC [130] LOG: received smart shutdown request22652026-11-11 23:02:30.741 UTC [130] LOG: background worker "logical replication launcher" (PID 152) exited with exit code 122662026-11-11 23:02:30.752 UTC [147] LOG: shutting down22672026-11-11 23:02:30.753 UTC [147] LOG: checkpoint starting: shutdown immediate22682026-11-11 23:02:31.506 UTC [147] LOG: checkpoint complete: wrote 11165 buffers (68.1%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.347 s, sync=0.353 s, total=0.754 s; sync files=36842, longest=0.006 s, average=0.001 s; distance=531051 kB, estimate=531051 kB; lsn=0/21E00A00, redo lsn=0/21E00A0022692026-11-11 23:02:31.679 UTC [130] LOG: database system is shut down2270Running OIDC tests...2271=== RUN TestAudienceForIssuer2272=== PAUSE TestAudienceForIssuer2273=== RUN TestGlobMatch2274=== PAUSE TestGlobMatch2275=== RUN TestValidateToken_ValidToken2276=== PAUSE TestValidateToken_ValidToken2277=== RUN TestValidateToken_WrongAudience2278=== PAUSE TestValidateToken_WrongAudience2279=== RUN TestValidateToken_Expired2280=== PAUSE TestValidateToken_Expired2281=== RUN TestValidateToken_BoundClaimsMismatch2282=== PAUSE TestValidateToken_BoundClaimsMismatch2283=== RUN TestValidateToken_BoundSubjectMismatch2284=== PAUSE TestValidateToken_BoundSubjectMismatch2285=== RUN TestValidateToken_MultipleProviders2286=== PAUSE TestValidateToken_MultipleProviders2287=== RUN TestValidateToken_NoMatchingProvider2288=== PAUSE TestValidateToken_NoMatchingProvider2289=== RUN TestValidateToken_KubernetesServiceAccount2290=== PAUSE TestValidateToken_KubernetesServiceAccount2291=== RUN TestNewValidator_KubernetesRequiresCA2292=== PAUSE TestNewValidator_KubernetesRequiresCA2293=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2294=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2295=== RUN TestPins_ReservedForMatchingRule2296=== PAUSE TestPins_ReservedForMatchingRule2297=== RUN TestPins_TopLevelShorthand2298=== PAUSE TestPins_TopLevelShorthand2299=== RUN TestPins_ConfigValidation2300=== PAUSE TestPins_ConfigValidation2301=== RUN TestScopes_LegacyProviderDefaultsToWrite2302=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2303=== RUN TestScopes_Rules2304=== PAUSE TestScopes_Rules2305=== RUN TestScopes_ConfigValidation2306=== PAUSE TestScopes_ConfigValidation2307=== CONT TestAudienceForIssuer2308--- PASS: TestAudienceForIssuer (0.00s)2309=== CONT TestScopes_ConfigValidation2310--- PASS: TestScopes_ConfigValidation (0.00s)2311=== CONT TestScopes_Rules2312=== CONT TestScopes_LegacyProviderDefaultsToWrite2313=== CONT TestPins_ConfigValidation2314=== CONT TestPins_TopLevelShorthand2315=== CONT TestPins_ReservedForMatchingRule2316=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2317--- PASS: TestPins_ConfigValidation (1.12s)2318=== CONT TestNewValidator_KubernetesRequiresCA2319=== CONT TestValidateToken_KubernetesServiceAccount2320=== CONT TestValidateToken_NoMatchingProvider2321=== CONT TestValidateToken_MultipleProviders2322=== CONT TestValidateToken_BoundSubjectMismatch2323=== CONT TestValidateToken_BoundClaimsMismatch2324=== CONT TestValidateToken_Expired2325=== CONT TestValidateToken_WrongAudience2326=== CONT TestValidateToken_ValidToken2327=== CONT TestGlobMatch2328=== RUN TestGlobMatch/foo_foo2329=== PAUSE TestGlobMatch/foo_foo2330=== RUN TestGlobMatch/foo_bar2331=== PAUSE TestGlobMatch/foo_bar2332=== RUN TestGlobMatch/*_2333=== PAUSE TestGlobMatch/*_2334=== RUN TestGlobMatch/*_anything2335=== PAUSE TestGlobMatch/*_anything2336=== RUN TestGlobMatch/foo*_foo2337=== PAUSE TestGlobMatch/foo*_foo2338=== RUN TestGlobMatch/foo*_foobar2339=== PAUSE TestGlobMatch/foo*_foobar2340=== RUN TestGlobMatch/foo*_bar2341=== PAUSE TestGlobMatch/foo*_bar2342=== RUN TestGlobMatch/*bar_bar2343=== PAUSE TestGlobMatch/*bar_bar2344=== RUN TestGlobMatch/*bar_foobar2345=== PAUSE TestGlobMatch/*bar_foobar2346=== RUN TestGlobMatch/*bar_foo2347=== PAUSE TestGlobMatch/*bar_foo2348=== RUN TestGlobMatch/foo*bar_foobar2349=== PAUSE TestGlobMatch/foo*bar_foobar2350=== RUN TestGlobMatch/foo*bar_foo123bar2351=== PAUSE TestGlobMatch/foo*bar_foo123bar2352=== RUN TestGlobMatch/foo*bar_foobarbaz2353=== PAUSE TestGlobMatch/foo*bar_foobarbaz2354=== RUN TestGlobMatch/*/*_foo/bar2355=== PAUSE TestGlobMatch/*/*_foo/bar2356=== RUN TestGlobMatch/*/*_foo2357=== PAUSE TestGlobMatch/*/*_foo2358=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2359=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2360=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02361=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02362=== RUN TestGlobMatch/refs/*/main_refs/heads/main2363=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2364=== RUN TestGlobMatch/fo?_foo2365=== PAUSE TestGlobMatch/fo?_foo2366=== RUN TestGlobMatch/fo?_fo2367=== PAUSE TestGlobMatch/fo?_fo2368=== RUN TestGlobMatch/fo?_fooo2369=== PAUSE TestGlobMatch/fo?_fooo2370=== RUN TestGlobMatch/?oo_foo2371=== PAUSE TestGlobMatch/?oo_foo2372=== RUN TestGlobMatch/?oo_boo2373=== PAUSE TestGlobMatch/?oo_boo2374=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2375=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2376=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2377=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2378=== CONT TestGlobMatch/foo_foo2379=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2380=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2381=== CONT TestGlobMatch/?oo_boo2382=== CONT TestGlobMatch/?oo_foo2383=== CONT TestGlobMatch/fo?_fooo2384=== CONT TestGlobMatch/fo?_fo2385=== CONT TestGlobMatch/fo?_foo2386=== CONT TestGlobMatch/refs/*/main_refs/heads/main2387=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02388=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2389=== CONT TestGlobMatch/*/*_foo2390=== CONT TestGlobMatch/*/*_foo/bar2391=== CONT TestGlobMatch/foo*bar_foobarbaz2392=== CONT TestGlobMatch/*bar_foo2393=== CONT TestGlobMatch/*bar_foobar2394=== CONT TestGlobMatch/*bar_bar2395=== CONT TestGlobMatch/foo*_bar2396=== CONT TestGlobMatch/foo*_foobar2397=== CONT TestGlobMatch/foo*_foo2398=== CONT TestGlobMatch/*_anything2399=== CONT TestGlobMatch/*_2400=== CONT TestGlobMatch/foo_bar2401=== CONT TestGlobMatch/foo*bar_foobar2402=== CONT TestGlobMatch/foo*bar_foo123bar2403--- PASS: TestGlobMatch (0.66s)2404 --- PASS: TestGlobMatch/foo_foo (0.00s)2405 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2406 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2407 --- PASS: TestGlobMatch/?oo_boo (0.00s)2408 --- PASS: TestGlobMatch/?oo_foo (0.00s)2409 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2410 --- PASS: TestGlobMatch/fo?_fo (0.00s)2411 --- PASS: TestGlobMatch/fo?_foo (0.00s)2412 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2413 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2414 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2415 --- PASS: TestGlobMatch/*/*_foo (0.00s)2416 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2417 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2418 --- PASS: TestGlobMatch/*bar_foo (0.00s)2419 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2420 --- PASS: TestGlobMatch/*bar_bar (0.00s)2421 --- PASS: TestGlobMatch/foo*_bar (0.00s)2422 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2423 --- PASS: TestGlobMatch/foo*_foo (0.00s)2424 --- PASS: TestGlobMatch/*_anything (0.00s)2425 --- PASS: TestGlobMatch/*_ (0.00s)2426 --- PASS: TestGlobMatch/foo_bar (0.00s)2427 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2428 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)24292026/11/11 23:02:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35475/oidc24302026/11/11 23:02:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35789/oidc24312026/11/11 23:02:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42951/oidc2432--- PASS: TestValidateToken_Expired (4.21s)24332026/11/11 23:02:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46731/oidc2434--- PASS: TestValidateToken_BoundSubjectMismatch (4.95s)24352026/11/11 23:02:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43659/oidc2436--- PASS: TestPins_ReservedForMatchingRule (4.97s)24372026/11/11 23:02:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33975/oidc24382026/11/11 23:02:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43161/oidc2439--- PASS: TestScopes_Rules (6.11s)2440--- PASS: TestPins_TopLevelShorthand (6.07s)2441--- PASS: TestValidateToken_BoundClaimsMismatch (4.95s)2442--- PASS: TestValidateToken_ValidToken (4.24s)24432026/11/11 23:02:40 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:4134524442026/11/11 23:02:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36147/oidc2445--- PASS: TestValidateToken_KubernetesServiceAccount (4.98s)2446--- PASS: TestValidateToken_WrongAudience (4.25s)24472026/11/11 23:02:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37437/oidc2448--- PASS: TestScopes_LegacyProviderDefaultsToWrite (6.13s)24492026/11/11 23:02:41 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:39189/oidc2450--- PASS: TestValidateToken_NoMatchingProvider (5.02s)24512026/11/11 23:02:41 http: TLS handshake error from 127.0.0.1:37186: remote error: tls: bad certificate2452--- PASS: TestNewValidator_KubernetesRequiresCA (5.06s)24532026/11/11 23:02:41 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:35119/oidc24542026/11/11 23:02:41 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:41969/oidc2455--- PASS: TestValidateToken_MultipleProviders (5.11s)24562026/11/11 23:02:41 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232457--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (5.15s)2458PASS2459Running hook tests...2460=== RUN TestSendPathsEmpty2461=== PAUSE TestSendPathsEmpty2462=== RUN TestQueueEnqueueAndFetch2463=== PAUSE TestQueueEnqueueAndFetch2464=== RUN TestQueueDeduplication2465=== PAUSE TestQueueDeduplication2466=== RUN TestQueueRemove2467=== PAUSE TestQueueRemove2468=== RUN TestQueueFetchBatchLimit2469=== PAUSE TestQueueFetchBatchLimit2470=== RUN TestQueueRetryMovesToBack2471=== PAUSE TestQueueRetryMovesToBack2472=== RUN TestQueueFetchRemoveLifecycle2473=== PAUSE TestQueueFetchRemoveLifecycle2474=== RUN TestQueueConcurrentWriters2475=== PAUSE TestQueueConcurrentWriters2476=== RUN TestQueueRemoveLargeClosure2477=== PAUSE TestQueueRemoveLargeClosure2478=== RUN TestServerClientIntegration2479--- PASS: TestServerClientIntegration (0.00s)2480=== RUN TestServerQueueError24812026/11/11 23:02:43 ERROR Failed to queue paths error="permission denied" count=12482--- PASS: TestServerQueueError (0.00s)2483=== RUN TestGetListenerSocketActivation2484 server_test.go:218: === RUN TestGetListenerSocketActivation2485 --- PASS: TestGetListenerSocketActivation (0.00s)2486 PASS2487 2488--- PASS: TestGetListenerSocketActivation (3.01s)2489=== RUN TestServerStalledClientDoesNotBlockShutdown2490=== PAUSE TestServerStalledClientDoesNotBlockShutdown2491=== RUN TestServerBacksOffOnAcceptErrors2492=== PAUSE TestServerBacksOffOnAcceptErrors2493=== RUN TestDrainIsolatesPoisonPath2494=== PAUSE TestDrainIsolatesPoisonPath2495=== RUN TestRunNotBlockedByPoisonHead2496=== PAUSE TestRunNotBlockedByPoisonHead2497=== RUN TestDrainGivesUpWhenServerDown2498=== PAUSE TestDrainGivesUpWhenServerDown2499=== RUN TestFailedPathPrunedByLaterClosure2500=== PAUSE TestFailedPathPrunedByLaterClosure2501=== RUN TestWorkerUploadsAndRemoves2502=== PAUSE TestWorkerUploadsAndRemoves2503=== RUN TestWorkerSkipsGCdPaths2504=== PAUSE TestWorkerSkipsGCdPaths2505=== RUN TestWorkerPrunesClosureDeps2506=== PAUSE TestWorkerPrunesClosureDeps2507=== RUN TestDrainTimeout2508=== PAUSE TestDrainTimeout2509=== RUN TestWorkerRemoveFailureIsNotProgress2510=== PAUSE TestWorkerRemoveFailureIsNotProgress2511=== RUN TestWorkerKeepsPathItCannotStat2512=== PAUSE TestWorkerKeepsPathItCannotStat2513=== CONT TestDrainTimeout2514=== CONT TestSendPathsEmpty2515--- PASS: TestSendPathsEmpty (0.00s)2516=== CONT TestWorkerPrunesClosureDeps2517=== CONT TestWorkerSkipsGCdPaths2518=== CONT TestWorkerUploadsAndRemoves2519=== CONT TestFailedPathPrunedByLaterClosure2520=== CONT TestDrainGivesUpWhenServerDown2521=== CONT TestRunNotBlockedByPoisonHead2522=== CONT TestDrainIsolatesPoisonPath2523=== CONT TestServerBacksOffOnAcceptErrors2524=== CONT TestServerStalledClientDoesNotBlockShutdown2525=== CONT TestQueueRemoveLargeClosure2526=== CONT TestQueueConcurrentWriters2527=== CONT TestQueueFetchRemoveLifecycle2528=== CONT TestQueueRetryMovesToBack2529=== CONT TestQueueFetchBatchLimit2530=== CONT TestQueueRemove2531=== CONT TestQueueDeduplication2532=== CONT TestQueueEnqueueAndFetch2533=== CONT TestWorkerKeepsPathItCannotStat2534=== CONT TestWorkerRemoveFailureIsNotProgress25352026/11/11 23:02:46 ERROR Accept failed error="too many open files"25362026/11/11 23:02:46 ERROR Accept failed error="too many open files"25372026/11/11 23:02:46 ERROR Accept failed error="too many open files"25382026/11/11 23:02:46 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat654720270/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat654720270/002/locked/aaa: permission denied"25392026/11/11 23:02:46 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat654720270/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat654720270/002/locked/aaa: permission denied"25402026/11/11 23:02:46 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat654720270/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat654720270/002/locked/aaa: permission denied"25412026/11/11 23:02:46 ERROR Drain finished with paths left in queue remaining=125422026/11/11 23:02:46 ERROR Accept failed error="too many open files"25432026/11/11 23:02:46 INFO Uploading batch count=225442026/11/11 23:02:46 ERROR Upload failed error="upload failed" count=22545--- PASS: TestWorkerKeepsPathItCannotStat (0.04s)25462026/11/11 23:02:46 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3044529157/002/a25472026/11/11 23:02:46 INFO Upload queue status pending=325482026/11/11 23:02:46 INFO Uploading batch count=125492026/11/11 23:02:46 ERROR Upload failed error="upload failed" count=125502026/11/11 23:02:46 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3044529157/002/b25512026/11/11 23:02:46 INFO Uploading batch count=225522026/11/11 23:02:46 ERROR Upload failed error="upload failed" count=225532026/11/11 23:02:46 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3044529157/002/c25542026/11/11 23:02:46 INFO Uploading batch count=425552026/11/11 23:02:46 ERROR Upload failed error="upload failed" count=425562026/11/11 23:02:46 INFO Upload queue status pending=225572026/11/11 23:02:46 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3044529157/002/d2558--- PASS: TestQueueEnqueueAndFetch (0.04s)25592026/11/11 23:02:46 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath4088538380/002/bbb2560--- PASS: TestQueueRetryMovesToBack (0.05s)25612026/11/11 23:02:46 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths735236411/002/nonexistent25622026/11/11 23:02:48 INFO Uploading batch count=125632026/11/11 23:02:48 INFO Uploading batch count=225642026/11/11 23:02:48 INFO Uploading batch count=125652026/11/11 23:02:48 ERROR Failed to decode request error="read unix /build/hook3235473715/test.sock->@: i/o timeout"25662026/11/11 23:02:48 ERROR Failed to write response error="write unix /build/hook3235473715/test.sock->@: i/o timeout"25672026/11/11 23:02:48 ERROR Accept failed error="too many open files"2568--- PASS: TestServerStalledClientDoesNotBlockShutdown (2.01s)25692026/11/11 23:02:48 INFO Uploading batch count=125702026/11/11 23:02:48 INFO Uploading batch count=125712026/11/11 23:02:48 ERROR Upload failed error="upload failed" count=125722026/11/11 23:02:48 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress2619583790/002/nonexistent25732026/11/11 23:02:48 INFO Uploading batch count=125742026/11/11 23:02:48 INFO Uploading batch count=225752026/11/11 23:02:48 ERROR Upload failed error="upload failed" count=225762026/11/11 23:02:48 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125772026/11/11 23:02:48 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3044529157/002/e2578--- PASS: TestQueueDeduplication (2.01s)25792026/11/11 23:02:48 INFO Uploading batch count=125802026/11/11 23:02:48 ERROR Upload failed error="upload failed" count=125812026/11/11 23:02:48 INFO Upload queue status pending=225822026/11/11 23:02:48 INFO Uploading batch count=22583--- PASS: TestQueueFetchBatchLimit (2.02s)25842026/11/11 23:02:48 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress2619583790/002/nonexistent25852026/11/11 23:02:48 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125862026/11/11 23:02:48 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress2619583790/002/nonexistent25872026/11/11 23:02:48 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125882026/11/11 23:02:48 ERROR Drain finished with paths left in queue remaining=125892026/11/11 23:02:48 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3044529157/002/f25902026/11/11 23:02:48 INFO Uploading batch count=12591--- PASS: TestQueueRemove (2.02s)25922026/11/11 23:02:48 INFO Upload queue status pending=22593--- PASS: TestWorkerRemoveFailureIsNotProgress (2.02s)25942026/11/11 23:02:48 INFO Uploading batch count=12595--- PASS: TestFailedPathPrunedByLaterClosure (2.02s)25962026/11/11 23:02:48 INFO Uploading batch count=125972026/11/11 23:02:48 ERROR Upload failed error="upload failed" count=125982026/11/11 23:02:48 ERROR Drain finished with paths left in queue remaining=102599--- PASS: TestQueueFetchRemoveLifecycle (2.02s)26002026/11/11 23:02:48 INFO Uploading batch count=126012026/11/11 23:02:48 ERROR Upload failed error="upload failed" count=126022026/11/11 23:02:48 INFO Uploading batch count=126032026/11/11 23:02:48 ERROR Upload failed error="upload failed" count=126042026/11/11 23:02:48 ERROR Drain finished with paths left in queue remaining=12605--- PASS: TestDrainGivesUpWhenServerDown (2.02s)2606--- PASS: TestDrainIsolatesPoisonPath (2.03s)26072026/11/11 23:02:48 INFO Uploading batch count=126082026/11/11 23:02:48 ERROR Upload failed error="upload failed" count=126092026/11/11 23:02:48 INFO Uploading batch count=126102026/11/11 23:02:48 ERROR Upload failed error="upload failed" count=126112026/11/11 23:02:48 INFO Uploading batch count=126122026/11/11 23:02:48 ERROR Upload failed error="upload failed" count=126132026/11/11 23:02:48 ERROR Drain finished with paths left in queue remaining=12614--- PASS: TestRunNotBlockedByPoisonHead (2.03s)2615--- PASS: TestWorkerSkipsGCdPaths (2.04s)2616--- PASS: TestWorkerUploadsAndRemoves (2.04s)2617--- PASS: TestWorkerPrunesClosureDeps (2.04s)26182026/11/11 23:02:48 ERROR Accept failed error="too many open files"2619--- PASS: TestQueueConcurrentWriters (2.14s)2620--- PASS: TestQueueRemoveLargeClosure (2.19s)26212026/11/11 23:02:48 ERROR Upload failed error="context deadline exceeded" count=226222026/11/11 23:02:48 ERROR Drain finished with paths left in queue remaining=42623--- PASS: TestDrainTimeout (2.22s)26242026/11/11 23:02:48 ERROR Accept failed error="too many open files"26252026/11/11 23:02:49 ERROR Accept failed error="too many open files"2626--- PASS: TestServerBacksOffOnAcceptErrors (2.57s)2627PASS2628Running signing tests...2629=== RUN TestExternalSigner2630=== PAUSE TestExternalSigner2631=== RUN TestExternalSignerWrongPublicKey2632=== PAUSE TestExternalSignerWrongPublicKey2633=== RUN TestExternalSignerErrors2634=== PAUSE TestExternalSignerErrors2635=== RUN TestExternalSignerRestartsAfterCrash2636=== PAUSE TestExternalSignerRestartsAfterCrash2637=== RUN TestExternalSignerProgramErrorKeepsProcess2638=== PAUSE TestExternalSignerProgramErrorKeepsProcess2639=== RUN TestExternalSignerClose2640=== PAUSE TestExternalSignerClose2641=== RUN TestExternalSignerRejectsInvalidPublicKey2642=== PAUSE TestExternalSignerRejectsInvalidPublicKey2643=== RUN TestExternalSignerCancellation2644=== PAUSE TestExternalSignerCancellation2645=== RUN TestGenerateFingerprint2646=== PAUSE TestGenerateFingerprint2647=== RUN TestParseSigningKey2648=== PAUSE TestParseSigningKey2649=== RUN TestSign2650=== PAUSE TestSign2651=== RUN TestSignBatch2652=== PAUSE TestSignBatch2653=== RUN TestNilKeyPublicKey2654=== PAUSE TestNilKeyPublicKey2655=== RUN TestSignErrors2656=== PAUSE TestSignErrors2657=== CONT TestExternalSigner2658=== CONT TestExternalSignerProgramErrorKeepsProcess2659=== CONT TestSign2660=== CONT TestExternalSignerRejectsInvalidPublicKey2661=== CONT TestExternalSignerCancellation2662=== CONT TestSignBatch2663=== CONT TestExternalSignerClose2664=== CONT TestExternalSignerErrors2665=== RUN TestExternalSignerErrors/exit_on_request2666=== PAUSE TestExternalSignerErrors/exit_on_request2667=== RUN TestExternalSignerErrors/null2668=== PAUSE TestExternalSignerErrors/null2669=== RUN TestExternalSignerErrors/wrong_signatures_shape2670=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2671=== RUN TestExternalSignerErrors/wrong_signature_name2672=== PAUSE TestExternalSignerErrors/wrong_signature_name2673=== RUN TestExternalSignerErrors/program_error2674=== PAUSE TestExternalSignerErrors/program_error2675=== RUN TestExternalSignerErrors/missing_signatures2676=== PAUSE TestExternalSignerErrors/missing_signatures2677=== RUN TestExternalSignerErrors/unrequested_key2678=== PAUSE TestExternalSignerErrors/unrequested_key2679=== RUN TestExternalSignerErrors/missing_signature_name2680=== PAUSE TestExternalSignerErrors/missing_signature_name2681=== RUN TestExternalSignerErrors/wrong_shape2682=== PAUSE TestExternalSignerErrors/wrong_shape2683=== RUN TestExternalSignerErrors/null_signatures2684=== PAUSE TestExternalSignerErrors/null_signatures2685=== RUN TestExternalSignerErrors/invalid_signature_base642686=== PAUSE TestExternalSignerErrors/invalid_signature_base642687=== RUN TestExternalSignerErrors/exit_at_startup2688=== PAUSE TestExternalSignerErrors/exit_at_startup2689=== RUN TestExternalSignerErrors/invalid_JSON2690=== PAUSE TestExternalSignerErrors/invalid_JSON2691=== RUN TestExternalSignerErrors/wrong_id2692=== PAUSE TestExternalSignerErrors/wrong_id2693=== RUN TestExternalSignerErrors/too_few_signatures2694=== CONT TestExternalSignerRestartsAfterCrash2695=== CONT TestExternalSignerWrongPublicKey2696=== CONT TestParseSigningKey2697=== CONT TestSignErrors2698=== CONT TestNilKeyPublicKey2699=== CONT TestGenerateFingerprint2700=== RUN TestExternalSignerRejectsInvalidPublicKey/#002701=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002702=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2703=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2704=== RUN TestParseSigningKey/valid_32-byte_key2705=== PAUSE TestParseSigningKey/valid_32-byte_key2706=== PAUSE TestExternalSignerErrors/too_few_signatures2707=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2708=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2709=== RUN TestParseSigningKey/no_colon2710=== PAUSE TestParseSigningKey/no_colon2711=== RUN TestParseSigningKey/empty_name2712=== PAUSE TestParseSigningKey/empty_name2713=== RUN TestParseSigningKey/invalid_base642714=== PAUSE TestParseSigningKey/invalid_base642715=== RUN TestParseSigningKey/wrong_length2716=== PAUSE TestParseSigningKey/wrong_length2717=== CONT TestParseSigningKey/valid_32-byte_key2718=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2719--- PASS: TestNilKeyPublicKey (0.00s)2720--- PASS: TestSign (0.00s)2721=== CONT TestParseSigningKey/invalid_base642722=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2723=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2724=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2725=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2726=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2727=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2728=== CONT TestExternalSignerRejectsInvalidPublicKey/#002729=== RUN TestExternalSignerErrors/wrong_signature_length2730=== PAUSE TestExternalSignerErrors/wrong_signature_length2731=== CONT TestExternalSignerErrors/exit_on_request2732=== CONT TestExternalSignerErrors/null_signatures2733--- PASS: TestSignBatch (0.00s)2734=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2735=== CONT TestExternalSignerErrors/missing_signatures2736=== CONT TestExternalSignerErrors/missing_signature_name2737=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2738=== CONT TestExternalSignerErrors/wrong_signature_length2739=== CONT TestExternalSignerErrors/wrong_signature_name2740=== RUN TestSignErrors/nil_key2741=== CONT TestExternalSignerErrors/unrequested_key2742=== CONT TestParseSigningKey/wrong_length2743=== CONT TestParseSigningKey/no_colon2744=== CONT TestParseSigningKey/empty_name2745--- PASS: TestParseSigningKey (0.00s)2746 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2747 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2748 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2749 --- PASS: TestParseSigningKey/wrong_length (0.00s)2750 --- PASS: TestParseSigningKey/no_colon (0.00s)2751 --- PASS: TestParseSigningKey/empty_name (0.00s)2752=== CONT TestExternalSignerErrors/program_error2753=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2754=== CONT TestExternalSignerErrors/invalid_signature_base642755=== CONT TestExternalSignerErrors/wrong_signatures_shape2756=== CONT TestExternalSignerErrors/null2757=== CONT TestExternalSignerErrors/too_few_signatures2758=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2759=== RUN TestGenerateFingerprint/basic_with_references2760=== PAUSE TestSignErrors/nil_key2761=== CONT TestExternalSignerErrors/invalid_JSON2762=== CONT TestExternalSignerErrors/wrong_shape2763=== CONT TestExternalSignerErrors/wrong_id2764=== CONT TestExternalSignerErrors/exit_at_startup2765--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2766 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2767 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2768 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2769 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2770 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2771=== PAUSE TestGenerateFingerprint/basic_with_references2772=== RUN TestSignErrors/nil_narinfo2773=== PAUSE TestSignErrors/nil_narinfo2774=== RUN TestGenerateFingerprint/no_references2775=== PAUSE TestGenerateFingerprint/no_references2776=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2777=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2778=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2779=== RUN TestSignErrors/invalid_narinfo2780=== PAUSE TestSignErrors/invalid_narinfo2781=== RUN TestSignErrors/canceled2782=== PAUSE TestSignErrors/canceled2783=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2784=== RUN TestGenerateFingerprint/invalid_nar_hash_length2785=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2786=== RUN TestGenerateFingerprint/invalid_store_path_prefix2787=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2788=== RUN TestGenerateFingerprint/invalid_reference_prefix2789=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2790=== CONT TestSignErrors/canceled2791=== CONT TestSignErrors/invalid_narinfo2792=== CONT TestSignErrors/nil_narinfo2793=== CONT TestGenerateFingerprint/basic_with_references2794=== CONT TestGenerateFingerprint/invalid_nar_hash_length2795=== CONT TestGenerateFingerprint/invalid_reference_prefix2796=== CONT TestGenerateFingerprint/invalid_store_path_prefix2797=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2798=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2799=== CONT TestGenerateFingerprint/no_references2800--- PASS: TestGenerateFingerprint (0.00s)2801 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2802 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2803 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2804 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2805 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2806 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2807 --- PASS: TestGenerateFingerprint/no_references (0.00s)2808=== CONT TestSignErrors/nil_key2809--- PASS: TestSignErrors (0.00s)2810 --- PASS: TestSignErrors/canceled (0.00s)2811 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2812 --- PASS: TestSignErrors/nil_narinfo (0.00s)2813 --- PASS: TestSignErrors/nil_key (0.00s)2814--- PASS: TestExternalSignerWrongPublicKey (0.01s)2815--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.02s)2816--- PASS: TestExternalSigner (0.02s)2817--- PASS: TestExternalSignerClose (0.02s)2818--- PASS: TestExternalSignerErrors (0.00s)2819 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2820 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2821 --- PASS: TestExternalSignerErrors/null (0.01s)2822 --- PASS: TestExternalSignerErrors/exit_on_request (0.02s)2823 --- PASS: TestExternalSignerErrors/missing_signature_name (0.02s)2824 --- PASS: TestExternalSignerErrors/too_few_signatures (0.02s)2825 --- PASS: TestExternalSignerErrors/program_error (0.02s)2826 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.02s)2827 --- PASS: TestExternalSignerErrors/unrequested_key (0.02s)2828 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.02s)2829 --- PASS: TestExternalSignerErrors/invalid_JSON (0.02s)2830 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.02s)2831 --- PASS: TestExternalSignerErrors/exit_at_startup (0.02s)2832 --- PASS: TestExternalSignerErrors/wrong_id (0.02s)2833 --- PASS: TestExternalSignerErrors/wrong_shape (0.02s)2834 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.02s)2835--- PASS: TestExternalSignerCancellation (0.03s)2836--- PASS: TestExternalSignerRestartsAfterCrash (0.03s)2837PASS2838Running OpenBao signer tests...2839=== RUN TestSign2840=== PAUSE TestSign2841=== RUN TestSignErrors2842=== PAUSE TestSignErrors2843=== RUN TestServe2844=== PAUSE TestServe2845=== RUN TestServeRejectsGarbage2846=== PAUSE TestServeRejectsGarbage2847=== CONT TestSign2848=== CONT TestServeRejectsGarbage2849--- PASS: TestServeRejectsGarbage (0.00s)2850=== CONT TestServe2851--- PASS: TestServe (0.00s)2852=== CONT TestSignErrors2853=== RUN TestSignErrors/http_error2854=== PAUSE TestSignErrors/http_error2855=== RUN TestSignErrors/invalid_json2856=== PAUSE TestSignErrors/invalid_json2857=== RUN TestSignErrors/no_prefix2858=== PAUSE TestSignErrors/no_prefix2859=== RUN TestSignErrors/invalid_base642860=== PAUSE TestSignErrors/invalid_base642861=== CONT TestSignErrors/http_error2862=== CONT TestSignErrors/invalid_base642863=== CONT TestSignErrors/no_prefix2864=== CONT TestSignErrors/invalid_json2865--- PASS: TestSign (1.83s)2866--- PASS: TestSignErrors (0.00s)2867 --- PASS: TestSignErrors/invalid_base64 (1.83s)2868 --- PASS: TestSignErrors/invalid_json (1.83s)2869 --- PASS: TestSignErrors/http_error (1.83s)2870 --- PASS: TestSignErrors/no_prefix (1.83s)2871PASS