niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #477
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestUploadMultipart_PartsInParallel18=== PAUSE TestUploadMultipart_PartsInParallel19=== RUN TestUploadMultipart_ReturnsAfterDroppedBody20=== PAUSE TestUploadMultipart_ReturnsAfterDroppedBody21=== RUN TestPartSizeForNAR22=== PAUSE TestPartSizeForNAR23=== RUN TestDumpPathCaseHackMatchesNix24--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)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 TestScriptTokenBadJSON116=== CONT TestRetryTimeoutOutlastsMaxRetries117=== CONT TestClientSignaturesByStorePath118=== CONT TestShellSplit119=== CONT TestRateLimiterFeedback120=== RUN TestRateLimiterFeedback/429_enables_limiter121=== PAUSE TestRateLimiterFeedback/429_enables_limiter122=== RUN TestRateLimiterFeedback/503_enables_limiter123=== PAUSE TestRateLimiterFeedback/503_enables_limiter124=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter125=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter126=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter127=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter128=== CONT TestStreamPushReportsSkippedPaths129=== CONT TestFileTokenMissing130=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess131=== CONT TestScriptTokenEmptyToken132=== CONT TestStreamPushReportsSignatures1332026/11/10 08:16:29 WARN Rate limiter enabled after throttle name=server-test rate=5134=== CONT TestStreamPushRequestLine135=== CONT TestStreamPushGivesUpOnDeadServer136=== CONT TestStreamPushIsolatesFailures137=== CONT TestStreamPushBatchesUnderLoad138=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false139=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false140=== CONT TestPathInfoCACompatibility141=== RUN TestPathInfoCACompatibility/null_ca_field142=== PAUSE TestPathInfoCACompatibility/null_ca_field143=== RUN TestPathInfoCACompatibility/old_string_format_-_text1442026/11/10 08:16:29 ERROR Upload failed error=boom count=1145=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true1462026/11/10 08:16:29 ERROR Upload failed error=boom count=1147=== CONT TestStreamPushReportsEveryPath1482026/11/10 08:16:29 ERROR Upload failed error="bad path" count=3149=== CONT TestScriptTokenCachesUntilRefresh150=== CONT TestScriptTokenScriptFails151=== CONT TestShellSplitErrors152=== CONT TestEncodeNixBase32153=== CONT TestResolveStorePath154=== CONT TestRegisterUploadedObject_OutlivesPush1552026/11/10 08:16:29 ERROR Upload failed error="connection refused" count=20156=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer157=== CONT TestPathInfoHashCompatibility158=== CONT TestGetStorePathHash159=== CONT TestConvertHashToNix32160=== CONT TestDoWithRetry_FinalResponseBodyReadable161--- PASS: TestScriptTokenEmptyCommand (0.00s)162=== CONT TestDoWithRetry_BodyReplayedViaGetBody163=== CONT TestEncodeNixBase32WithRealHash164=== CONT TestStreamPushStopsWhenCanceled1652026/11/10 08:16:29 ERROR Server seems unavailable, giving up on batch untried=17166=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text167=== CONT TestScriptTokenNoExpiryRerunsEveryCall1682026/11/10 08:16:29 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:34087169=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true170=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)171--- PASS: TestClientSignaturesByStorePath (0.00s)172=== RUN TestEncodeNixBase32/test_string_hash173=== RUN TestConvertHashToNix32/SRI_format_to_Nix32174=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32175=== RUN TestGetStorePathHash/valid_store_path176=== RUN TestConvertHashToNix32/already_Nix32_format177=== PAUSE TestGetStorePathHash/valid_store_path178=== CONT TestDumpPathWriterError179=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)180--- PASS: TestShellSplit (0.00s)181=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon182=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon183=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI1842026/11/10 08:16:29 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:34087185=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI186=== CONT TestParsePathInfoJSONMultiplePaths187=== PAUSE TestEncodeNixBase32/test_string_hash188=== PAUSE TestConvertHashToNix32/already_Nix32_format189=== RUN TestGetStorePathHash/basename_without_hyphen_should_error190=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error191=== CONT TestFileTokenEmpty192=== CONT TestFilterOversizedClosures193=== RUN TestFilterOversizedClosures/no_limit_keeps_everything194=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything195=== CONT TestSetClientTLSErrors196=== CONT TestUploadMultipart_PartsInParallel197--- PASS: TestFileTokenMissing (0.00s)198=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512199=== CONT TestDumpPathSingleFile200=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun201=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive202=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths203=== RUN TestEncodeNixBase32/empty_input204=== CONT TestFileTokenReadsAndCaches205=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512206=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped207=== CONT TestStaticToken208=== RUN TestConvertHashToNix32/invalid_format209=== PAUSE TestConvertHashToNix32/invalid_format210=== CONT TestSetClientTLSDoesNotMutateDefaultTransport211=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error2122026/11/10 08:16:29 WARN Rate limiter enabled after throttle name=server-test rate=5213--- PASS: TestStreamPushReportsSkippedPaths (0.00s)214=== CONT TestDumpPathMatchesNix215=== CONT TestPartSizeForNAR216=== CONT TestUploadMultipart_ReturnsAfterDroppedBody2172026/11/10 08:16:29 WARN Rate limiter enabled after throttle name=server-test rate=5218=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error219=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths2202026/11/10 08:16:29 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:34087221=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped222=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error223=== RUN TestFilterOversizedClosures/all_closures_skipped2242026/11/10 08:16:29 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:352472252026/11/10 08:16:29 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:40529226=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive227=== PAUSE TestEncodeNixBase32/empty_input228--- PASS: TestScriptTokenBadJSON (0.00s)229--- PASS: TestStreamPushReportsSignatures (0.00s)230--- PASS: TestStreamPushIsolatesFailures (0.00s)231--- PASS: TestScriptTokenEmptyToken (0.00s)2322026/11/10 08:16:29 WARN Rate limiter backed off name=server-test rate=5233=== RUN TestPartSizeForNAR/zero_stays_at_minimum2342026/11/10 08:16:29 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:40529235=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum236=== CONT TestCaseHackSuffix237=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths238--- PASS: TestStreamPushReportsEveryPath (0.00s)239=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error2402026/11/10 08:16:29 WARN Rate limiter backed off name=server-test rate=5241=== CONT TestSetClientTLS2422026/11/10 08:16:29 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:34087243=== RUN TestPathInfoCACompatibility/new_structured_format_-_text244=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text245=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method246=== CONT TestParsePathInfoJSON247=== RUN TestParsePathInfoJSON/Nix_format248=== PAUSE TestFilterOversizedClosures/all_closures_skipped249=== PAUSE TestParsePathInfoJSON/Nix_format250=== CONT TestRateLimiterFeedback/429_enables_limiter2512026/11/10 08:16:29 INFO Garbage collection started252=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica253=== CONT TestRegisterUploadedObjectReusesConnections254=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter255=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false256=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry2572026/11/10 08:16:29 WARN Rate limiter enabled after throttle name=server-test rate=5258=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true2592026/11/10 08:16:29 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:42267260=== RUN TestSetClientTLSErrors/missing_cert_file261=== PAUSE TestSetClientTLSErrors/missing_cert_file262=== RUN TestSetClientTLSErrors/missing_key_file263=== PAUSE TestSetClientTLSErrors/missing_key_file264=== RUN TestSetClientTLSErrors/missing_ca_file265=== PAUSE TestSetClientTLSErrors/missing_ca_file266=== RUN TestSetClientTLSErrors/invalid_ca_file267=== PAUSE TestSetClientTLSErrors/invalid_ca_file268=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)2692026/11/10 08:16:29 WARN Rate limiter backed off name=server-test rate=5270=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha5122712026/11/10 08:16:29 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:34087272=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon273=== CONT TestConvertHashToNix32/SRI_format_to_Nix32274=== CONT TestConvertHashToNix32/invalid_format275=== CONT TestConvertHashToNix32/already_Nix32_format276=== CONT TestEncodeNixBase32/empty_input277=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error278=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error279=== CONT TestGetStorePathHash/basename_without_hyphen_should_error280=== CONT TestFilterOversizedClosures/no_limit_keeps_everything281=== CONT TestFilterOversizedClosures/all_closures_skipped2822026/11/10 08:16:29 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=50283=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2842026/11/10 08:16:29 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=2000285=== CONT TestSetClientTLSErrors/missing_cert_file286=== CONT TestSetClientTLSErrors/invalid_ca_file287=== CONT TestSetClientTLSErrors/missing_ca_file288=== RUN TestSetClientTLS/rejects_connection_without_client_cert289=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert290=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA291=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA292=== RUN TestSetClientTLS/preserves_debug_logging_transport293=== PAUSE TestSetClientTLS/preserves_debug_logging_transport294=== CONT TestSetClientTLS/rejects_connection_without_client_cert295=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI296=== CONT TestGetStorePathHash/valid_store_path2972026/11/10 08:16:29 INFO Garbage collection started298=== CONT TestEncodeNixBase32/test_string_hash2992026/11/10 08:16:29 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:34087300--- PASS: TestStreamPushStopsWhenCanceled (0.00s)301--- PASS: TestShellSplitErrors (0.00s)302--- PASS: TestResolveStorePath (0.00s)303--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)304--- PASS: TestEncodeNixBase32WithRealHash (0.00s)305--- PASS: TestScriptTokenScriptFails (0.00s)306--- PASS: TestDoServerRequestAttachesToken (0.01s)307=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths308=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths309=== CONT TestSetClientTLSErrors/missing_key_file310=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method311=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter312=== RUN TestParsePathInfoJSON/Lix_format3132026/11/10 08:16:29 WARN Rate limiter enabled after throttle name=s3-test rate=5314=== PAUSE TestParsePathInfoJSON/Lix_format3152026/11/10 08:16:29 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:35687316=== RUN TestParsePathInfoJSON/empty_input317=== PAUSE TestParsePathInfoJSON/empty_input318=== RUN TestParsePathInfoJSON/whitespace_only319=== CONT TestSetClientTLS/preserves_debug_logging_transport320=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA3212026/11/10 08:16:29 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:34087322--- PASS: TestStaticToken (0.00s)323=== RUN TestPartSizeForNAR/small_stays_at_minimum324--- PASS: TestFileTokenEmpty (0.00s)3252026/11/10 08:16:29 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=0326--- PASS: TestFileTokenReadsAndCaches (0.00s)327=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths328=== CONT TestPathInfoCACompatibility/null_ca_field329=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method3302026/11/10 08:16:29 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:34087331=== CONT TestPathInfoCACompatibility/new_structured_format_-_text332=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive333=== CONT TestPathInfoCACompatibility/old_string_format_-_text334=== PAUSE TestParsePathInfoJSON/whitespace_only335=== PAUSE TestPartSizeForNAR/small_stays_at_minimum336=== CONT TestRateLimiterFeedback/503_enables_limiter337--- PASS: TestRegisterUploadedObject_OutlivesPush (0.07s)338--- PASS: TestDumpPathSingleFile (0.07s)3392026/11/10 08:16:29 WARN Garbage collection finished on another replica. Its statistics are not available here340--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.08s)341--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.08s)342--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.08s)343--- PASS: TestUploadMultipart_ReturnsAfterDroppedBody (0.07s)344--- PASS: TestScriptTokenCachesUntilRefresh (0.08s)345=== RUN TestParsePathInfoJSON/invalid_JSON346=== PAUSE TestParsePathInfoJSON/invalid_JSON347=== CONT TestParsePathInfoJSON/Nix_format3482026/11/10 08:16:29 WARN Rate limiter enabled after throttle name=server-test rate=5349=== CONT TestParsePathInfoJSON/Lix_format3502026/11/10 08:16:29 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:43649351--- PASS: TestStreamPushBatchesUnderLoad (0.00s)352 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)353 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)3542026/11/10 08:16:29 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:34087355=== CONT TestParsePathInfoJSON/empty_input3562026/11/10 08:16:29 WARN Rate limiter backed off name=server-test rate=5357=== CONT TestParsePathInfoJSON/invalid_JSON358=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum359=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum360=== CONT TestParsePathInfoJSON/whitespace_only361--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.07s)362=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts363=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts364--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.08s)365=== RUN TestPartSizeForNAR/1_TiB3662026/11/10 08:16:29 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:34087367=== PAUSE TestPartSizeForNAR/1_TiB368--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.01s)369--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)370--- PASS: TestConvertHashToNix32 (0.01s)371 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)372 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)373 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)374=== RUN TestPartSizeForNAR/5_TiB_S3_max_object375=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object3762026/11/10 08:16:29 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:34087377--- PASS: TestFilterOversizedClosures (0.07s)378 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)379 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)380 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)3812026/11/10 08:16:29 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:32829/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:32829/api/uploads/complete382--- PASS: TestGetStorePathHash (0.07s)383 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)384 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)385 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)386 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)3872026/11/10 08:16:29 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"388--- PASS: TestEncodeNixBase32 (0.07s)389 --- PASS: TestEncodeNixBase32/empty_input (0.00s)390 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)3912026/11/10 08:16:29 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:32829/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:32829/api/uploads/complete392--- PASS: TestPathInfoHashCompatibility (0.00s)393 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)394 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)395 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)396 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)3972026/11/10 08:16:29 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"398--- PASS: TestParsePathInfoJSONMultiplePaths (0.08s)399 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)400 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)4012026/11/10 08:16:29 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:32829/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:32829/api/uploads/complete402--- PASS: TestPathInfoCACompatibility (0.08s)403 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)404 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)405 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)406 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)407 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)4082026/11/10 08:16:29 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"409--- PASS: TestRateLimiterFeedback (0.00s)410 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)411 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.01s)412 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)413 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)414--- PASS: TestParsePathInfoJSON (0.01s)415 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)416 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)417 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)418 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)419 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)420--- PASS: TestSetClientTLSErrors (0.07s)421 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)422 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)423 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)424 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)425--- PASS: TestCaseHackSuffix (0.05s)426=== RUN TestPartSizeForNAR/capped_at_5_GiB427=== PAUSE TestPartSizeForNAR/capped_at_5_GiB428=== CONT TestPartSizeForNAR/zero_stays_at_minimum429--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (0.12s)430=== CONT TestPartSizeForNAR/capped_at_5_GiB431=== CONT TestPartSizeForNAR/5_TiB_S3_max_object432=== CONT TestPartSizeForNAR/1_TiB433=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts434=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum4352026/11/10 08:16:29 http: TLS handshake error from 127.0.0.1:38140: remote error: tls: bad certificate436=== CONT TestPartSizeForNAR/small_stays_at_minimum437--- PASS: TestPartSizeForNAR (0.12s)438 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)439 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)440 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)441 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)442 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)443 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)444 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)4452026/11/10 08:16:29 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:34087446--- PASS: TestSetClientTLS (0.01s)447 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)448 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)449 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.05s)450--- PASS: TestStreamPushRequestLine (0.13s)4512026/11/10 08:16:29 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:340874522026/11/10 08:16:29 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:340874532026/11/10 08:16:29 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:340874542026/11/10 08:16:29 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:340874552026/11/10 08:16:29 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:340874562026/11/10 08:16:29 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:340874572026/11/10 08:16:29 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:34087458--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.14s)459--- PASS: TestRegisterUploadedObjectReusesConnections (0.06s)460--- PASS: TestDumpPathWriterError (0.14s)461--- PASS: TestDumpPathMatchesNix (0.18s)462--- PASS: TestUploadMultipart_PartsInParallel (0.73s)463--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)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/postgres2177983782/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/postgres2177983782/data -l logfile start492493/build/postgres2177983782:5432 - no response4942026-11-10 08:16:31.114 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4952026-11-10 08:16:31.116 UTC [129] LOG: listening on Unix socket "/build/postgres2177983782/.s.PGSQL.5432"4962026-11-10 08:16:31.121 UTC [136] LOG: database system was shut down at 2026-11-10 08:16:30 UTC4972026-11-10 08:16:31.125 UTC [129] LOG: database system is ready to accept connections498/build/postgres2177983782:5432 - accepting connections499=== RUN TestAbortSucceeded500=== PAUSE TestAbortSucceeded501=== RUN TestService_AuthMiddleware502=== PAUSE TestService_AuthMiddleware503=== RUN TestService_AuthMiddleware_MTLSProxyHeader504=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader505=== RUN TestService_AuthMiddleware_MTLSBoundSubjects506=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects507=== RUN TestService_ReadAuthMiddleware508=== PAUSE TestService_ReadAuthMiddleware509=== RUN TestService_AuthMiddleware_OIDC510=== PAUSE TestService_AuthMiddleware_OIDC511=== RUN TestService_RequireScope_OIDC512=== PAUSE TestService_RequireScope_OIDC513=== RUN TestService_ReadScope_PublicByDefault514=== PAUSE TestService_ReadScope_PublicByDefault515=== RUN TestCacheConfigHandler516=== PAUSE TestCacheConfigHandler517=== RUN TestCacheStatsHandler518=== PAUSE TestCacheStatsHandler519=== RUN TestClientCADerivations520=== PAUSE TestClientCADerivations521=== RUN TestClientErrorHandling522=== PAUSE TestClientErrorHandling523=== RUN TestClientIntegration524=== PAUSE TestClientIntegration525=== RUN TestClientMultipleUploads526=== PAUSE TestClientMultipleUploads527=== RUN TestClientWithDependencies528=== PAUSE TestClientWithDependencies529=== RUN TestClientSharedPathCommittedMidPush530=== PAUSE TestClientSharedPathCommittedMidPush531=== RUN TestPinProtectsFromGC532=== PAUSE TestPinProtectsFromGC533=== RUN TestClientPushesUseOnePush534=== PAUSE TestClientPushesUseOnePush535=== RUN TestClientFallsBackToClosures536=== PAUSE TestClientFallsBackToClosures537=== RUN TestDeleteClosuresRacingPins538=== PAUSE TestDeleteClosuresRacingPins539=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock540=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock541=== RUN TestResolveDBConnectionString542=== PAUSE TestResolveDBConnectionString543=== RUN TestConnectWaitsForAPeerMigration544=== PAUSE TestConnectWaitsForAPeerMigration545=== RUN TestLeadElectsOneAndHandsOver546=== PAUSE TestLeadElectsOneAndHandsOver547=== RUN TestLeadIncumbentWinsAfterRestart5482026/11/10 08:16:31 INFO lead: acquired remote=192.0.2.1:12345492026/11/10 08:16:32 INFO lead: released remote=192.0.2.1:12345502026/11/10 08:16:32 INFO lead: acquired remote=192.0.2.1:12345512026/11/10 08:16:33 INFO lead: released remote=192.0.2.1:1234552--- PASS: TestLeadIncumbentWinsAfterRestart (1.91s)553=== RUN TestLeadIncumbentAnnouncesAtOnce554=== PAUSE TestLeadIncumbentAnnouncesAtOnce555=== RUN TestLeadEndsOnShutdown556=== PAUSE TestLeadEndsOnShutdown557=== RUN TestLeadEndsWhenItsConnectionHangs5582026/11/10 08:16:33 INFO lead: acquired remote=192.0.2.1:12345592026-11-10 08:16:34.971 UTC [576] FATAL: terminating connection due to administrator command5602026/11/10 08:16:35 INFO lead: acquired remote=192.0.2.1:12345612026/11/10 08:16:36 WARN lead: lock connection lost error="timeout: context deadline exceeded"5622026/11/10 08:16:36 INFO lead: released remote=192.0.2.1:12345632026/11/10 08:16:36 INFO lead: released remote=192.0.2.1:1234564--- PASS: TestLeadEndsWhenItsConnectionHangs (3.12s)565=== RUN TestGCAdvisoryLockBlocksConcurrentRun566=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun567=== RUN TestGCBugBareHashReferences568=== PAUSE TestGCBugBareHashReferences569=== RUN TestGCMetrics570=== PAUSE TestGCMetrics571=== RUN TestPushDedupSurvivesConcurrentGC572=== PAUSE TestPushDedupSurvivesConcurrentGC573=== RUN TestDeduplicatedObjectsRecordedAsPending574=== PAUSE TestDeduplicatedObjectsRecordedAsPending575=== RUN TestGCSweepSkipsPendingObjects576=== PAUSE TestGCSweepSkipsPendingObjects577=== RUN TestTombstonedObjectOfferedWithoutWaiting578=== PAUSE TestTombstonedObjectOfferedWithoutWaiting579=== RUN TestGCSweepDeliversEachKeyOnce580=== PAUSE TestGCSweepDeliversEachKeyOnce581=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection582=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection583=== RUN TestForceGCDuringPushOffersSweptObject584=== PAUSE TestForceGCDuringPushOffersSweptObject585=== RUN TestFailedS3DeleteKeepsTombstone586=== PAUSE TestFailedS3DeleteKeepsTombstone587=== RUN TestSweepSkipsRowsLockedByPush588=== PAUSE TestSweepSkipsRowsLockedByPush589=== RUN TestRegisterCompletedObjectNeedsPendingRow590=== PAUSE TestRegisterCompletedObjectNeedsPendingRow591=== RUN TestGetExistingObjectsLocksRows592=== PAUSE TestGetExistingObjectsLocksRows593=== RUN TestSweepRechecksPendingAfterLocking594=== PAUSE TestSweepRechecksPendingAfterLocking595=== RUN TestPushWaitsForSweepHoldingRow596=== PAUSE TestPushWaitsForSweepHoldingRow597=== RUN TestCommitRacingPendingCleanupKeepsObjects598=== PAUSE TestCommitRacingPendingCleanupKeepsObjects599=== RUN TestGCEndsOnShutdown600=== PAUSE TestGCEndsOnShutdown601=== RUN TestGCTaskStore_StartNew602=== PAUSE TestGCTaskStore_StartNew603=== RUN TestGCTaskStore_DeduplicateSameParams604=== PAUSE TestGCTaskStore_DeduplicateSameParams605=== RUN TestGCTaskStore_ConflictDifferentParams606=== PAUSE TestGCTaskStore_ConflictDifferentParams607=== RUN TestGCTaskStore_GetEmpty608=== PAUSE TestGCTaskStore_GetEmpty609=== RUN TestGCTaskStore_GetReturnsLatest610=== PAUSE TestGCTaskStore_GetReturnsLatest611=== RUN TestGCTaskStore_CompletedAllowsNewTask612=== PAUSE TestGCTaskStore_CompletedAllowsNewTask613=== RUN TestGCTaskStore_PhaseUpdates614=== PAUSE TestGCTaskStore_PhaseUpdates615=== RUN TestGCTaskStore_Fail616=== PAUSE TestGCTaskStore_Fail617=== RUN TestGracefulShutdownDrainsInflight618=== PAUSE TestGracefulShutdownDrainsInflight619=== RUN TestService_healthCheckHandler620=== PAUSE TestService_healthCheckHandler621=== RUN TestService_readinessHandler622=== PAUSE TestService_readinessHandler623=== RUN TestGenerateLandingPage624=== PAUSE TestGenerateLandingPage625=== RUN TestEnsureAbortUploadsRule626=== PAUSE TestEnsureAbortUploadsRule627=== RUN TestCacheConfigHandlerMaxNarSize628=== PAUSE TestCacheConfigHandlerMaxNarSize629=== RUN TestCreatePendingClosureRejectsOversizedNAR630=== PAUSE TestCreatePendingClosureRejectsOversizedNAR631=== RUN TestNARDeduplicationMetadataUploadBug632=== PAUSE TestNARDeduplicationMetadataUploadBug633=== RUN TestMetricsInventory634=== PAUSE TestMetricsInventory635=== RUN TestMetricsCommit636=== PAUSE TestMetricsCommit637=== RUN TestService_NativeMTLS638=== PAUSE TestService_NativeMTLS639=== RUN TestServerTLSConfig640=== PAUSE TestServerTLSConfig641=== RUN TestMultipartCleanup642=== PAUSE TestMultipartCleanup643=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded644=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded645=== RUN TestPendingCleanupUsesOneCutoff646=== PAUSE TestPendingCleanupUsesOneCutoff647=== RUN TestObjectStatsTrigger648=== PAUSE TestObjectStatsTrigger649=== RUN TestObjectStatsUpdatedOncePerCommit650=== PAUSE TestObjectStatsUpdatedOncePerCommit651=== RUN TestOrphanedObjectsGC652=== PAUSE TestOrphanedObjectsGC653=== RUN TestOrphanedObjectsGCStressTest654=== PAUSE TestOrphanedObjectsGCStressTest655=== RUN TestCreatePin_ReservedPins656=== PAUSE TestCreatePin_ReservedPins657=== RUN TestPresentReportsOnlyClosureRoots658=== PAUSE TestPresentReportsOnlyClosureRoots659=== RUN TestPresentRefreshesOnlyStaleClosures660=== PAUSE TestPresentRefreshesOnlyStaleClosures661=== RUN TestPresentNotReportedWhileGCDeletesClosure662=== PAUSE TestPresentNotReportedWhileGCDeletesClosure663=== RUN TestParseSingleRange664=== PAUSE TestParseSingleRange665=== RUN TestProxyHeadersOnlyTrustedOnSocket6662026/11/10 08:16:36 INFO Starting HTTP server address=127.0.0.1:330316672026/11/10 08:16:36 INFO Starting HTTP server address=proxy.sock6682026/11/10 08:16:36 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6692026/11/10 08:16:36 INFO Shutdown signal received, draining in-flight requests timeout=10s670--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.13s)671=== RUN TestIsValidCachePath672=== PAUSE TestIsValidCachePath673=== RUN TestReadProxyNarinfo674=== PAUSE TestReadProxyNarinfo675=== RUN TestReadProxyNarinfoAlreadyDecompressed676=== PAUSE TestReadProxyNarinfoAlreadyDecompressed677=== RUN TestReadProxyContentNegotiation678=== PAUSE TestReadProxyContentNegotiation679=== RUN TestReadProxyNarStreaming680=== PAUSE TestReadProxyNarStreaming681=== RUN TestReadProxy404682=== PAUSE TestReadProxy404683=== RUN TestReadProxyInvalidPath684=== PAUSE TestReadProxyInvalidPath685=== RUN TestReadProxyHead686=== PAUSE TestReadProxyHead687=== RUN TestReadProxyOutlastsServerWriteTimeout688=== PAUSE TestReadProxyOutlastsServerWriteTimeout689=== RUN TestReadProxyConditionalGet690=== PAUSE TestReadProxyConditionalGet691=== RUN TestReadProxyRootRedirectsToIndexHTML692=== PAUSE TestReadProxyRootRedirectsToIndexHTML693=== RUN TestReadProxyDisabled694=== PAUSE TestReadProxyDisabled695=== RUN TestReadRedirectNar696=== PAUSE TestReadRedirectNar697=== RUN TestReadRedirectKeepsNarinfoProxied698=== PAUSE TestReadRedirectKeepsNarinfoProxied699=== RUN TestReadProxyRangeRequest700=== PAUSE TestReadProxyRangeRequest701=== RUN TestReadRedirectUsesPublicS3URL702=== PAUSE TestReadRedirectUsesPublicS3URL703=== RUN TestPush_OverlappingRootsStoreOneRowPerKey704=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey705=== RUN TestPush_CompleteCommitsEveryRoot706=== PAUSE TestPush_CompleteCommitsEveryRoot707=== RUN TestPush_RepeatedRootCommitsOnce708=== PAUSE TestPush_RepeatedRootCommitsOnce709=== RUN TestPush_CompleteWaitsForCleanupOfThePush710=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush711=== RUN TestPush_RootsAreLockedInByteOrder712=== PAUSE TestPush_RootsAreLockedInByteOrder713=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit714=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit715=== RUN TestPush_RejectsBadRequests716=== PAUSE TestPush_RejectsBadRequests717=== RUN TestPush_SignsNarinfosOfItsPendingObjects718=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects719=== RUN TestSharedNarBothUploadsComplete720=== PAUSE TestSharedNarBothUploadsComplete721=== RUN TestCompleteMultipartUpload_ErrorButObjectExists722=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists723=== RUN TestCompletedNarNotReofferedAcrossClosures724=== PAUSE TestCompletedNarNotReofferedAcrossClosures725=== RUN TestPresignedUploadRegisteredBeforeCommit726=== PAUSE TestPresignedUploadRegisteredBeforeCommit727=== RUN TestService_Rustfstest728=== PAUSE TestService_Rustfstest729=== RUN TestParseSize730=== PAUSE TestParseSize731=== RUN TestSkippedUploadsHandler732=== PAUSE TestSkippedUploadsHandler733=== RUN TestSystemdListenerNotActivated734--- PASS: TestSystemdListenerNotActivated (0.00s)735=== RUN TestWatchdogBeatsWhenHealthy736--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)737=== RUN TestWatchdogSkipsWhenUnhealthy7382026/11/10 08:16:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7392026/11/10 08:16:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7402026/11/10 08:16:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7412026/11/10 08:16:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7422026/11/10 08:16:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7432026/11/10 08:16:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7442026/11/10 08:16:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7452026/11/10 08:16:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7462026/11/10 08:16:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7472026/11/10 08:16:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"748--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)749=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle750=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle751=== RUN TestProxyWriteTimeout752=== PAUSE TestProxyWriteTimeout753=== RUN TestPendingClosureWriteTimeout754=== PAUSE TestPendingClosureWriteTimeout755=== RUN TestIsValidUploadKey756=== PAUSE TestIsValidUploadKey757=== RUN TestUploadHandlersRejectInvalidKeys758=== PAUSE TestUploadHandlersRejectInvalidKeys759=== RUN TestUploadHandlersRejectOversizedBody760=== PAUSE TestUploadHandlersRejectOversizedBody761=== RUN TestService_cleanupPendingClosuresHandler762=== PAUSE TestService_cleanupPendingClosuresHandler763=== RUN TestService_createPendingClosureHandler764=== PAUSE TestService_createPendingClosureHandler765=== RUN TestService_verifyS3Integrity766=== PAUSE TestService_verifyS3Integrity767=== RUN TestService_verifyS3ReuploadsStaleNarinfo768=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo769=== RUN TestCompleteMultipartUnregistered770=== PAUSE TestCompleteMultipartUnregistered771=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT772=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT773=== CONT TestAbortSucceeded774=== CONT TestPendingClosureWriteTimeout775--- PASS: TestAbortSucceeded (0.00s)776=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT777=== CONT TestCompleteMultipartUnregistered778=== CONT TestService_verifyS3ReuploadsStaleNarinfo779=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed780=== CONT TestService_verifyS3Integrity781=== CONT TestService_createPendingClosureHandler782=== CONT TestService_cleanupPendingClosuresHandler783=== CONT TestUploadHandlersRejectOversizedBody784=== CONT TestUploadHandlersRejectInvalidKeys785=== CONT TestIsValidUploadKey786=== CONT TestReadProxyNarinfo787=== CONT TestIsValidCachePath788=== CONT TestParseSingleRange789=== CONT TestPresentNotReportedWhileGCDeletesClosure790=== CONT TestPresentRefreshesOnlyStaleClosures791=== CONT TestPresentReportsOnlyClosureRoots792=== CONT TestCreatePin_ReservedPins793=== CONT TestOrphanedObjectsGCStressTest794=== CONT TestOrphanedObjectsGC795=== CONT TestObjectStatsUpdatedOncePerCommit796=== CONT TestObjectStatsTrigger797=== CONT TestPendingCleanupUsesOneCutoff798=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded799=== CONT TestMultipartCleanup800=== RUN TestPendingClosureWriteTimeout/empty801=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed802=== RUN TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed803=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed804=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost805=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost806=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info807=== RUN TestIsValidUploadKey/narinfo808=== RUN TestIsValidCachePath/narinfo809=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale810=== PAUSE TestIsValidCachePath/narinfo811=== PAUSE TestIsValidUploadKey/narinfo812=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info813=== RUN TestParseSingleRange/none814=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed815=== PAUSE TestPendingClosureWriteTimeout/empty816=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale817=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars818=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh819=== RUN TestIsValidUploadKey/nar_zst820=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal821=== RUN TestPendingClosureWriteTimeout/400_objects822=== PAUSE TestParseSingleRange/none823=== RUN TestParseSingleRange/unknown_unit824=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed825=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars826=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh827=== PAUSE TestIsValidUploadKey/nar_zst828=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal829=== PAUSE TestPendingClosureWriteTimeout/400_objects830=== PAUSE TestParseSingleRange/unknown_unit831=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed832=== RUN TestIsValidCachePath/nar_zst833=== PAUSE TestIsValidCachePath/nar_zst834=== RUN TestIsValidCachePath/nar_xz835=== PAUSE TestIsValidCachePath/nar_xz836=== RUN TestIsValidCachePath/nar_bz2837=== CONT TestServerTLSConfig838=== RUN TestServerTLSConfig/no_client_CA839=== RUN TestIsValidUploadKey/nar_xz840=== PAUSE TestIsValidUploadKey/nar_xz841=== RUN TestIsValidUploadKey/nar_plain842=== PAUSE TestIsValidUploadKey/nar_plain843=== RUN TestIsValidUploadKey/listing844=== PAUSE TestIsValidUploadKey/listing845=== RUN TestIsValidUploadKey/build_log846=== PAUSE TestIsValidUploadKey/build_log847=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key848=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key849=== RUN TestPendingClosureWriteTimeout/670k_objects850=== RUN TestParseSingleRange/multi-range_ignored851=== PAUSE TestParseSingleRange/multi-range_ignored852=== RUN TestParseSingleRange/malformed_no_dash853=== PAUSE TestParseSingleRange/malformed_no_dash854=== RUN TestParseSingleRange/malformed_both_empty855=== PAUSE TestParseSingleRange/malformed_both_empty856=== RUN TestParseSingleRange/malformed_end_before_start857=== PAUSE TestParseSingleRange/malformed_end_before_start858=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed859=== PAUSE TestIsValidCachePath/nar_bz2860=== RUN TestIsValidCachePath/nar_uncompressed861=== PAUSE TestIsValidCachePath/nar_uncompressed862=== RUN TestIsValidCachePath/ls863=== PAUSE TestIsValidCachePath/ls864=== RUN TestIsValidCachePath/log865=== PAUSE TestIsValidCachePath/log866=== PAUSE TestServerTLSConfig/no_client_CA867=== RUN TestIsValidUploadKey/build_log_home-manager_file868=== PAUSE TestIsValidUploadKey/build_log_home-manager_file869=== RUN TestIsValidUploadKey/build_log_plus_in_name870=== PAUSE TestIsValidUploadKey/build_log_plus_in_name871=== RUN TestIsValidUploadKey/build_log_question_mark872=== PAUSE TestIsValidUploadKey/build_log_question_mark873=== RUN TestIsValidUploadKey/build_log_equals874=== PAUSE TestIsValidUploadKey/build_log_equals875=== RUN TestIsValidUploadKey/realisation876=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key877=== PAUSE TestPendingClosureWriteTimeout/670k_objects878=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key879=== RUN TestParseSingleRange/closed880=== PAUSE TestParseSingleRange/closed881=== RUN TestParseSingleRange/open-ended882=== PAUSE TestParseSingleRange/open-ended883=== RUN TestParseSingleRange/end_clamped_to_size884=== PAUSE TestParseSingleRange/end_clamped_to_size885=== RUN TestParseSingleRange/suffix886=== PAUSE TestParseSingleRange/suffix887=== CONT TestService_NativeMTLS888=== RUN TestIsValidCachePath/realisation889=== PAUSE TestIsValidCachePath/realisation890=== RUN TestIsValidCachePath/nix-cache-info891=== PAUSE TestIsValidCachePath/nix-cache-info892=== RUN TestIsValidCachePath/index.html893=== PAUSE TestIsValidCachePath/index.html894=== RUN TestIsValidCachePath/traversal_parent895=== PAUSE TestIsValidCachePath/traversal_parent896=== RUN TestIsValidCachePath/traversal_in_middle897=== RUN TestServerTLSConfig/missing_CA_file898=== PAUSE TestIsValidUploadKey/realisation899=== RUN TestIsValidUploadKey/realisation_plus_in_output900=== PAUSE TestIsValidUploadKey/realisation_plus_in_output901=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline902=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline903=== CONT TestMetricsCommit904=== RUN TestParseSingleRange/suffix_exceeds_size905=== PAUSE TestParseSingleRange/suffix_exceeds_size906=== RUN TestParseSingleRange/single_byte907=== PAUSE TestParseSingleRange/single_byte908=== RUN TestParseSingleRange/start_past_EOF909=== PAUSE TestParseSingleRange/start_past_EOF910=== PAUSE TestIsValidCachePath/traversal_in_middle911=== PAUSE TestServerTLSConfig/missing_CA_file912=== RUN TestServerTLSConfig/not_a_PEM_file913=== PAUSE TestServerTLSConfig/not_a_PEM_file914=== RUN TestIsValidUploadKey/nix-cache-info915=== PAUSE TestIsValidUploadKey/nix-cache-info916=== RUN TestIsValidUploadKey/index.html917=== PAUSE TestIsValidUploadKey/index.html918=== RUN TestIsValidUploadKey/narinfo_key,_nar_type919=== CONT TestMetricsInventory920=== RUN TestParseSingleRange/start_far_past_EOF921=== PAUSE TestParseSingleRange/start_far_past_EOF922=== RUN TestIsValidCachePath/invalid_char_e923=== PAUSE TestIsValidCachePath/invalid_char_e924=== RUN TestIsValidCachePath/invalid_char_u925=== PAUSE TestIsValidCachePath/invalid_char_u926=== RUN TestIsValidCachePath/random_path927=== PAUSE TestIsValidCachePath/random_path928=== RUN TestIsValidCachePath/empty929=== CONT TestNARDeduplicationMetadataUploadBug930=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type931=== CONT TestCreatePendingClosureRejectsOversizedNAR932=== PAUSE TestIsValidCachePath/empty933=== RUN TestIsValidUploadKey/nar_key,_narinfo_type934=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type935=== RUN TestIsValidUploadKey/listing_key,_narinfo_type936=== RUN TestIsValidCachePath/leading_slash937=== PAUSE TestIsValidCachePath/leading_slash938=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type939=== RUN TestIsValidUploadKey/traversal940=== PAUSE TestIsValidUploadKey/traversal941=== RUN TestIsValidUploadKey/traversal_nar942=== PAUSE TestIsValidUploadKey/traversal_nar943=== RUN TestIsValidUploadKey/absolute944=== PAUSE TestIsValidUploadKey/absolute945=== RUN TestIsValidUploadKey/empty_key946=== PAUSE TestIsValidUploadKey/empty_key947=== RUN TestIsValidUploadKey/unknown_type948=== PAUSE TestIsValidUploadKey/unknown_type949=== RUN TestIsValidCachePath/wrong_extension950=== PAUSE TestIsValidCachePath/wrong_extension951=== RUN TestIsValidCachePath/short_hash952=== PAUSE TestIsValidCachePath/short_hash953=== CONT TestCacheConfigHandlerMaxNarSize954=== CONT TestEnsureAbortUploadsRule9552026/11/10 08:16:37 INFO Received uploads request method=POST path=/api/pending_closures956--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)957=== CONT TestGenerateLandingPage958--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)959=== CONT TestService_readinessHandler960--- PASS: TestGenerateLandingPage (0.00s)961=== CONT TestService_healthCheckHandler9622026/11/10 08:16:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38585/oidc963=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure964=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure965=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart966=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart967=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts968=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts969=== CONT TestGracefulShutdownDrainsInflight9702026/11/10 08:16:37 INFO Starting HTTP server address=127.0.0.1:393719712026/11/10 08:16:37 INFO Shutdown signal received, draining in-flight requests timeout=10s972--- PASS: TestGracefulShutdownDrainsInflight (0.07s)973=== CONT TestGCTaskStore_Fail974--- PASS: TestGCTaskStore_Fail (0.00s)975=== CONT TestGCTaskStore_PhaseUpdates976--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)977=== CONT TestGCTaskStore_CompletedAllowsNewTask978--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)979=== CONT TestGCTaskStore_GetReturnsLatest980--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)981=== CONT TestGCTaskStore_GetEmpty982--- PASS: TestGCTaskStore_GetEmpty (0.00s)983=== CONT TestGCTaskStore_ConflictDifferentParams984--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)985=== CONT TestGCTaskStore_DeduplicateSameParams986--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)987=== CONT TestGCTaskStore_StartNew988--- PASS: TestGCTaskStore_StartNew (0.00s)989=== CONT TestGCEndsOnShutdown990=== RUN TestGCEndsOnShutdown/before_the_run991=== PAUSE TestGCEndsOnShutdown/before_the_run992=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete993=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete994=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark995=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark996=== CONT TestCommitRacingPendingCleanupKeepsObjects9972026/11/10 08:16:37 INFO Received uploads request method=POST path=/api/pending_closures998--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.42s)999=== CONT TestPushWaitsForSweepHoldingRow10002026/11/10 08:16:37 INFO Received uploads request method=POST path=/api/pending_closures10012026/11/10 08:16:37 INFO Received uploads request method=POST path=/api/pending_closures10022026/11/10 08:16:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10032026/11/10 08:16:37 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1004--- PASS: TestCompleteMultipartUnregistered (0.46s)1005=== CONT TestSweepRechecksPendingAfterLocking10062026/11/10 08:16:37 INFO Received cleanup request method=DELETE path=/api/pending_closures10072026/11/10 08:16:37 INFO Received uploads request method=POST path=/api/pending_closures10082026/11/10 08:16:37 INFO Received uploads request method=POST path=/api/pending_closures10092026/11/10 08:16:37 INFO Received uploads request method=POST path=/api/pending_closures10102026/11/10 08:16:37 INFO Received uploads request method=POST path=/api/pending_closures1011--- PASS: TestPresentReportsOnlyClosureRoots (0.56s)1012=== CONT TestGetExistingObjectsLocksRows10132026/11/10 08:16:37 INFO Received cleanup request method=DELETE path=/api/pending_closures10142026/11/10 08:16:37 INFO Aborted multipart uploads count=0 kept=010152026/11/10 08:16:37 INFO Received uploads request method=POST path=/api/pending_closures10162026/11/10 08:16:37 INFO Received cleanup request method=DELETE path=/api/pending_closures10172026/11/10 08:16:37 INFO Aborted multipart uploads count=1 kept=010182026/11/10 08:16:37 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10192026-11-10 08:16:37.530 UTC [653] ERROR: Closure does not exist: id=110202026-11-10 08:16:37.530 UTC [653] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE10212026-11-10 08:16:37.530 UTC [653] STATEMENT: -- name: CommitPendingClosure :one1022 SELECT commit_pending_closure($1::bigint)::bigint1023 1024--- PASS: TestService_cleanupPendingClosuresHandler (0.60s)1025=== CONT TestPush_CompleteCommitsEveryRoot10262026/11/10 08:16:37 INFO Received uploads request method=POST path=/api/pending_closures1027--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.62s)1028=== CONT TestRegisterCompletedObjectNeedsPendingRow1029--- PASS: TestPresentRefreshesOnlyStaleClosures (0.64s)1030=== CONT TestSweepSkipsRowsLockedByPush1031--- PASS: TestObjectStatsTrigger (0.72s)1032=== CONT TestProxyWriteTimeout1033=== RUN TestProxyWriteTimeout/narinfo1034=== PAUSE TestProxyWriteTimeout/narinfo1035=== RUN TestProxyWriteTimeout/1_GiB_nar1036=== PAUSE TestProxyWriteTimeout/1_GiB_nar1037=== RUN TestProxyWriteTimeout/10_GiB_nar1038=== PAUSE TestProxyWriteTimeout/10_GiB_nar1039=== RUN TestProxyWriteTimeout/unknown_size1040=== PAUSE TestProxyWriteTimeout/unknown_size1041=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1042--- PASS: TestService_healthCheckHandler (0.68s)1043=== CONT TestSkippedUploadsHandler10442026/11/10 08:16:37 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001045--- PASS: TestSkippedUploadsHandler (0.01s)1046=== CONT TestFailedS3DeleteKeepsTombstone10472026/11/10 08:16:37 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1048--- PASS: TestReadProxyNarinfo (0.83s)1049=== CONT TestParseSize1050--- PASS: TestParseSize (0.00s)1051=== CONT TestForceGCDuringPushOffersSweptObject1052=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1053=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1054=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1055=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1056=== CONT TestService_Rustfstest1057--- PASS: TestObjectStatsUpdatedOncePerCommit (0.83s)1058=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10592026/11/10 08:16:37 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10602026/11/10 08:16:37 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1061--- PASS: TestService_NativeMTLS (0.75s)1062=== CONT TestPresignedUploadRegisteredBeforeCommit10632026/11/10 08:16:37 INFO Received uploads request method=POST path=/api/pending_closures10642026/11/10 08:16:37 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10652026/11/10 08:16:37 WARN Refused reserved pin name=worker-x86_64-linux10662026/11/10 08:16:37 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10672026/11/10 08:16:37 INFO Received create pin request method=POST path=/api/pins/my-app10682026/11/10 08:16:37 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1069--- PASS: TestCreatePin_ReservedPins (0.93s)1070=== CONT TestCompletedNarNotReofferedAcrossClosures10712026/11/10 08:16:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1072--- PASS: TestMetricsInventory (0.87s)1073=== CONT TestGCSweepDeliversEachKeyOnce10742026/11/10 08:16:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10752026/11/10 08:16:37 INFO Received push request method=POST path=/api/pushes10762026/11/10 08:16:37 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MzgzOGI3MDItYjg3Ny00NTY5LWFlMGMtNTZmYzBlZWVhZTQyLmE4MWU2ZjI5LTI4MDMtNDI5YS05YWMzLTBmMjZiMTk2OWVkOHgxNzk0Mjk4NTk3NDI4MDYxOTMy parts=1010772026/11/10 08:16:37 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10782026/11/10 08:16:37 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MzgzOGI3MDItYjg3Ny00NTY5LWFlMGMtNTZmYzBlZWVhZTQyLmYxOTk2MjljLWJiNGQtNDRiNy1hZjBmLWNiYTcxNzQ1MjRmMHgxNzk0Mjk4NTk3NDU4NTM0MTE5 parts=1010792026/11/10 08:16:37 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10802026/11/10 08:16:37 INFO Completed upload id=1 objects=2 duration=5.115799ms10812026/11/10 08:16:37 INFO Received complete push request method=POST path=/api/pushes/1/complete10822026/11/10 08:16:37 INFO Completed upload id=1 objects=2 duration=5.560339ms10832026/11/10 08:16:37 INFO Received uploads request method=POST path=/api/pending_closures10842026/11/10 08:16:37 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010852026/11/10 08:16:37 INFO Received cleanup request method=DELETE path=/api/pending_closures10862026/11/10 08:16:37 INFO Received uploads request method=POST path=/api/pending_closures10872026/11/10 08:16:37 INFO Received uploads request method=POST path=/api/pending_closures10882026/11/10 08:16:37 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket20/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""10892026/11/10 08:16:37 INFO Aborted multipart uploads count=0 kept=110902026/11/10 08:16:37 INFO Starting cleanup of old closures method=DELETE path=/api/closures10912026/11/10 08:16:37 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10922026/11/10 08:16:37 WARN Found objects in DB but missing from S3, will re-upload count=11093--- PASS: TestService_verifyS3Integrity (1.01s)1094=== CONT TestCompleteMultipartUpload_ErrorButObjectExists10952026/11/10 08:16:37 INFO Completed push id=1 objects=4 duration=12.707824ms10962026/11/10 08:16:37 INFO Received cleanup request method=DELETE path=/api/pending_closures10972026/11/10 08:16:37 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10982026/11/10 08:16:37 INFO Aborted multipart uploads count=0 kept=010992026/11/10 08:16:37 INFO Aborted multipart uploads count=1 kept=011002026/11/10 08:16:37 INFO Completed upload id=2 objects=2 duration=1.517227ms1101--- PASS: TestMultipartCleanup (1.02s)1102=== CONT TestTombstonedObjectOfferedWithoutWaiting1103--- PASS: TestMetricsCommit (0.92s)1104=== CONT TestSharedNarBothUploadsComplete11052026/11/10 08:16:37 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=011062026/11/10 08:16:37 INFO Vacuumed table table=pending_closures11072026/11/10 08:16:37 INFO Vacuumed table table=pending_objects11082026/11/10 08:16:37 INFO Vacuumed table table=multipart_uploads11092026/11/10 08:16:37 INFO Vacuumed table table=closures11102026/11/10 08:16:37 INFO Vacuumed table table=objects11112026/11/10 08:16:37 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001112=== NAME TestNARDeduplicationMetadataUploadBug1113 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3678491981/001/store/hw8r8r196xpc85bcqvvbplhbdk486l3s-file1.txt1114--- PASS: TestService_createPendingClosureHandler (1.06s)1115=== CONT TestPush_SignsNarinfosOfItsPendingObjects11162026/11/10 08:16:38 INFO Installed lifecycle rule aborting incomplete NAR uploads bucket=bucket26 days=21117--- PASS: TestEnsureAbortUploadsRule (0.98s)1118=== CONT TestGCSweepSkipsPendingObjects11192026/11/10 08:16:38 WARN readiness check failed error="closed pool"1120--- PASS: TestService_readinessHandler (0.99s)1121=== CONT TestPush_RejectsBadRequests11222026/11/10 08:16:38 INFO Aborted multipart uploads count=0 kept=011232026/11/10 08:16:38 WARN Force mode enabled - objects will be deleted immediately without grace period11242026/11/10 08:16:38 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=011252026/11/10 08:16:38 INFO Vacuumed table table=pending_closures11262026/11/10 08:16:38 INFO Vacuumed table table=pending_objects11272026/11/10 08:16:38 INFO Vacuumed table table=multipart_uploads11282026/11/10 08:16:38 INFO Vacuumed table table=closures11292026/11/10 08:16:38 INFO Vacuumed table table=objects1130--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.87s)1131=== CONT TestDeduplicatedObjectsRecordedAsPending11322026/11/10 08:16:38 INFO Received uploads request method=POST path=/api/pending_closures11332026/11/10 08:16:38 INFO Received push request method=POST path=/api/pushes11342026/11/10 08:16:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11352026/11/10 08:16:38 INFO Uploading hw8r8r196xpc85bcqvvbplhbdk486l3s-file1.txt (160B)11362026/11/10 08:16:38 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11372026/11/10 08:16:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11382026/11/10 08:16:38 WARN Failed to register uploaded object key=hw8r8r196xpc85bcqvvbplhbdk486l3s.ls error="server returned 404: 404 page not found\n"11392026/11/10 08:16:38 INFO Signed narinfos id=1 count=111402026/11/10 08:16:38 INFO Uploading 1 narinfos11412026/11/10 08:16:38 INFO Received complete push request method=POST path=/api/pushes/1/complete11422026/11/10 08:16:38 WARN Failed to register uploaded object key=hw8r8r196xpc85bcqvvbplhbdk486l3s.narinfo error="server returned 404: 404 page not found\n"11432026/11/10 08:16:38 INFO Completed push id=1 objects=3 duration=6.321717ms11442026/11/10 08:16:38 INFO Upload complete. (87ms)1145=== NAME TestNARDeduplicationMetadataUploadBug1146 metadata_upload_test.go:54: Retrieved narinfo from S3:1147 StorePath: /build/TestNARDeduplicationMetadataUploadBug3678491981/001/store/hw8r8r196xpc85bcqvvbplhbdk486l3s-file1.txt1148 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1149 Compression: zstd1150 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1151 NarSize: 1601152 References: 1153 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1154 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1155 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1156 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}11572026/11/10 08:16:38 INFO Aborted multipart uploads count=0 kept=011582026/11/10 08:16:38 WARN Force mode enabled - objects will be deleted immediately without grace period11592026/11/10 08:16:38 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=01160 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3678491981/001/store/bq06fnv3z2xzrbjlw51bd0fbqfn57win-file2.txt1161--- PASS: TestGetExistingObjectsLocksRows (0.68s)1162=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit11632026/11/10 08:16:38 INFO Vacuumed table table=pending_closures11642026/11/10 08:16:38 INFO Vacuumed table table=pending_objects11652026/11/10 08:16:38 INFO Vacuumed table table=multipart_uploads11662026/11/10 08:16:38 INFO Vacuumed table table=closures11672026/11/10 08:16:38 INFO Vacuumed table table=objects1168--- PASS: TestSweepRechecksPendingAfterLocking (0.78s)1169=== CONT TestPush_RootsAreLockedInByteOrder11702026/11/10 08:16:38 INFO Received push request method=POST path=/api/pushes11712026/11/10 08:16:38 INFO Received complete push request method=POST path=/api/pushes/1/complete1172=== NAME TestOrphanedObjectsGC1173 orphaned_objects_gc_test.go:287: GC Test Summary:1174 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1175 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1176 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1177 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1178 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1179--- PASS: TestOrphanedObjectsGC (1.27s)1180=== CONT TestPushDedupSurvivesConcurrentGC11812026/11/10 08:16:38 INFO Completed push id=1 objects=6 duration=8.546653ms1182--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.66s)1183=== CONT TestPush_CompleteWaitsForCleanupOfThePush1184--- PASS: TestPush_CompleteCommitsEveryRoot (0.68s)1185=== CONT TestGCMetrics11862026/11/10 08:16:38 INFO Received push request method=POST path=/api/pushes11872026/11/10 08:16:38 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11882026/11/10 08:16:38 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11892026/11/10 08:16:38 WARN Failed to register uploaded object key=bq06fnv3z2xzrbjlw51bd0fbqfn57win.ls error="server returned 404: 404 page not found\n"11902026/11/10 08:16:38 INFO Signed narinfos id=2 count=111912026/11/10 08:16:38 INFO Uploading 1 narinfos11922026/11/10 08:16:38 INFO Received uploads request method=POST path=/api/pending_closures11932026/11/10 08:16:38 INFO Aborted multipart uploads count=0 kept=011942026/11/10 08:16:38 INFO Received complete push request method=POST path=/api/pushes/2/complete11952026/11/10 08:16:38 WARN Failed to register uploaded object key=bq06fnv3z2xzrbjlw51bd0fbqfn57win.narinfo error="server returned 404: 404 page not found\n"11962026/11/10 08:16:38 INFO Completed push id=2 objects=3 duration=2.082225ms11972026/11/10 08:16:38 INFO Upload complete. (59ms)1198=== NAME TestNARDeduplicationMetadataUploadBug1199 metadata_upload_test.go:76: Retrieved narinfo from S3:1200 StorePath: /build/TestNARDeduplicationMetadataUploadBug3678491981/001/store/bq06fnv3z2xzrbjlw51bd0fbqfn57win-file2.txt1201 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1202 Compression: zstd1203 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1204 NarSize: 1601205 References: 1206 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf12072026/11/10 08:16:38 WARN Force mode enabled - objects will be deleted immediately without grace period1208 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1209 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1210 {"version":1,"root":{"type":"regular","size":44}}12112026/11/10 08:16:38 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=012122026/11/10 08:16:38 INFO Vacuumed table table=pending_closures12132026/11/10 08:16:38 INFO Vacuumed table table=pending_objects12142026/11/10 08:16:38 INFO Vacuumed table table=multipart_uploads12152026/11/10 08:16:38 INFO Vacuumed table table=closures1216--- PASS: TestNARDeduplicationMetadataUploadBug (1.24s)1217=== CONT TestPush_RepeatedRootCommitsOnce12182026/11/10 08:16:38 INFO Vacuumed table table=objects12192026/11/10 08:16:38 INFO Aborted multipart uploads count=0 kept=012202026/11/10 08:16:38 WARN Force mode enabled - objects will be deleted immediately without grace period12212026/11/10 08:16:38 INFO Received uploads request method=POST path=/api/pending_closures12222026/11/10 08:16:38 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=012232026/11/10 08:16:38 INFO Vacuumed table table=pending_closures12242026/11/10 08:16:38 INFO Vacuumed table table=pending_objects12252026/11/10 08:16:38 INFO Vacuumed table table=multipart_uploads12262026/11/10 08:16:38 INFO Vacuumed table table=closures12272026/11/10 08:16:38 INFO Vacuumed table table=objects1228--- PASS: TestSweepSkipsRowsLockedByPush (0.75s)1229=== CONT TestGCBugBareHashReferences12302026/11/10 08:16:38 INFO Received uploads request method=POST path=/api/pending_closures12312026/11/10 08:16:38 INFO Received push request method=POST path=/api/pushes12322026/11/10 08:16:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12332026/11/10 08:16:38 INFO Aborted multipart uploads count=0 kept=01234--- PASS: TestService_Rustfstest (0.62s)1235=== CONT TestClientWithDependencies12362026/11/10 08:16:38 WARN Force mode enabled - objects will be deleted immediately without grace period12372026/11/10 08:16:38 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12382026/11/10 08:16:38 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."12392026-11-10 08:16:38.395 UTC [898] ERROR: could not obtain lock on row in relation "closures"12402026-11-10 08:16:38.395 UTC [898] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12412026-11-10 08:16:38.396 UTC [898] ERROR: could not obtain lock on row in relation "closures"12422026-11-10 08:16:38.396 UTC [898] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12432026-11-10 08:16:38.396 UTC [898] ERROR: could not obtain lock on row in relation "closures"12442026-11-10 08:16:38.396 UTC [898] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1245--- PASS: TestFailedS3DeleteKeepsTombstone (0.66s)1246=== CONT TestClientMultipleUploads12472026-11-10 08:16:38.397 UTC [898] ERROR: could not obtain lock on row in relation "closures"12482026-11-10 08:16:38.397 UTC [898] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12492026-11-10 08:16:38.397 UTC [898] ERROR: could not obtain lock on row in relation "closures"12502026-11-10 08:16:38.397 UTC [898] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1251--- PASS: TestPush_RootsAreLockedInByteOrder (0.23s)1252=== CONT TestClientIntegration12532026/11/10 08:16:38 INFO Received uploads request method=POST path=/api/pending_closures12542026/11/10 08:16:38 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst12552026/11/10 08:16:38 INFO Received uploads request method=POST path=/api/pending_closures1256--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.66s)1257=== CONT TestGCAdvisoryLockBlocksConcurrentRun12582026/11/10 08:16:38 INFO Received uploads request method=POST path=/api/pending_closures12592026/11/10 08:16:38 INFO Received uploads request method=POST path=/api/pending_closures12602026/11/10 08:16:38 INFO Aborted multipart uploads count=0 kept=012612026/11/10 08:16:38 WARN Force mode enabled - objects will be deleted immediately without grace period12622026/11/10 08:16:38 INFO Received uploads request method=POST path=/api/pending_closures1263--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.77s)1264=== CONT TestClientErrorHandling1265=== RUN TestClientErrorHandling/InvalidStorePath1266=== PAUSE TestClientErrorHandling/InvalidStorePath1267=== RUN TestClientErrorHandling/InvalidAuthToken1268=== PAUSE TestClientErrorHandling/InvalidAuthToken1269=== RUN TestClientErrorHandling/ServerNotAvailable1270=== PAUSE TestClientErrorHandling/ServerNotAvailable1271=== CONT TestDeleteClosuresRacingPins12722026/11/10 08:16:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12732026/11/10 08:16:38 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MzgzOGI3MDItYjg3Ny00NTY5LWFlMGMtNTZmYzBlZWVhZTQyLjIwMTlhNzlhLTkyZDEtNDQ1Zi1hOGU0LTUxMTEwZGVmYzdiNngxNzk0Mjk4NTk4NTE1NjMwNDk412742026/11/10 08:16:38 INFO Received uploads request method=POST path=/api/pending_closures12752026/11/10 08:16:38 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MzgzOGI3MDItYjg3Ny00NTY5LWFlMGMtNTZmYzBlZWVhZTQyLjIwMTlhNzlhLTkyZDEtNDQ1Zi1hOGU0LTUxMTEwZGVmYzdiNngxNzk0Mjk4NTk4NTE1NjMwNDk4 parts=11276--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.62s)12772026/11/10 08:16:38 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=01278=== CONT TestClientCADerivations12792026/11/10 08:16:38 INFO Vacuumed table table=pending_closures12802026/11/10 08:16:38 INFO Vacuumed table table=pending_objects12812026/11/10 08:16:38 INFO Vacuumed table table=multipart_uploads12822026/11/10 08:16:38 INFO Vacuumed table table=closures12832026/11/10 08:16:38 INFO Vacuumed table table=objects1284--- PASS: TestGCSweepDeliversEachKeyOnce (0.66s)1285=== CONT TestClientFallsBackToClosures12862026/11/10 08:16:38 INFO Received uploads request method=POST path=/api/pending_closures1287--- PASS: TestPushWaitsForSweepHoldingRow (1.22s)1288=== CONT TestClientPushesUseOnePush1289--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.63s)1290=== CONT TestCacheStatsHandler12912026/11/10 08:16:38 INFO Received push request method=POST path=/api/pushes12922026/11/10 08:16:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12932026/11/10 08:16:38 INFO Signed narinfos id=1 count=112942026/11/10 08:16:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12952026/11/10 08:16:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12962026/11/10 08:16:38 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"12972026/11/10 08:16:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12982026/11/10 08:16:38 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"12992026/11/10 08:16:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13002026/11/10 08:16:38 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=113012026/11/10 08:16:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13022026/11/10 08:16:38 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1303--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.64s)1304=== CONT TestPinProtectsFromGC13052026/11/10 08:16:38 INFO Received uploads request method=POST path=/api/pending_closures1306=== RUN TestPush_RejectsBadRequests/bad_root1307=== PAUSE TestPush_RejectsBadRequests/bad_root1308=== RUN TestPush_RejectsBadRequests/root_not_in_objects1309=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1310=== RUN TestPush_RejectsBadRequests/no_roots1311=== PAUSE TestPush_RejectsBadRequests/no_roots1312=== RUN TestPush_RejectsBadRequests/no_objects1313=== PAUSE TestPush_RejectsBadRequests/no_objects1314=== CONT TestCacheConfigHandler1315=== RUN TestCacheConfigHandler/full_config,_no_issuer1316=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1317=== RUN TestCacheConfigHandler/no_cache_url_configured1318=== PAUSE TestCacheConfigHandler/no_cache_url_configured1319=== RUN TestCacheConfigHandler/no_signing_keys1320=== PAUSE TestCacheConfigHandler/no_signing_keys1321=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1322=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1323=== CONT TestClientSharedPathCommittedMidPush13242026/11/10 08:16:38 INFO Aborted multipart uploads count=0 kept=013252026/11/10 08:16:38 WARN Force mode enabled - objects will be deleted immediately without grace period13262026/11/10 08:16:38 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=013272026/11/10 08:16:38 INFO Vacuumed table table=pending_closures13282026/11/10 08:16:38 INFO Vacuumed table table=pending_objects13292026/11/10 08:16:38 INFO Vacuumed table table=multipart_uploads13302026/11/10 08:16:38 INFO Vacuumed table table=closures13312026/11/10 08:16:38 INFO Vacuumed table table=objects1332--- PASS: TestGCSweepSkipsPendingObjects (0.68s)1333=== CONT TestService_ReadScope_PublicByDefault13342026/11/10 08:16:38 INFO Received uploads request method=POST path=/api/pending_closures1335--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.65s)1336=== CONT TestService_RequireScope_OIDC13372026/11/10 08:16:38 INFO Received push request method=POST path=/api/pushes13382026/11/10 08:16:38 INFO Received complete push request method=POST path=/api/pushes/1/complete13392026/11/10 08:16:38 INFO Completed push id=1 objects=4 duration=8.320413ms13402026/11/10 08:16:38 INFO Received push request method=POST path=/api/pushes13412026/11/10 08:16:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44281/oidc13422026/11/10 08:16:38 INFO Received uploads request method=POST path=/api/pending_closures13432026/11/10 08:16:38 INFO Aborted multipart uploads count=0 kept=013442026/11/10 08:16:38 WARN Force mode enabled - objects will be deleted immediately without grace period13452026/11/10 08:16:38 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=013462026/11/10 08:16:38 INFO Vacuumed table table=pending_closures13472026/11/10 08:16:38 INFO Vacuumed table table=pending_objects13482026/11/10 08:16:38 INFO Vacuumed table table=multipart_uploads13492026/11/10 08:16:38 INFO Vacuumed table table=closures13502026/11/10 08:16:38 INFO Vacuumed table table=objects1351--- PASS: TestGCMetrics (0.60s)1352=== CONT TestService_AuthMiddleware_OIDC13532026/11/10 08:16:38 INFO Aborted multipart uploads count=0 kept=013542026/11/10 08:16:38 INFO Received push request method=POST path=/api/pushes13552026/11/10 08:16:38 WARN Force mode enabled - objects will be deleted immediately without grace period13562026/11/10 08:16:38 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=013572026/11/10 08:16:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41487/oidc13582026/11/10 08:16:38 INFO Vacuumed table table=pending_closures13592026/11/10 08:16:38 INFO Received push request method=POST path=/api/pushes13602026/11/10 08:16:38 INFO Vacuumed table table=pending_objects13612026/11/10 08:16:38 INFO Vacuumed table table=multipart_uploads13622026/11/10 08:16:38 INFO Vacuumed table table=closures13632026/11/10 08:16:38 INFO Vacuumed table table=objects13642026/11/10 08:16:38 INFO Received complete push request method=POST path=/api/pushes/2/complete13652026/11/10 08:16:38 INFO Aborted multipart uploads count=0 kept=013662026/11/10 08:16:38 INFO Completed push id=2 objects=4 duration=4.264291ms1367--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.70s)1368=== CONT TestLeadElectsOneAndHandsOver13692026/11/10 08:16:38 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=013702026/11/10 08:16:38 INFO Received complete push request method=POST path=/api/pushes/1/complete13712026/11/10 08:16:38 INFO Vacuumed table table=pending_closures13722026/11/10 08:16:38 INFO Vacuumed table table=pending_objects13732026/11/10 08:16:38 INFO Vacuumed table table=multipart_uploads13742026/11/10 08:16:38 INFO Completed push id=1 objects=4 duration=8.425012ms1375--- PASS: TestPush_RepeatedRootCommitsOnce (0.61s)1376=== CONT TestService_ReadAuthMiddleware13772026/11/10 08:16:38 INFO Vacuumed table table=closures13782026/11/10 08:16:38 INFO Vacuumed table table=objects13792026/11/10 08:16:38 INFO Aborted multipart uploads count=0 kept=013802026/11/10 08:16:38 WARN Force mode enabled - objects will be deleted immediately without grace period13812026/11/10 08:16:38 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=013822026/11/10 08:16:38 INFO Vacuumed table table=pending_closures13832026/11/10 08:16:38 INFO Vacuumed table table=pending_objects13842026/11/10 08:16:38 INFO Vacuumed table table=multipart_uploads13852026/11/10 08:16:38 INFO Vacuumed table table=closures13862026/11/10 08:16:38 INFO Vacuumed table table=objects1387--- PASS: TestPushDedupSurvivesConcurrentGC (0.69s)1388=== CONT TestLeadEndsOnShutdown1389=== NAME TestClientMultipleUploads1390 client_integration_test.go:405: Created store path 0: /build/TestClientMultipleUploads1830043098/001/store/bpnga25dvpisnqlyclaq8rdhm1d4s2zd-test-file-0.txt13912026/11/10 08:16:39 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"1392--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.57s)1393=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1394=== NAME TestClientWithDependencies1395 client_integration_test.go:660: Built derivation: /build/TestClientWithDependencies164915923/001/store/d93pjilc8n1rp29698s53l4gwypagz5a-test-script13962026/11/10 08:16:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1397=== NAME TestClientIntegration1398 client_integration_test.go:291: Created store path: /build/TestClientIntegration1799455234/002/store/p35shfnlavm2rp7xvm7vaa0raxfjwbmd-test-file.txt1399=== NAME TestClientMultipleUploads1400 client_integration_test.go:405: Created store path 1: /build/TestClientMultipleUploads1830043098/001/store/18jcl9nnc9mqqg0fn31s4f4f1dd2im9r-test-file-1.txt14012026/11/10 08:16:39 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MzgzOGI3MDItYjg3Ny00NTY5LWFlMGMtNTZmYzBlZWVhZTQyLmM1MDhiYjA5LTVmYWUtNDlmYi1hZTYyLTVkM2MwYWVkYzAxYXgxNzk0Mjk4NTk4NDU4MjU4NTY3 parts=121402=== NAME TestClientWithDependencies1403 client_integration_test.go:662: Found 1 dependencies (including self)14042026/11/10 08:16:39 INFO Received uploads request method=POST path=/api/pending_closures1405--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.19s)1406=== CONT TestLeadIncumbentAnnouncesAtOnce1407=== NAME TestClientMultipleUploads1408 client_integration_test.go:405: Created store path 2: /build/TestClientMultipleUploads1830043098/001/store/pz3q8lwjp9rmap71rwkp0d05qiqjkydg-test-file-2.txt14092026/11/10 08:16:39 INFO Received push request method=POST path=/api/pushes14102026/11/10 08:16:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14112026/11/10 08:16:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14122026/11/10 08:16:39 INFO Uploading p35shfnlavm2rp7xvm7vaa0raxfjwbmd-test-file.txt (152B)14132026/11/10 08:16:39 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"14142026/11/10 08:16:39 WARN Failed to register uploaded object key=p35shfnlavm2rp7xvm7vaa0raxfjwbmd.ls error="server returned 404: 404 page not found\n"14152026/11/10 08:16:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14162026/11/10 08:16:39 INFO Signed narinfos id=1 count=114172026/11/10 08:16:39 INFO Uploading 1 narinfos1418--- PASS: TestGCBugBareHashReferences (0.79s)1419=== CONT TestService_AuthMiddleware_MTLSProxyHeader14202026/11/10 08:16:39 WARN Failed to register uploaded object key=p35shfnlavm2rp7xvm7vaa0raxfjwbmd.narinfo error="server returned 404: 404 page not found\n"14212026/11/10 08:16:39 INFO Received complete push request method=POST path=/api/pushes/1/complete14222026/11/10 08:16:39 INFO Received push request method=POST path=/api/pushes14232026/11/10 08:16:39 INFO Completed push id=1 objects=3 duration=15.248599ms14242026/11/10 08:16:39 INFO Upload complete. (76ms)14252026/11/10 08:16:39 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MzgzOGI3MDItYjg3Ny00NTY5LWFlMGMtNTZmYzBlZWVhZTQyLjEyMDI4YTFiLTI2ZjItNDQyMC1iYzk0LTk2ZDhmY2RhMWIxNngxNzk0Mjk4NTk4NTQ2NDczODQ0 parts=1214262026/11/10 08:16:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14272026/11/10 08:16:39 INFO Uploading d93pjilc8n1rp29698s53l4gwypagz5a-test-script (136B)14282026-11-10 08:16:39.142 UTC [945] ERROR: Push does not exist: id=114292026-11-10 08:16:39.142 UTC [945] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE14302026-11-10 08:16:39.142 UTC [945] STATEMENT: SELECT commit_push($1)1431--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.93s)1432=== CONT TestReadProxyConditionalGet14332026/11/10 08:16:39 WARN Failed to register uploaded object key=log/qgxzi38q72bnhnpa12afgmvz3zb4lg2a-test-script.drv error="server returned 404: 404 page not found\n"14342026/11/10 08:16:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14352026/11/10 08:16:39 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"14362026/11/10 08:16:39 WARN Failed to register uploaded object key=d93pjilc8n1rp29698s53l4gwypagz5a.ls error="server returned 404: 404 page not found\n"14372026/11/10 08:16:39 INFO Signed narinfos id=1 count=114382026/11/10 08:16:39 INFO Uploading 1 narinfos1439=== NAME TestClientCADerivations1440 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3626785897/001/store/rd1q7x1xyjpbknwkh8idw282rvap56gx-ca-test14412026/11/10 08:16:39 INFO Received complete push request method=POST path=/api/pushes/1/complete14422026/11/10 08:16:39 WARN Failed to register uploaded object key=d93pjilc8n1rp29698s53l4gwypagz5a.narinfo error="server returned 404: 404 page not found\n"14432026/11/10 08:16:39 INFO Received push request method=POST path=/api/pushes14442026/11/10 08:16:39 INFO Completed push id=1 objects=4 duration=11.461176ms14452026/11/10 08:16:39 INFO Upload complete. (78ms)14462026/11/10 08:16:39 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)14472026/11/10 08:16:39 INFO Uploading pz3q8lwjp9rmap71rwkp0d05qiqjkydg-test-file-2.txt (160B)14482026/11/10 08:16:39 INFO Uploading 18jcl9nnc9mqqg0fn31s4f4f1dd2im9r-test-file-1.txt (160B)14492026/11/10 08:16:39 INFO Uploading bpnga25dvpisnqlyclaq8rdhm1d4s2zd-test-file-0.txt (160B)14502026/11/10 08:16:39 INFO All 1 paths already cached1451=== NAME TestClientWithDependencies1452 client_integration_test.go:664: Skipping nix copy test - isolated store (/build/TestClientWithDependencies164915923/001/store) requires matching store prefix1453=== NAME TestClientIntegration1454 client_integration_test.go:317: Retrieved narinfo from S3:1455 StorePath: /build/TestClientIntegration1799455234/002/store/p35shfnlavm2rp7xvm7vaa0raxfjwbmd-test-file.txt1456 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1457 Compression: zstd1458 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11459 NarSize: 1521460 References: 1461 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11462 client_integration_test.go:318: Retrieved .ls file from S3 (compressed size: 77 bytes)1463 client_integration_test.go:318: Decompressed .ls content (64 bytes):1464 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1465--- PASS: TestCacheStatsHandler (0.59s)1466=== CONT TestService_AuthMiddleware14672026/11/10 08:16:39 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"14682026/11/10 08:16:39 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"14692026/11/10 08:16:39 WARN Failed to register uploaded object key=18jcl9nnc9mqqg0fn31s4f4f1dd2im9r.ls error="server returned 404: 404 page not found\n"14702026/11/10 08:16:39 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"14712026/11/10 08:16:39 WARN Failed to register uploaded object key=bpnga25dvpisnqlyclaq8rdhm1d4s2zd.ls error="server returned 404: 404 page not found\n"14722026/11/10 08:16:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14732026/11/10 08:16:39 WARN Failed to register uploaded object key=pz3q8lwjp9rmap71rwkp0d05qiqjkydg.ls error="server returned 404: 404 page not found\n"14742026/11/10 08:16:39 INFO Signed narinfos id=1 count=314752026/11/10 08:16:39 INFO Uploading 3 narinfos1476--- PASS: TestClientWithDependencies (0.80s)1477=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock14782026/11/10 08:16:39 WARN Failed to register uploaded object key=18jcl9nnc9mqqg0fn31s4f4f1dd2im9r.narinfo error="server returned 404: 404 page not found\n"14792026/11/10 08:16:39 WARN Failed to register uploaded object key=pz3q8lwjp9rmap71rwkp0d05qiqjkydg.narinfo error="server returned 404: 404 page not found\n"14802026/11/10 08:16:39 INFO Received complete push request method=POST path=/api/pushes/1/complete14812026/11/10 08:16:39 WARN Failed to register uploaded object key=bpnga25dvpisnqlyclaq8rdhm1d4s2zd.narinfo error="server returned 404: 404 page not found\n"1482=== NAME TestClientCADerivations1483 client_ca_test.go:139: Found 1 dependencies (including self)14842026/11/10 08:16:39 INFO Completed push id=1 objects=9 duration=15.036609ms14852026/11/10 08:16:39 INFO Upload complete. (87ms)1486=== NAME TestClientMultipleUploads1487 client_integration_test.go:416: Uploaded 3 paths in 124.404212ms1488--- PASS: TestClientMultipleUploads (0.82s)1489=== CONT TestPush_OverlappingRootsStoreOneRowPerKey1490--- PASS: TestService_ReadScope_PublicByDefault (0.55s)1491=== CONT TestReadProxy40414922026/11/10 08:16:39 INFO Received push request method=POST path=/api/pushes1493=== NAME TestPinProtectsFromGC1494 client_integration_test.go:778: Pinned store path: /build/TestPinProtectsFromGC3519948876/001/store/57cwamcm1fai4x59lchf0y770yv055qq-pinned-file.txt1495 client_integration_test.go:779: Unpinned store path: /build/TestPinProtectsFromGC3519948876/001/store/6ihi11xpjhla4mpqyhk3kbgrhh9s6lhz-unpinned-file.txt14962026/11/10 08:16:39 INFO Object in database but missing from S3 key=p35shfnlavm2rp7xvm7vaa0raxfjwbmd.ls14972026/11/10 08:16:39 WARN Found objects in DB but missing from S3, will re-upload count=114982026/11/10 08:16:39 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)14992026/11/10 08:16:39 INFO Received push request method=POST path=/api/pushes15002026/11/10 08:16:39 INFO Received complete push request method=POST path=/api/pushes/2/complete15012026/11/10 08:16:39 WARN Failed to register uploaded object key=p35shfnlavm2rp7xvm7vaa0raxfjwbmd.ls error="server returned 404: 404 page not found\n"1502=== RUN TestService_RequireScope_OIDC/builder_may_write1503=== PAUSE TestService_RequireScope_OIDC/builder_may_write1504=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1505=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1506=== RUN TestService_RequireScope_OIDC/ops_may_admin1507=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1508=== RUN TestService_RequireScope_OIDC/ops_may_not_write1509=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1510=== RUN TestService_RequireScope_OIDC/reader_may_not_write1511=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1512=== RUN TestService_RequireScope_OIDC/static_token_may_admin1513=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1514=== RUN TestService_RequireScope_OIDC/static_token_may_write1515=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1516=== RUN TestService_RequireScope_OIDC/reader_may_read1517=== PAUSE TestService_RequireScope_OIDC/reader_may_read1518=== RUN TestService_RequireScope_OIDC/writer_implies_read1519=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1520=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1521=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1522=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1523=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1524=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1525=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1526=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1527=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1528=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1529=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read15302026/11/10 08:16:39 INFO Completed push id=2 objects=3 duration=2.566295ms1531=== CONT TestReadRedirectUsesPublicS3URL15322026/11/10 08:16:39 INFO Upload complete. (51ms)1533=== NAME TestClientIntegration1534 client_integration_test.go:335: Retrieved .ls file from S3 (compressed size: 62 bytes)1535 client_integration_test.go:335: Decompressed .ls content (49 bytes):1536 {"version":1,"root":{"type":"regular","size":39}}15372026/11/10 08:16:39 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15382026/11/10 08:16:39 INFO Uploading 29xc0wnsjr5hl3idv04vzpk6cvdx7qk4-a (216B)15392026/11/10 08:16:39 INFO Uploading 23is2pikc63ycdg3y5gxdhncd1yzkhdf-shared-dep (136B)15402026/11/10 08:16:39 INFO Received push request method=POST path=/api/pushes15412026/11/10 08:16:39 WARN Failed to register uploaded object key=24n29mvxi6sn9dl1ng1x9qwcvfg5m9f6.ls error="server returned 404: 404 page not found\n"15422026/11/10 08:16:39 WARN Failed to register uploaded object key=23is2pikc63ycdg3y5gxdhncd1yzkhdf.ls error="server returned 404: 404 page not found\n"15432026/11/10 08:16:39 WARN Failed to register uploaded object key=29xc0wnsjr5hl3idv04vzpk6cvdx7qk4.ls error="server returned 404: 404 page not found\n"15442026/11/10 08:16:39 WARN Failed to register uploaded object key=nar/1wygg8rv46mbsp54b4kyj448ggpxjav6llilnb1yd94wj02vc9wc.nar.zst error="server returned 404: 404 page not found\n"15452026/11/10 08:16:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15462026/11/10 08:16:39 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15472026/11/10 08:16:39 INFO Signed narinfos id=1 count=315482026/11/10 08:16:39 INFO Uploading 3 narinfos15492026/11/10 08:16:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15502026/11/10 08:16:39 INFO Uploading rd1q7x1xyjpbknwkh8idw282rvap56gx-ca-test (144B)15512026/11/10 08:16:39 WARN Failed to register uploaded object key=24n29mvxi6sn9dl1ng1x9qwcvfg5m9f6.narinfo error="server returned 404: 404 page not found\n"15522026/11/10 08:16:39 WARN Failed to register uploaded object key=23is2pikc63ycdg3y5gxdhncd1yzkhdf.narinfo error="server returned 404: 404 page not found\n"15532026/11/10 08:16:39 INFO Received complete push request method=POST path=/api/pushes/1/complete15542026/11/10 08:16:39 WARN Failed to register uploaded object key=29xc0wnsjr5hl3idv04vzpk6cvdx7qk4.narinfo error="server returned 404: 404 page not found\n"1555=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1556=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1557=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1558=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1559=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected15602026/11/10 08:16:39 WARN Failed to register uploaded object key=rd1q7x1xyjpbknwkh8idw282rvap56gx.ls error="server returned 404: 404 page not found\n"1561=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1562=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1563=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1564=== CONT TestReadProxyOutlastsServerWriteTimeout15652026/11/10 08:16:39 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"15662026/11/10 08:16:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15672026/11/10 08:16:39 WARN Failed to register uploaded object key=log/x37w95fsqdzz01nd3bw5i4mmx6rrz2v8-ca-test.drv error="server returned 404: 404 page not found\n"15682026/11/10 08:16:39 INFO Signed narinfos id=1 count=115692026/11/10 08:16:39 INFO Uploading 1 narinfos15702026/11/10 08:16:39 INFO Received complete push request method=POST path=/api/pushes/1/complete15712026/11/10 08:16:39 WARN Failed to register uploaded object key=rd1q7x1xyjpbknwkh8idw282rvap56gx.narinfo error="server returned 404: 404 page not found\n"15722026/11/10 08:16:39 INFO Completed push id=1 objects=4 duration=10.238008ms15732026/11/10 08:16:39 INFO Completed push id=1 objects=8 duration=20.894336ms15742026/11/10 08:16:39 INFO Upload complete. (109ms)15752026/11/10 08:16:39 INFO Upload complete. (84ms)1576=== NAME TestClientPushesUseOnePush1577 client_pushes_test.go:97: Retrieved narinfo from S3:1578 StorePath: /build/TestClientPushesUseOnePush2496403950/001/store/23is2pikc63ycdg3y5gxdhncd1yzkhdf-shared-dep1579 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1580 Compression: zstd1581 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821582 NarSize: 1361583 References: 1584 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1585=== NAME TestClientCADerivations1586 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3626785897/001/store/rd1q7x1xyjpbknwkh8idw282rvap56gx-ca-test1587 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1588 Compression: zstd1589 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1590 NarSize: 1441591 References: 1592 Deriver: /build/TestClientCADerivations3626785897/001/store/x37w95fsqdzz01nd3bw5i4mmx6rrz2v8-ca-test.drv1593 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1594=== NAME TestClientPushesUseOnePush1595 client_pushes_test.go:97: Retrieved narinfo from S3:1596 StorePath: /build/TestClientPushesUseOnePush2496403950/001/store/29xc0wnsjr5hl3idv04vzpk6cvdx7qk4-a1597 URL: nar/1wygg8rv46mbsp54b4kyj448ggpxjav6llilnb1yd94wj02vc9wc.nar.zst1598 Compression: zstd1599 NarHash: sha256:1wygg8rv46mbsp54b4kyj448ggpxjav6llilnb1yd94wj02vc9wc1600 NarSize: 2161601 References: /build/TestClientPushesUseOnePush2496403950/001/store/23is2pikc63ycdg3y5gxdhncd1yzkhdf-shared-dep1602 CA: text:sha256:18dhx2y28vzm147q2l2wgarxvjays5jw8s15m7cykajpsi3v1gsi1603=== NAME TestClientCADerivations1604 client_ca_test.go:185: Checking for realisation files in S3...1605=== NAME TestClientPushesUseOnePush1606 client_pushes_test.go:97: Retrieved narinfo from S3:1607 StorePath: /build/TestClientPushesUseOnePush2496403950/001/store/24n29mvxi6sn9dl1ng1x9qwcvfg5m9f6-b1608 URL: nar/1wygg8rv46mbsp54b4kyj448ggpxjav6llilnb1yd94wj02vc9wc.nar.zst1609 Compression: zstd1610 NarHash: sha256:1wygg8rv46mbsp54b4kyj448ggpxjav6llilnb1yd94wj02vc9wc1611 NarSize: 2161612 References: /build/TestClientPushesUseOnePush2496403950/001/store/23is2pikc63ycdg3y5gxdhncd1yzkhdf-shared-dep1613 CA: text:sha256:18dhx2y28vzm147q2l2wgarxvjays5jw8s15m7cykajpsi3v1gsi1614=== NAME TestClientCADerivations1615 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1616 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1617--- PASS: TestService_ReadAuthMiddleware (0.46s)1618=== CONT TestReadProxyRangeRequest16192026/11/10 08:16:39 INFO Received uploads request method=POST path=/api/pending_closures1620--- PASS: TestClientPushesUseOnePush (0.77s)1621=== CONT TestReadProxyHead16222026/11/10 08:16:39 INFO Received uploads request method=POST path=/api/pending_closures16232026/11/10 08:16:39 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16242026/11/10 08:16:39 INFO Uploading 9b47m5lmg35jrrjpcqmbni2398cwmvv7-shared-dep (136B)16252026/11/10 08:16:39 INFO Uploading pai9fn318bja4jms522d00lwjyz4qgnq-b (216B)16262026/11/10 08:16:39 WARN Failed to register uploaded object key=9b47m5lmg35jrrjpcqmbni2398cwmvv7.ls error="server returned 404: 404 page not found\n"16272026/11/10 08:16:39 WARN Failed to register uploaded object key=pai9fn318bja4jms522d00lwjyz4qgnq.ls error="server returned 404: 404 page not found\n"16282026/11/10 08:16:39 WARN Failed to register uploaded object key=hakx7ial6dzzzf27rrasryvprr748wg4.ls error="server returned 404: 404 page not found\n"16292026/11/10 08:16:39 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16302026/11/10 08:16:39 WARN Failed to register uploaded object key=nar/19yg8l6mjp59i21iij2328wh9hd160dhzblvsgq51x50kzrrplxp.nar.zst error="server returned 404: 404 page not found\n"16312026/11/10 08:16:39 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16322026/11/10 08:16:39 INFO Signed narinfos id=2 count=216332026/11/10 08:16:39 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16342026/11/10 08:16:39 INFO Signed narinfos id=1 count=216352026/11/10 08:16:39 INFO Uploading 4 narinfos16362026/11/10 08:16:39 INFO Received push request method=POST path=/api/pushes16372026/11/10 08:16:39 WARN Failed to register uploaded object key=hakx7ial6dzzzf27rrasryvprr748wg4.narinfo error="server returned 404: 404 page not found\n"16382026/11/10 08:16:39 WARN Failed to register uploaded object key=9b47m5lmg35jrrjpcqmbni2398cwmvv7.narinfo error="server returned 404: 404 page not found\n"16392026/11/10 08:16:39 WARN Failed to register uploaded object key=pai9fn318bja4jms522d00lwjyz4qgnq.narinfo error="server returned 404: 404 page not found\n"16402026/11/10 08:16:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16412026/11/10 08:16:39 INFO Uploading 57cwamcm1fai4x59lchf0y770yv055qq-pinned-file.txt (128B)16422026/11/10 08:16:39 INFO lead: acquired remote=192.0.2.1:123416432026/11/10 08:16:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16442026/11/10 08:16:39 WARN Failed to register uploaded object key=9b47m5lmg35jrrjpcqmbni2398cwmvv7.narinfo error="server returned 404: 404 page not found\n"16452026/11/10 08:16:39 INFO Completed upload id=1 objects=6 duration=6.662496ms16462026/11/10 08:16:39 WARN Failed to register uploaded object key=57cwamcm1fai4x59lchf0y770yv055qq.ls error="server returned 404: 404 page not found\n"16472026/11/10 08:16:39 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16482026/11/10 08:16:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16492026/11/10 08:16:39 INFO Signed narinfos id=1 count=116502026/11/10 08:16:39 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"16512026/11/10 08:16:39 INFO Uploading 1 narinfos16522026/11/10 08:16:39 INFO Completed upload id=2 objects=6 duration=1.554437ms16532026/11/10 08:16:39 INFO Upload complete. (87ms)1654=== NAME TestClientFallsBackToClosures1655 client_pushes_test.go:112: Retrieved narinfo from S3:1656 StorePath: /build/TestClientFallsBackToClosures2870255807/001/store/9b47m5lmg35jrrjpcqmbni2398cwmvv7-shared-dep1657 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1658 Compression: zstd1659 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821660 NarSize: 13616612026/11/10 08:16:39 INFO Received push request method=POST path=/api/pushes1662 References: 1663 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1664 client_pushes_test.go:112: Retrieved narinfo from S3:1665 StorePath: /build/TestClientFallsBackToClosures2870255807/001/store/hakx7ial6dzzzf27rrasryvprr748wg4-a1666 URL: nar/19yg8l6mjp59i21iij2328wh9hd160dhzblvsgq51x50kzrrplxp.nar.zst1667 Compression: zstd1668 NarHash: sha256:19yg8l6mjp59i21iij2328wh9hd160dhzblvsgq51x50kzrrplxp1669 NarSize: 2161670 References: /build/TestClientFallsBackToClosures2870255807/001/store/9b47m5lmg35jrrjpcqmbni2398cwmvv7-shared-dep1671 CA: text:sha256:0zmhirnzlgw2aa3bxvgnz32bwj8mdbwahyga6cw0w3pgihrpnbkl1672 client_pushes_test.go:112: Retrieved narinfo from S3:1673 StorePath: /build/TestClientFallsBackToClosures2870255807/001/store/pai9fn318bja4jms522d00lwjyz4qgnq-b1674 URL: nar/19yg8l6mjp59i21iij2328wh9hd160dhzblvsgq51x50kzrrplxp.nar.zst1675 Compression: zstd1676 NarHash: sha256:19yg8l6mjp59i21iij2328wh9hd160dhzblvsgq51x50kzrrplxp1677 NarSize: 2161678 References: /build/TestClientFallsBackToClosures2870255807/001/store/9b47m5lmg35jrrjpcqmbni2398cwmvv7-shared-dep1679 CA: text:sha256:0zmhirnzlgw2aa3bxvgnz32bwj8mdbwahyga6cw0w3pgihrpnbkl16802026/11/10 08:16:39 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)16812026/11/10 08:16:39 INFO Received complete push request method=POST path=/api/pushes/1/complete16822026/11/10 08:16:39 INFO Uploading g31x4ckngd680spav56rps0xf1w7s713-shared-dep (136B)16832026/11/10 08:16:39 INFO Uploading 4wrx1dahdf10zyj5lz1qb969jfcml6h5-top (224B)16842026/11/10 08:16:39 WARN Failed to register uploaded object key=57cwamcm1fai4x59lchf0y770yv055qq.narinfo error="server returned 404: 404 page not found\n"1685--- PASS: TestClientFallsBackToClosures (0.83s)1686=== CONT TestReadRedirectKeepsNarinfoProxied16872026/11/10 08:16:39 WARN Failed to register uploaded object key=4wrx1dahdf10zyj5lz1qb969jfcml6h5.ls error="server returned 404: 404 page not found\n"16882026/11/10 08:16:39 WARN Failed to register uploaded object key=g31x4ckngd680spav56rps0xf1w7s713.ls error="server returned 404: 404 page not found\n"16892026/11/10 08:16:39 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16902026/11/10 08:16:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16912026/11/10 08:16:39 WARN Failed to register uploaded object key=nar/09rradv5h6zjhi3zhk6dr7gqxgaxcjhir7gq2vd3dx2mz519wnkp.nar.zst error="server returned 404: 404 page not found\n"16922026/11/10 08:16:39 INFO Signed narinfos id=1 count=216932026/11/10 08:16:39 INFO Uploading 2 narinfos16942026/11/10 08:16:39 INFO Completed push id=1 objects=3 duration=11.568266ms16952026/11/10 08:16:39 INFO Upload complete. (87ms)16962026/11/10 08:16:39 WARN Failed to register uploaded object key=g31x4ckngd680spav56rps0xf1w7s713.narinfo error="server returned 404: 404 page not found\n"16972026/11/10 08:16:39 INFO Received complete push request method=POST path=/api/pushes/1/complete16982026/11/10 08:16:39 WARN Failed to register uploaded object key=4wrx1dahdf10zyj5lz1qb969jfcml6h5.narinfo error="server returned 404: 404 page not found\n"16992026/11/10 08:16:39 INFO Received push request method=POST path=/api/pushes17002026/11/10 08:16:39 INFO lead: acquired remote=192.0.2.1:123417012026/11/10 08:16:39 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17022026/11/10 08:16:39 INFO Received complete push request method=POST path=/api/pushes/3/complete17032026/11/10 08:16:39 WARN Failed to register uploaded object key=p35shfnlavm2rp7xvm7vaa0raxfjwbmd.ls error="server returned 404: 404 page not found\n"17042026/11/10 08:16:39 INFO Completed push id=3 objects=3 duration=10.577498ms17052026/11/10 08:16:39 INFO Completed push id=1 objects=6 duration=21.910035ms17062026/11/10 08:16:39 INFO Upload complete. (62ms)17072026/11/10 08:16:39 INFO Upload complete. (88ms)1708=== NAME TestClientIntegration1709 client_integration_test.go:352: Retrieved .ls file from S3 (compressed size: 62 bytes)1710=== NAME TestClientSharedPathCommittedMidPush1711 client_integration_test.go:727: Retrieved narinfo from S3:1712 StorePath: /build/TestClientSharedPathCommittedMidPush1252159034/001/store/g31x4ckngd680spav56rps0xf1w7s713-shared-dep1713 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1714=== NAME TestClientIntegration1715 client_integration_test.go:352: Decompressed .ls content (49 bytes):1716 {"version":1,"root":{"type":"regular","size":39}}1717=== NAME TestClientSharedPathCommittedMidPush1718 Compression: zstd1719 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821720 NarSize: 1361721 References: 1722 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1723=== NAME TestClientIntegration1724 client_integration_test.go:363: Testing garbage collection...1725=== NAME TestClientSharedPathCommittedMidPush1726 client_integration_test.go:727: Retrieved narinfo from S3:1727 StorePath: /build/TestClientSharedPathCommittedMidPush1252159034/001/store/4wrx1dahdf10zyj5lz1qb969jfcml6h5-top1728 URL: nar/09rradv5h6zjhi3zhk6dr7gqxgaxcjhir7gq2vd3dx2mz519wnkp.nar.zst1729 Compression: zstd1730 NarHash: sha256:09rradv5h6zjhi3zhk6dr7gqxgaxcjhir7gq2vd3dx2mz519wnkp1731 NarSize: 2241732 References: /build/TestClientSharedPathCommittedMidPush1252159034/001/store/g31x4ckngd680spav56rps0xf1w7s713-shared-dep1733 CA: text:sha256:0bhv0x5h7bvnxmiv5smj3566zj64xmcr6023pvhngkb094kzs3rn17342026/11/10 08:16:39 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17352026/11/10 08:16:39 WARN mTLS auth: bound subjects configured but subject DN unavailable17362026/11/10 08:16:39 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1737--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.43s)1738=== CONT TestReadRedirectNar1739--- PASS: TestClientSharedPathCommittedMidPush (0.78s)1740=== CONT TestReadProxyInvalidPath17412026/11/10 08:16:39 INFO lead: acquired remote=192.0.2.1:123417422026/11/10 08:16:39 INFO Starting cleanup of old closures method=DELETE path=/api/closures17432026/11/10 08:16:39 INFO lead: released remote=192.0.2.1:12341744--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.42s)17452026/11/10 08:16:39 INFO Garbage collection started1746=== CONT TestReadProxyDisabled1747=== NAME TestClientCADerivations1748 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1749 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1750 error: binary cache 's3://bucket60?endpoint=http://localhost:34545®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3626785897/001/store'1751 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 117522026/11/10 08:16:39 INFO Aborted multipart uploads count=0 kept=01753--- PASS: TestClientCADerivations (0.92s)1754=== CONT TestResolveDBConnectionString1755=== RUN TestResolveDBConnectionString/flag_wins1756=== PAUSE TestResolveDBConnectionString/flag_wins1757=== RUN TestResolveDBConnectionString/file_when_flag_empty1758=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1759=== RUN TestResolveDBConnectionString/missing_file_is_an_error1760=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1761=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1762=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1763=== RUN TestResolveDBConnectionString/nothing_configured1764=== PAUSE TestResolveDBConnectionString/nothing_configured1765=== CONT TestReadProxyRootRedirectsToIndexHTML17662026/11/10 08:16:39 WARN Force mode enabled - objects will be deleted immediately without grace period17672026/11/10 08:16:39 INFO Received push request method=POST path=/api/pushes1768--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.39s)1769=== CONT TestReadProxyContentNegotiation17702026/11/10 08:16:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17712026/11/10 08:16:39 INFO Uploading 6ihi11xpjhla4mpqyhk3kbgrhh9s6lhz-unpinned-file.txt (128B)17722026/11/10 08:16:39 WARN Failed to register uploaded object key=6ihi11xpjhla4mpqyhk3kbgrhh9s6lhz.ls error="server returned 404: 404 page not found\n"17732026/11/10 08:16:39 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17742026/11/10 08:16:39 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"17752026/11/10 08:16:39 INFO Signed narinfos id=2 count=117762026/11/10 08:16:39 INFO Uploading 1 narinfos17772026/11/10 08:16:39 INFO Received complete push request method=POST path=/api/pushes/2/complete17782026/11/10 08:16:39 WARN Failed to register uploaded object key=6ihi11xpjhla4mpqyhk3kbgrhh9s6lhz.narinfo error="server returned 404: 404 page not found\n"17792026/11/10 08:16:39 INFO Completed push id=2 objects=3 duration=4.101101ms17802026/11/10 08:16:39 INFO Upload complete. (69ms)17812026/11/10 08:16:39 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=01782--- PASS: TestReadProxyConditionalGet (0.42s)1783=== CONT TestReadProxyNarStreaming17842026/11/10 08:16:39 INFO Vacuumed table table=pending_closures17852026/11/10 08:16:39 INFO Vacuumed table table=pending_objects17862026/11/10 08:16:39 INFO Vacuumed table table=multipart_uploads17872026/11/10 08:16:39 INFO Starting cleanup of old closures method=DELETE path=/api/closures17882026/11/10 08:16:39 INFO Garbage collection started17892026/11/10 08:16:39 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1790--- PASS: TestService_AuthMiddleware (0.40s)1791=== CONT TestReadProxyNarinfoAlreadyDecompressed17922026/11/10 08:16:39 INFO Vacuumed table table=closures17932026/11/10 08:16:39 INFO Vacuumed table table=objects17942026/11/10 08:16:39 INFO Aborted multipart uploads count=0 kept=017952026/11/10 08:16:39 WARN Force mode enabled - objects will be deleted immediately without grace period17962026/11/10 08:16:39 INFO Received push request method=POST path=/api/pushes17972026/11/10 08:16:39 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=017982026/11/10 08:16:39 INFO Vacuumed table table=pending_closures17992026/11/10 08:16:39 INFO Vacuumed table table=pending_objects18002026/11/10 08:16:39 INFO Vacuumed table table=multipart_uploads18012026/11/10 08:16:39 INFO Vacuumed table table=closures18022026/11/10 08:16:39 INFO Vacuumed table table=objects1803--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.45s)1804=== CONT TestConnectWaitsForAPeerMigration18052026/11/10 08:16:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18062026/11/10 08:16:39 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MzgzOGI3MDItYjg3Ny00NTY5LWFlMGMtNTZmYzBlZWVhZTQyLjhjNzM0MGNmLTQxOWYtNDQyZC05Zjc0LTY2Y2FjNzNmNjI0ZHgxNzk0Mjk4NTk4NTU0MDczMDI5 parts=121807--- PASS: TestSharedNarBothUploadsComplete (1.75s)1808=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1809--- PASS: TestReadRedirectUsesPublicS3URL (0.44s)1810=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1811--- PASS: TestReadProxy404 (0.49s)1812=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed1813--- PASS: TestReadProxyRangeRequest (0.44s)1814=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed1815--- PASS: TestReadProxyHead (0.46s)1816=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed1817=== NAME TestOrphanedObjectsGCStressTest1818 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1819--- PASS: TestReadRedirectKeepsNarinfoProxied (0.44s)1820=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost1821=== NAME TestOrphanedObjectsGCStressTest1822 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion1823--- PASS: TestReadRedirectNar (0.44s)1824=== CONT TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed1825--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.70s)1826=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18272026/11/10 08:16:39 INFO Received uploads request method=POST path=/1828=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18292026/11/10 08:16:39 INFO Received request for more parts method=POST path=/1830=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18312026/11/10 08:16:39 INFO Received complete multipart upload request method=POST path=/1832=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18332026/11/10 08:16:39 INFO Received uploads request method=POST path=/1834--- PASS: TestUploadHandlersRejectInvalidKeys (0.10s)1835 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1836 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1837 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1838 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1839=== CONT TestPendingClosureWriteTimeout/empty1840=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1841--- PASS: TestReadProxyInvalidPath (0.46s)1842=== CONT TestPendingClosureWriteTimeout/670k_objects1843=== CONT TestPendingClosureWriteTimeout/400_objects1844=== CONT TestServerTLSConfig/no_client_CA1845=== CONT TestServerTLSConfig/not_a_PEM_file1846=== CONT TestServerTLSConfig/missing_CA_file1847--- PASS: TestServerTLSConfig (0.00s)1848 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1849 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1850 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1851=== CONT TestParseSingleRange/none1852=== CONT TestParseSingleRange/start_far_past_EOF1853=== CONT TestParseSingleRange/start_past_EOF1854=== CONT TestParseSingleRange/single_byte1855=== CONT TestParseSingleRange/suffix_exceeds_size1856=== CONT TestParseSingleRange/suffix1857=== CONT TestParseSingleRange/end_clamped_to_size1858=== CONT TestParseSingleRange/open-ended1859=== CONT TestParseSingleRange/closed1860=== CONT TestParseSingleRange/malformed_end_before_start1861=== CONT TestParseSingleRange/multi-range_ignored1862=== CONT TestParseSingleRange/unknown_unit1863=== CONT TestParseSingleRange/malformed_both_empty1864=== CONT TestParseSingleRange/malformed_no_dash1865--- PASS: TestParseSingleRange (0.10s)1866 --- PASS: TestParseSingleRange/none (0.00s)1867 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1868 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1869 --- PASS: TestParseSingleRange/single_byte (0.00s)1870 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1871 --- PASS: TestParseSingleRange/suffix (0.00s)1872 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1873 --- PASS: TestParseSingleRange/open-ended (0.00s)1874 --- PASS: TestParseSingleRange/closed (0.00s)1875 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1876 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1877 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1878 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1879 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1880=== CONT TestIsValidUploadKey/narinfo1881=== CONT TestIsValidUploadKey/realisation_plus_in_output1882=== CONT TestIsValidUploadKey/realisation1883=== CONT TestIsValidUploadKey/build_log_equals1884=== CONT TestIsValidUploadKey/build_log_question_mark1885=== CONT TestIsValidUploadKey/build_log_plus_in_name1886=== CONT TestIsValidUploadKey/build_log_home-manager_file1887=== CONT TestIsValidUploadKey/build_log1888=== CONT TestIsValidUploadKey/nix-cache-info1889=== CONT TestIsValidUploadKey/listing1890=== CONT TestIsValidUploadKey/nar_plain1891=== CONT TestIsValidUploadKey/nar_zst1892=== CONT TestIsValidUploadKey/traversal_nar1893=== CONT TestIsValidUploadKey/unknown_type1894=== CONT TestIsValidUploadKey/empty_key1895=== CONT TestIsValidUploadKey/absolute1896=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1897=== CONT TestIsValidUploadKey/traversal1898=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1899=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1900=== CONT TestIsValidUploadKey/index.html1901=== CONT TestIsValidCachePath/narinfo1902=== CONT TestIsValidCachePath/traversal_parent1903=== CONT TestIsValidUploadKey/nar_xz1904--- PASS: TestIsValidUploadKey (0.10s)1905 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1906 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1907 --- PASS: TestIsValidUploadKey/realisation (0.00s)1908 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1909 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1910 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1911 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1912 --- PASS: TestIsValidUploadKey/build_log (0.00s)1913 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1914 --- PASS: TestIsValidUploadKey/listing (0.00s)1915 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1916 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1917 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1918 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1919 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1920 --- PASS: TestIsValidUploadKey/absolute (0.00s)1921 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1922 --- PASS: TestIsValidUploadKey/traversal (0.00s)1923 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1924 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1925 --- PASS: TestIsValidUploadKey/index.html (0.00s)1926 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1927=== CONT TestIsValidCachePath/ls1928=== CONT TestIsValidCachePath/index.html1929=== CONT TestIsValidCachePath/nix-cache-info1930=== CONT TestIsValidCachePath/realisation1931=== CONT TestIsValidCachePath/log1932=== CONT TestIsValidCachePath/empty1933=== CONT TestIsValidCachePath/short_hash1934=== CONT TestIsValidCachePath/wrong_extension1935=== CONT TestIsValidCachePath/leading_slash1936=== CONT TestIsValidCachePath/nar_xz1937=== CONT TestIsValidCachePath/nar_uncompressed1938=== CONT TestIsValidCachePath/nar_bz21939=== CONT TestIsValidCachePath/invalid_char_u1940=== CONT TestIsValidCachePath/random_path1941=== CONT TestIsValidCachePath/nar_zst1942=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1943=== CONT TestIsValidCachePath/invalid_char_e1944=== CONT TestIsValidCachePath/traversal_in_middle1945--- PASS: TestIsValidCachePath (0.10s)1946 --- PASS: TestIsValidCachePath/narinfo (0.00s)1947 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1948 --- PASS: TestIsValidCachePath/ls (0.00s)1949 --- PASS: TestIsValidCachePath/index.html (0.00s)1950 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1951 --- PASS: TestIsValidCachePath/realisation (0.00s)1952 --- PASS: TestIsValidCachePath/log (0.00s)1953 --- PASS: TestIsValidCachePath/empty (0.00s)1954 --- PASS: TestIsValidCachePath/short_hash (0.00s)1955 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1956 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1957 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1958 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1959 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1960 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1961 --- PASS: TestIsValidCachePath/random_path (0.00s)1962 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1963 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1964 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1965 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1966=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19672026/11/10 08:16:39 INFO Received uploads request method=POST path=/1968--- PASS: TestReadProxyDisabled (0.46s)1969=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts19702026/11/10 08:16:39 INFO Received request for more parts method=POST path=/1971--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.48s)1972=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19732026/11/10 08:16:39 INFO Received complete multipart upload request method=POST path=/1974=== CONT TestGCEndsOnShutdown/before_the_run1975=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1976--- PASS: TestReadProxyNarStreaming (0.47s)1977=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1978--- PASS: TestReadProxyContentNegotiation (0.54s)1979=== CONT TestProxyWriteTimeout/narinfo1980=== CONT TestProxyWriteTimeout/10_GiB_nar1981=== CONT TestProxyWriteTimeout/unknown_size1982=== CONT TestProxyWriteTimeout/1_GiB_nar1983=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1984--- PASS: TestProxyWriteTimeout (0.00s)1985 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1986 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1987 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1988 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1989--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.48s)1990=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1991--- PASS: TestDeleteClosuresRacingPins (1.57s)1992=== CONT TestClientErrorHandling/InvalidStorePath19932026/11/10 08:16:40 INFO Received uploads request method=POST path=/api/pending_closures19942026/11/10 08:16:40 INFO Received uploads request method=POST path=/api/pending_closures19952026/11/10 08:16:40 INFO Received uploads request method=POST path=/api/pending_closures19962026/11/10 08:16:40 INFO Received uploads request method=POST path=/api/pending_closures19972026/11/10 08:16:40 INFO Received uploads request method=POST path=/api/pending_closures19982026/11/10 08:16:40 INFO Received uploads request method=POST path=/api/pending_closures1999=== CONT TestClientErrorHandling/ServerNotAvailable20002026/11/10 08:16:40 INFO lead: released remote=192.0.2.1:12342001--- PASS: TestLeadEndsOnShutdown (1.56s)2002=== CONT TestClientErrorHandling/InvalidAuthToken20032026/11/10 08:16:40 INFO Aborted multipart uploads count=0 kept=020042026/11/10 08:16:40 WARN Force mode enabled - objects will be deleted immediately without grace period2005=== CONT TestPush_RejectsBadRequests/bad_root20062026/11/10 08:16:40 INFO Received push request method=POST path=/api/pushes2007=== CONT TestPush_RejectsBadRequests/no_roots20082026/11/10 08:16:40 INFO Received push request method=POST path=/api/pushes2009=== CONT TestPush_RejectsBadRequests/no_objects20102026/11/10 08:16:40 INFO Received push request method=POST path=/api/pushes2011=== CONT TestPush_RejectsBadRequests/root_not_in_objects20122026/11/10 08:16:40 INFO Received push request method=POST path=/api/pushes2013=== CONT TestCacheConfigHandler/full_config,_no_issuer2014--- PASS: TestPush_RejectsBadRequests (0.63s)2015 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2016 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2017 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2018 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2019=== CONT TestCacheConfigHandler/no_signing_keys2020=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2021=== CONT TestCacheConfigHandler/no_cache_url_configured2022--- PASS: TestCacheConfigHandler (0.00s)2023 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2024 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2025 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2026 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2027=== CONT TestService_RequireScope_OIDC/builder_may_write2028=== CONT TestService_RequireScope_OIDC/reader_may_read2029=== CONT TestService_RequireScope_OIDC/reader_may_not_write2030=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2031=== CONT TestService_RequireScope_OIDC/static_token_may_write2032=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2033=== CONT TestService_RequireScope_OIDC/static_token_may_admin2034=== CONT TestService_RequireScope_OIDC/writer_implies_read2035=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2036=== CONT TestService_RequireScope_OIDC/ops_may_admin2037=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2038=== CONT TestService_RequireScope_OIDC/ops_may_not_write2039=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read20402026/11/10 08:16:40 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]2041=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2042=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2043--- PASS: TestService_RequireScope_OIDC (0.58s)2044 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2045 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2046 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2047 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2048 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2049 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2050 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2051 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2052 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2053 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2054 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2055 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2056 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2057 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2058=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2059=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20602026/11/10 08:16:40 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]2061=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20622026/11/10 08:16:40 WARN Authentication failed token_preview=eyJhbGciOi...7H87gkeqCg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2063=== CONT TestResolveDBConnectionString/flag_wins2064=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2065=== CONT TestResolveDBConnectionString/nothing_configured2066=== CONT TestResolveDBConnectionString/missing_file_is_an_error2067=== CONT TestResolveDBConnectionString/file_when_flag_empty2068--- PASS: TestService_AuthMiddleware_OIDC (0.49s)2069 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2070 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2071 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2072 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2073--- PASS: TestResolveDBConnectionString (0.00s)2074 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2075 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2076 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2077 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2078 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)20792026/11/10 08:16:40 INFO Aborted multipart uploads count=0 kept=020802026/11/10 08:16:40 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/present20812026/11/10 08:16:40 INFO Received uploads request method=POST path=/api/pending_closures20822026/11/10 08:16:40 WARN Force mode enabled - objects will be deleted immediately without grace period20832026/11/10 08:16:40 INFO Aborted multipart uploads count=0 kept=020842026/11/10 08:16:40 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:34545/bucket102/?delete=\": context canceled"2085--- PASS: TestGCEndsOnShutdown (0.00s)2086 --- PASS: TestGCEndsOnShutdown/before_the_run (0.45s)2087 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.50s)2088 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.51s)20892026/11/10 08:16:40 WARN Force mode enabled - objects will be deleted immediately without grace period20902026/11/10 08:16:40 INFO Received uploads request method=POST path=/api/pending_closures20912026/11/10 08:16:40 INFO Aborted multipart uploads count=0 kept=020922026/11/10 08:16:40 WARN Force mode enabled - objects will be deleted immediately without grace period20932026/11/10 08:16:40 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=020942026/11/10 08:16:40 INFO Vacuumed table table=pending_closures20952026/11/10 08:16:40 INFO Vacuumed table table=pending_objects20962026/11/10 08:16:40 INFO Vacuumed table table=multipart_uploads20972026/11/10 08:16:40 INFO Vacuumed table table=closures20982026/11/10 08:16:40 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=020992026/11/10 08:16:40 INFO Vacuumed table table=objects21002026/11/10 08:16:40 INFO Vacuumed table table=pending_closures21012026/11/10 08:16:40 INFO Vacuumed table table=pending_objects21022026/11/10 08:16:40 INFO Vacuumed table table=multipart_uploads21032026/11/10 08:16:40 INFO Vacuumed table table=closures21042026/11/10 08:16:40 INFO lead: released remote=192.0.2.1:123421052026/11/10 08:16:40 INFO Vacuumed table table=objects2106--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2107 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.53s)2108 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.54s)2109--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.10s)2110 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.88s)2111 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.89s)21122026/11/10 08:16:40 INFO lead: acquired remote=192.0.2.1:123421132026/11/10 08:16:40 WARN Request failed, retrying attempt=2 backoff=196.49471ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21142026/11/10 08:16:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21152026/11/10 08:16:40 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21162026/11/10 08:16:40 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst upload_id=MzgzOGI3MDItYjg3Ny00NTY5LWFlMGMtNTZmYzBlZWVhZTQyLmJmMTkzNTAzLTRhNWQtNDczZC1hMTBiLWZkMTBjYzFhZmRlZXgxNzk0Mjk4NjAwMTQ0NTYwNjMz parts=1021172026/11/10 08:16:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21182026/11/10 08:16:40 INFO Completed upload id=1 objects=3 duration=3.050464ms21192026/11/10 08:16:40 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21202026/11/10 08:16:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21212026/11/10 08:16:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21222026/11/10 08:16:40 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst upload_id=MzgzOGI3MDItYjg3Ny00NTY5LWFlMGMtNTZmYzBlZWVhZTQyLjFjY2JhMWZkLTQzNDUtNGQ2Yi1iYTQzLWNhMWE0ZTc3MjAxY3gxNzk0Mjk4NjAwMjAzMTM1MTQx parts=1021232026/11/10 08:16:40 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst upload_id=MzgzOGI3MDItYjg3Ny00NTY5LWFlMGMtNTZmYzBlZWVhZTQyLjMyZTIyZmY0LTI3NGYtNGI1YS04M2M5LTA0MGEyNWQ3YzlhNXgxNzk0Mjk4NjAwMTczNjM1Mzgz parts=1021242026/11/10 08:16:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21252026/11/10 08:16:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21262026/11/10 08:16:40 INFO Received uploads request method=POST path=/api/pending_closures21272026/11/10 08:16:40 INFO Completed upload id=1 objects=3 duration=1.933806ms21282026/11/10 08:16:40 INFO Received uploads request method=POST path=/api/pending_closures21292026/11/10 08:16:40 INFO Completed upload id=1 objects=3 duration=3.196084ms21302026/11/10 08:16:40 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst21312026/11/10 08:16:40 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0001.narinfo21322026/11/10 08:16:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2133--- PASS: TestUploadHandlersRejectOversizedBody (0.19s)2134 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)2135 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)2136 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.87s)21372026/11/10 08:16:40 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst upload_id=MzgzOGI3MDItYjg3Ny00NTY5LWFlMGMtNTZmYzBlZWVhZTQyLjNjOTY2MTg0LTRjOWMtNGEwNy05OWI5LTY0MGYxYWM3M2VjM3gxNzk0Mjk4NjAwMjMzODMzMDM4 parts=1021382026/11/10 08:16:40 INFO Received uploads request method=POST path=/api/pending_closures21392026/11/10 08:16:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21402026/11/10 08:16:40 INFO Completed upload id=1 objects=3 duration=2.843694ms21412026/11/10 08:16:40 INFO Received uploads request method=POST path=/api/pending_closures21422026/11/10 08:16:40 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst21432026/11/10 08:16:40 WARN Found objects in DB but missing from S3, will re-upload count=121442026/11/10 08:16:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21452026/11/10 08:16:40 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000200000000000000000000.nar.zst upload_id=MzgzOGI3MDItYjg3Ny00NTY5LWFlMGMtNTZmYzBlZWVhZTQyLmM5NDliYWY4LTQxZDItNGVhMC05ZTZjLWRmZDNkM2QxZTRhZngxNzk0Mjk4NjAwMzc5NDgzNjQ2 parts=1021462026/11/10 08:16:40 WARN Request failed, retrying attempt=3 backoff=437.122784ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21472026/11/10 08:16:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21482026/11/10 08:16:40 INFO Completed upload id=1 objects=3 duration=1.539917ms21492026/11/10 08:16:40 INFO Received uploads request method=POST path=/api/pending_closures2150=== NAME TestOrphanedObjectsGCStressTest2151 orphaned_objects_gc_test.go:503: Stress test completed successfully:2152 orphaned_objects_gc_test.go:504: - Active objects preserved: 202153 orphaned_objects_gc_test.go:505: - Objects deleted: 2102154 orphaned_objects_gc_test.go:506: - Total GC'd: 2102155--- PASS: TestOrphanedObjectsGCStressTest (4.20s)21562026/11/10 08:16:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21572026/11/10 08:16:41 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100400000000000000000000.nar.zst upload_id=MzgzOGI3MDItYjg3Ny00NTY5LWFlMGMtNTZmYzBlZWVhZTQyLjE5YzJhYTIxLTQwMTctNDk0Mi05MzI4LWJiMjdmODc4MDlmOXgxNzk0Mjk4NjAwNzU3NjY5OTYy parts=1021582026/11/10 08:16:41 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21592026/11/10 08:16:41 INFO Completed upload id=2 objects=3 duration=1.338147ms21602026/11/10 08:16:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21612026/11/10 08:16:41 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100300000000000000000000.nar.zst upload_id=MzgzOGI3MDItYjg3Ny00NTY5LWFlMGMtNTZmYzBlZWVhZTQyLmRjNTY4ZGEzLTczMjAtNDA5MS05Yzk2LTVjYjRhOGI2N2U5NHgxNzk0Mjk4NjAwNzk5Njk0Mjg1 parts=1021622026/11/10 08:16:41 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21632026/11/10 08:16:41 INFO Completed upload id=2 objects=3 duration=691.508µs21642026/11/10 08:16:41 INFO Received uploads request method=POST path=/api/pending_closures21652026/11/10 08:16:41 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst21662026/11/10 08:16:41 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0004.narinfo2167--- PASS: TestPendingClosureWriteTimeout (0.10s)2168 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2169 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2170 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2171 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.33s)21722026/11/10 08:16:41 INFO Received uploads request method=POST path=/api/pending_closures21732026/11/10 08:16:41 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst21742026/11/10 08:16:41 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0003.narinfo2175--- PASS: TestService_verifyS3ReuploadsStaleNarinfo (0.10s)2176 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed (1.02s)2177 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed (1.02s)2178 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed (0.96s)2179 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed (1.39s)2180 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost (1.39s)21812026/11/10 08:16:41 WARN Request failed, retrying attempt=4 backoff=860.717417ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21822026/11/10 08:16:41 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02183=== NAME TestClientIntegration2184 client_integration_test.go:370: Objects in database after GC:2185 client_integration_test.go:370: Successfully deleted all objects with GC --force2186--- PASS: TestClientIntegration (3.08s)21872026/11/10 08:16:41 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=021882026/11/10 08:16:41 INFO Received create pin request method=POST path=/api/pins/myapp21892026/11/10 08:16:41 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3519948876/001/store/57cwamcm1fai4x59lchf0y770yv055qq-pinned-file.txt narinfo_key=57cwamcm1fai4x59lchf0y770yv055qq.narinfo21902026/11/10 08:16:41 INFO Starting cleanup of old closures method=DELETE path=/api/closures21912026/11/10 08:16:41 INFO Garbage collection started21922026/11/10 08:16:41 INFO Aborted multipart uploads count=0 kept=021932026/11/10 08:16:41 WARN Force mode enabled - objects will be deleted immediately without grace period21942026/11/10 08:16:41 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=021952026/11/10 08:16:41 INFO Vacuumed table table=pending_closures21962026/11/10 08:16:41 INFO Vacuumed table table=pending_objects21972026/11/10 08:16:41 INFO Vacuumed table table=multipart_uploads21982026/11/10 08:16:41 INFO Vacuumed table table=closures21992026/11/10 08:16:41 INFO Vacuumed table table=objects22002026/11/10 08:16:41 INFO lead: released remote=192.0.2.1:12342201--- PASS: TestLeadElectsOneAndHandsOver (2.81s)22022026/11/10 08:16:42 WARN Request failed, retrying attempt=5 backoff=1.531124589s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22032026/11/10 08:16:42 WARN Rate limiter enabled after throttle name=s3-test rate=522042026/11/10 08:16:42 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2205=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2206 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102207 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002208--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.55s)22092026/11/10 08:16:43 INFO Aborted multipart uploads count=1 kept=022102026/11/10 08:16:43 INFO Received cleanup request method=DELETE path=/api/pending_closures22112026/11/10 08:16:43 INFO Aborted multipart uploads count=1 kept=02212--- PASS: TestPendingCleanupUsesOneCutoff (6.50s)2213=== NAME TestPinProtectsFromGC2214 client_integration_test.go:887: Pin successfully protected closure from garbage collection2215--- PASS: TestPinProtectsFromGC (4.97s)22162026/11/10 08:16:43 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-config22172026/11/10 08:16:43 WARN Request failed, retrying attempt=2 backoff=180.159ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2218--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.64s)22192026/11/10 08:16:43 WARN Request failed, retrying attempt=3 backoff=376.532808ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22202026/11/10 08:16:44 WARN Request failed, retrying attempt=4 backoff=816.694451ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2221--- PASS: TestConnectWaitsForAPeerMigration (5.15s)22222026/11/10 08:16:45 WARN Request failed, retrying attempt=5 backoff=1.642052688s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22232026/11/10 08:16:46 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"22242026/11/10 08:16:46 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-config22252026/11/10 08:16:46 WARN Request failed, retrying attempt=2 backoff=188.741897ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22262026/11/10 08:16:47 WARN Request failed, retrying attempt=3 backoff=395.395682ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22272026/11/10 08:16:47 WARN Request failed, retrying attempt=4 backoff=858.224042ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22282026/11/10 08:16:48 WARN Request failed, retrying attempt=5 backoff=1.730281473s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22292026/11/10 08:16:50 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_closures22302026/11/10 08:16:50 WARN Request failed, retrying attempt=2 backoff=213.554076ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22312026/11/10 08:16:50 WARN Request failed, retrying attempt=3 backoff=393.039356ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22322026/11/10 08:16:50 WARN Request failed, retrying attempt=4 backoff=871.41042ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22332026/11/10 08:16:51 WARN Request failed, retrying attempt=5 backoff=1.739853113s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2234--- PASS: TestClientErrorHandling (0.00s)2235 --- PASS: TestClientErrorHandling/InvalidStorePath (0.50s)2236 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.26s)2237 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.00s)2238PASS2239{"timestamp":"2026-11-10T08:16:53.443849863Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:55828","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(401)"}2240{"timestamp":"2026-11-10T08:16:53.443824083Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:55056","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(392)"}22412026-11-10 08:16:53.792 UTC [129] LOG: received smart shutdown request22422026-11-10 08:16:53.796 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 122432026-11-10 08:16:53.807 UTC [134] LOG: shutting down22442026-11-10 08:16:53.807 UTC [134] LOG: checkpoint starting: shutdown immediate22452026-11-10 08:16:55.324 UTC [134] LOG: checkpoint complete: wrote 11303 buffers (69.0%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.318 s, sync=1.149 s, total=1.518 s; sync files=36061, longest=0.056 s, average=0.001 s; distance=521425 kB, estimate=521425 kB; lsn=0/2149A3B8, redo lsn=0/2149A3B822462026-11-10 08:16:55.391 UTC [129] LOG: database system is shut down2247Running OIDC tests...2248=== RUN TestAudienceForIssuer2249=== PAUSE TestAudienceForIssuer2250=== RUN TestGlobMatch2251=== PAUSE TestGlobMatch2252=== RUN TestValidateToken_ValidToken2253=== PAUSE TestValidateToken_ValidToken2254=== RUN TestValidateToken_WrongAudience2255=== PAUSE TestValidateToken_WrongAudience2256=== RUN TestValidateToken_Expired2257=== PAUSE TestValidateToken_Expired2258=== RUN TestValidateToken_BoundClaimsMismatch2259=== PAUSE TestValidateToken_BoundClaimsMismatch2260=== RUN TestValidateToken_BoundSubjectMismatch2261=== PAUSE TestValidateToken_BoundSubjectMismatch2262=== RUN TestValidateToken_MultipleProviders2263=== PAUSE TestValidateToken_MultipleProviders2264=== RUN TestValidateToken_NoMatchingProvider2265=== PAUSE TestValidateToken_NoMatchingProvider2266=== RUN TestValidateToken_KubernetesServiceAccount2267=== PAUSE TestValidateToken_KubernetesServiceAccount2268=== RUN TestNewValidator_KubernetesRequiresCA2269=== PAUSE TestNewValidator_KubernetesRequiresCA2270=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2271=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2272=== RUN TestPins_ReservedForMatchingRule2273=== PAUSE TestPins_ReservedForMatchingRule2274=== RUN TestPins_TopLevelShorthand2275=== PAUSE TestPins_TopLevelShorthand2276=== RUN TestPins_ConfigValidation2277=== PAUSE TestPins_ConfigValidation2278=== RUN TestScopes_LegacyProviderDefaultsToWrite2279=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2280=== RUN TestScopes_Rules2281=== PAUSE TestScopes_Rules2282=== RUN TestScopes_ConfigValidation2283=== PAUSE TestScopes_ConfigValidation2284=== CONT TestAudienceForIssuer2285=== CONT TestValidateToken_KubernetesServiceAccount2286--- PASS: TestAudienceForIssuer (0.00s)2287=== CONT TestValidateToken_NoMatchingProvider2288=== CONT TestValidateToken_MultipleProviders2289=== CONT TestValidateToken_BoundSubjectMismatch2290=== CONT TestValidateToken_BoundClaimsMismatch2291=== CONT TestValidateToken_Expired2292=== CONT TestValidateToken_WrongAudience2293=== CONT TestValidateToken_ValidToken2294=== CONT TestGlobMatch2295=== CONT TestScopes_Rules2296=== CONT TestScopes_ConfigValidation2297=== CONT TestPins_TopLevelShorthand2298=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2299=== CONT TestScopes_LegacyProviderDefaultsToWrite2300=== CONT TestNewValidator_KubernetesRequiresCA2301=== CONT TestPins_ConfigValidation2302=== CONT TestPins_ReservedForMatchingRule2303=== RUN TestGlobMatch/foo_foo2304=== PAUSE TestGlobMatch/foo_foo2305=== RUN TestGlobMatch/foo_bar2306=== PAUSE TestGlobMatch/foo_bar2307=== RUN TestGlobMatch/*_2308=== PAUSE TestGlobMatch/*_2309=== RUN TestGlobMatch/*_anything2310=== PAUSE TestGlobMatch/*_anything2311=== RUN TestGlobMatch/foo*_foo2312=== PAUSE TestGlobMatch/foo*_foo2313=== RUN TestGlobMatch/foo*_foobar2314=== PAUSE TestGlobMatch/foo*_foobar2315=== RUN TestGlobMatch/foo*_bar2316=== PAUSE TestGlobMatch/foo*_bar2317=== RUN TestGlobMatch/*bar_bar2318=== PAUSE TestGlobMatch/*bar_bar2319=== RUN TestGlobMatch/*bar_foobar2320=== PAUSE TestGlobMatch/*bar_foobar2321=== RUN TestGlobMatch/*bar_foo2322=== PAUSE TestGlobMatch/*bar_foo2323--- PASS: TestScopes_ConfigValidation (0.00s)2324=== RUN TestGlobMatch/foo*bar_foobar2325=== PAUSE TestGlobMatch/foo*bar_foobar2326--- PASS: TestPins_ConfigValidation (0.00s)2327=== RUN TestGlobMatch/foo*bar_foo123bar2328=== PAUSE TestGlobMatch/foo*bar_foo123bar2329=== RUN TestGlobMatch/foo*bar_foobarbaz2330=== PAUSE TestGlobMatch/foo*bar_foobarbaz2331=== RUN TestGlobMatch/*/*_foo/bar2332=== PAUSE TestGlobMatch/*/*_foo/bar2333=== RUN TestGlobMatch/*/*_foo2334=== PAUSE TestGlobMatch/*/*_foo2335=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2336=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2337=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02338=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02339=== RUN TestGlobMatch/refs/*/main_refs/heads/main2340=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2341=== RUN TestGlobMatch/fo?_foo2342=== PAUSE TestGlobMatch/fo?_foo2343=== RUN TestGlobMatch/fo?_fo2344=== PAUSE TestGlobMatch/fo?_fo2345=== RUN TestGlobMatch/fo?_fooo2346=== PAUSE TestGlobMatch/fo?_fooo2347=== RUN TestGlobMatch/?oo_foo2348=== PAUSE TestGlobMatch/?oo_foo2349=== RUN TestGlobMatch/?oo_boo2350=== PAUSE TestGlobMatch/?oo_boo2351=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2352=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2353=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2354=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2355=== CONT TestGlobMatch/foo_foo2356=== CONT TestGlobMatch/fo?_foo2357=== CONT TestGlobMatch/foo*bar_foobar2358=== CONT TestGlobMatch/*bar_foo2359=== CONT TestGlobMatch/fo?_fo2360=== CONT TestGlobMatch/*bar_bar2361=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2362=== CONT TestGlobMatch/foo*_bar2363=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2364=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2365=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02366=== CONT TestGlobMatch/*_2367=== CONT TestGlobMatch/foo_bar2368=== CONT TestGlobMatch/?oo_boo2369=== CONT TestGlobMatch/*/*_foo2370=== CONT TestGlobMatch/*_anything2371=== CONT TestGlobMatch/?oo_foo2372=== CONT TestGlobMatch/foo*bar_foobarbaz2373=== CONT TestGlobMatch/foo*bar_foo123bar2374=== CONT TestGlobMatch/fo?_fooo2375=== CONT TestGlobMatch/*/*_foo/bar2376=== CONT TestGlobMatch/*bar_foobar2377=== CONT TestGlobMatch/refs/*/main_refs/heads/main2378=== CONT TestGlobMatch/foo*_foobar2379=== CONT TestGlobMatch/foo*_foo2380--- PASS: TestGlobMatch (0.01s)2381 --- PASS: TestGlobMatch/foo_foo (0.00s)2382 --- PASS: TestGlobMatch/fo?_foo (0.00s)2383 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2384 --- PASS: TestGlobMatch/*bar_foo (0.00s)2385 --- PASS: TestGlobMatch/fo?_fo (0.00s)2386 --- PASS: TestGlobMatch/*bar_bar (0.00s)2387 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2388 --- PASS: TestGlobMatch/foo*_bar (0.00s)2389 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2390 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2391 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2392 --- PASS: TestGlobMatch/*_ (0.00s)2393 --- PASS: TestGlobMatch/foo_bar (0.00s)2394 --- PASS: TestGlobMatch/?oo_boo (0.00s)2395 --- PASS: TestGlobMatch/*/*_foo (0.00s)2396 --- PASS: TestGlobMatch/*_anything (0.00s)2397 --- PASS: TestGlobMatch/?oo_foo (0.00s)2398 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2399 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2400 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2401 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2402 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2403 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2404 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2405 --- PASS: TestGlobMatch/foo*_foo (0.00s)24062026/11/10 08:16:57 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:460212407--- PASS: TestValidateToken_KubernetesServiceAccount (0.03s)24082026/11/10 08:16:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36349/oidc2409--- PASS: TestValidateToken_BoundClaimsMismatch (0.04s)24102026/11/10 08:16:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44329/oidc2411--- PASS: TestPins_TopLevelShorthand (0.06s)24122026/11/10 08:16:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37761/oidc2413--- PASS: TestScopes_Rules (0.06s)24142026/11/10 08:16:57 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232415--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.07s)24162026/11/10 08:16:57 http: TLS handshake error from 127.0.0.1:40876: remote error: tls: bad certificate2417--- PASS: TestNewValidator_KubernetesRequiresCA (0.07s)24182026/11/10 08:16:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42121/oidc2419--- PASS: TestValidateToken_BoundSubjectMismatch (0.09s)24202026/11/10 08:16:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39981/oidc2421--- PASS: TestValidateToken_WrongAudience (0.09s)24222026/11/10 08:16:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46285/oidc2423--- PASS: TestValidateToken_Expired (0.10s)24242026/11/10 08:16:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45579/oidc2425--- PASS: TestPins_ReservedForMatchingRule (0.10s)24262026/11/10 08:16:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39697/oidc2427--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.11s)24282026/11/10 08:16:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45723/oidc2429--- PASS: TestValidateToken_ValidToken (0.14s)24302026/11/10 08:16:57 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:44257/oidc24312026/11/10 08:16:57 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:46639/oidc2432--- PASS: TestValidateToken_MultipleProviders (0.15s)24332026/11/10 08:16:57 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:42281/oidc2434--- PASS: TestValidateToken_NoMatchingProvider (0.17s)2435PASS2436Running hook tests...2437=== RUN TestSendPathsEmpty2438=== PAUSE TestSendPathsEmpty2439=== RUN TestQueueEnqueueAndFetch2440=== PAUSE TestQueueEnqueueAndFetch2441=== RUN TestQueueDeduplication2442=== PAUSE TestQueueDeduplication2443=== RUN TestQueueRemove2444=== PAUSE TestQueueRemove2445=== RUN TestQueueFetchBatchLimit2446=== PAUSE TestQueueFetchBatchLimit2447=== RUN TestQueueRetryMovesToBack2448=== PAUSE TestQueueRetryMovesToBack2449=== RUN TestQueueFetchRemoveLifecycle2450=== PAUSE TestQueueFetchRemoveLifecycle2451=== RUN TestQueueConcurrentWriters2452=== PAUSE TestQueueConcurrentWriters2453=== RUN TestQueueRemoveLargeClosure2454=== PAUSE TestQueueRemoveLargeClosure2455=== RUN TestServerClientIntegration2456--- PASS: TestServerClientIntegration (0.00s)2457=== RUN TestServerQueueError24582026/11/10 08:16:57 ERROR Failed to queue paths error="permission denied" count=12459--- PASS: TestServerQueueError (0.00s)2460=== RUN TestGetListenerSocketActivation2461 server_test.go:218: === RUN TestGetListenerSocketActivation2462 --- PASS: TestGetListenerSocketActivation (0.00s)2463 PASS2464 2465--- PASS: TestGetListenerSocketActivation (0.01s)2466=== RUN TestServerStalledClientDoesNotBlockShutdown2467=== PAUSE TestServerStalledClientDoesNotBlockShutdown2468=== RUN TestServerBacksOffOnAcceptErrors2469=== PAUSE TestServerBacksOffOnAcceptErrors2470=== RUN TestDrainIsolatesPoisonPath2471=== PAUSE TestDrainIsolatesPoisonPath2472=== RUN TestRunNotBlockedByPoisonHead2473=== PAUSE TestRunNotBlockedByPoisonHead2474=== RUN TestDrainGivesUpWhenServerDown2475=== PAUSE TestDrainGivesUpWhenServerDown2476=== RUN TestFailedPathPrunedByLaterClosure2477=== PAUSE TestFailedPathPrunedByLaterClosure2478=== RUN TestWorkerUploadsAndRemoves2479=== PAUSE TestWorkerUploadsAndRemoves2480=== RUN TestWorkerSkipsGCdPaths2481=== PAUSE TestWorkerSkipsGCdPaths2482=== RUN TestWorkerPrunesClosureDeps2483=== PAUSE TestWorkerPrunesClosureDeps2484=== RUN TestDrainTimeout2485=== PAUSE TestDrainTimeout2486=== RUN TestWorkerRemoveFailureIsNotProgress2487=== PAUSE TestWorkerRemoveFailureIsNotProgress2488=== RUN TestWorkerKeepsPathItCannotStat2489=== PAUSE TestWorkerKeepsPathItCannotStat2490=== CONT TestSendPathsEmpty2491=== CONT TestWorkerKeepsPathItCannotStat2492--- PASS: TestSendPathsEmpty (0.00s)2493=== CONT TestDrainIsolatesPoisonPath2494=== CONT TestServerBacksOffOnAcceptErrors2495=== CONT TestServerStalledClientDoesNotBlockShutdown24962026/11/10 08:16:57 ERROR Accept failed error="too many open files"2497=== CONT TestQueueRemoveLargeClosure2498=== CONT TestQueueConcurrentWriters2499=== CONT TestQueueFetchRemoveLifecycle2500=== CONT TestQueueRetryMovesToBack2501=== CONT TestQueueFetchBatchLimit2502=== CONT TestQueueRemove2503=== CONT TestQueueDeduplication2504=== CONT TestQueueEnqueueAndFetch2505=== CONT TestFailedPathPrunedByLaterClosure2506=== CONT TestWorkerUploadsAndRemoves2507=== CONT TestDrainTimeout2508=== CONT TestWorkerRemoveFailureIsNotProgress2509=== CONT TestWorkerPrunesClosureDeps2510=== CONT TestRunNotBlockedByPoisonHead2511=== CONT TestDrainGivesUpWhenServerDown2512=== CONT TestWorkerSkipsGCdPaths25132026/11/10 08:16:57 ERROR Accept failed error="too many open files"25142026/11/10 08:16:57 INFO Upload queue status pending=325152026/11/10 08:16:57 ERROR Accept failed error="too many open files"25162026/11/10 08:16:57 INFO Uploading batch count=125172026/11/10 08:16:57 ERROR Upload failed error="upload failed" count=125182026/11/10 08:16:57 INFO Uploading batch count=42519--- PASS: TestQueueFetchBatchLimit (0.02s)25202026/11/10 08:16:57 ERROR Upload failed error="upload failed" count=425212026/11/10 08:16:57 INFO Upload queue status pending=225222026/11/10 08:16:57 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2934941986/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat2934941986/002/locked/aaa: permission denied"25232026/11/10 08:16:57 INFO Uploading batch count=225242026/11/10 08:16:57 INFO Uploading batch count=125252026/11/10 08:16:57 ERROR Upload failed error="upload failed" count=125262026/11/10 08:16:57 INFO Upload queue status pending=225272026/11/10 08:16:57 INFO Upload queue status pending=225282026/11/10 08:16:57 INFO Uploading batch count=225292026/11/10 08:16:57 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2044101198/002/nonexistent25302026/11/10 08:16:57 INFO Uploading batch count=12531--- PASS: TestQueueRemove (0.02s)25322026/11/10 08:16:57 INFO Uploading batch count=225332026/11/10 08:16:57 ERROR Upload failed error="upload failed" count=225342026/11/10 08:16:57 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4172018681/002/a2535--- PASS: TestQueueRetryMovesToBack (0.02s)25362026/11/10 08:16:57 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3097902974/002/bbb2537--- PASS: TestQueueDeduplication (0.02s)25382026/11/10 08:16:57 INFO Uploading batch count=125392026/11/10 08:16:57 INFO Uploading batch count=125402026/11/10 08:16:57 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4172018681/002/b2541--- PASS: TestQueueFetchRemoveLifecycle (0.02s)25422026/11/10 08:16:57 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2934941986/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat2934941986/002/locked/aaa: permission denied"25432026/11/10 08:16:57 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress2298704556/002/nonexistent25442026/11/10 08:16:57 INFO Uploading batch count=22545--- PASS: TestQueueEnqueueAndFetch (0.02s)25462026/11/10 08:16:57 ERROR Upload failed error="upload failed" count=225472026/11/10 08:16:57 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4172018681/002/c25482026/11/10 08:16:57 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125492026/11/10 08:16:57 INFO Uploading batch count=125502026/11/10 08:16:57 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress2298704556/002/nonexistent25512026/11/10 08:16:57 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125522026/11/10 08:16:57 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2934941986/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat2934941986/002/locked/aaa: permission denied"25532026/11/10 08:16:57 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4172018681/002/d25542026/11/10 08:16:57 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress2298704556/002/nonexistent25552026/11/10 08:16:57 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125562026/11/10 08:16:57 ERROR Drain finished with paths left in queue remaining=125572026/11/10 08:16:57 ERROR Drain finished with paths left in queue remaining=125582026/11/10 08:16:57 INFO Uploading batch count=125592026/11/10 08:16:57 ERROR Upload failed error="upload failed" count=125602026/11/10 08:16:57 INFO Uploading batch count=225612026/11/10 08:16:57 ERROR Upload failed error="upload failed" count=225622026/11/10 08:16:57 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4172018681/002/e2563--- PASS: TestWorkerRemoveFailureIsNotProgress (0.02s)25642026/11/10 08:16:57 INFO Uploading batch count=125652026/11/10 08:16:57 ERROR Upload failed error="upload failed" count=125662026/11/10 08:16:57 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4172018681/002/f25672026/11/10 08:16:57 INFO Uploading batch count=125682026/11/10 08:16:57 ERROR Upload failed error="upload failed" count=125692026/11/10 08:16:57 ERROR Drain finished with paths left in queue remaining=102570--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)25712026/11/10 08:16:57 ERROR Drain finished with paths left in queue remaining=12572--- PASS: TestWorkerKeepsPathItCannotStat (0.02s)2573--- PASS: TestDrainIsolatesPoisonPath (0.03s)2574--- PASS: TestDrainGivesUpWhenServerDown (0.02s)25752026/11/10 08:16:57 ERROR Accept failed error="too many open files"2576--- PASS: TestWorkerUploadsAndRemoves (0.03s)2577--- PASS: TestWorkerSkipsGCdPaths (0.03s)2578--- PASS: TestWorkerPrunesClosureDeps (0.04s)2579--- PASS: TestQueueRemoveLargeClosure (0.07s)25802026/11/10 08:16:58 ERROR Accept failed error="too many open files"25812026/11/10 08:16:58 ERROR Accept failed error="too many open files"25822026/11/10 08:16:58 ERROR Failed to decode request error="read unix /build/hook716764399/test.sock->@: i/o timeout"25832026/11/10 08:16:58 ERROR Failed to write response error="write unix /build/hook716764399/test.sock->@: i/o timeout"2584--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)2585--- PASS: TestQueueConcurrentWriters (0.21s)25862026/11/10 08:16:58 ERROR Upload failed error="context deadline exceeded" count=225872026/11/10 08:16:58 ERROR Drain finished with paths left in queue remaining=42588--- PASS: TestDrainTimeout (0.22s)25892026/11/10 08:16:58 ERROR Accept failed error="too many open files"25902026/11/10 08:16:58 ERROR Accept failed error="too many open files"2591--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)25922026/11/10 08:16:58 INFO Uploading batch count=125932026/11/10 08:16:58 INFO Uploading batch count=125942026/11/10 08:16:58 INFO Uploading batch count=125952026/11/10 08:16:58 ERROR Upload failed error="upload failed" count=125962026/11/10 08:16:58 INFO Uploading batch count=125972026/11/10 08:16:58 ERROR Upload failed error="upload failed" count=125982026/11/10 08:16:58 INFO Uploading batch count=125992026/11/10 08:16:58 ERROR Upload failed error="upload failed" count=126002026/11/10 08:16:58 INFO Uploading batch count=126012026/11/10 08:16:58 ERROR Upload failed error="upload failed" count=126022026/11/10 08:16:58 ERROR Drain finished with paths left in queue remaining=12603--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2604PASS2605Running signing tests...2606=== RUN TestExternalSigner2607=== PAUSE TestExternalSigner2608=== RUN TestExternalSignerWrongPublicKey2609=== PAUSE TestExternalSignerWrongPublicKey2610=== RUN TestExternalSignerErrors2611=== PAUSE TestExternalSignerErrors2612=== RUN TestExternalSignerRestartsAfterCrash2613=== PAUSE TestExternalSignerRestartsAfterCrash2614=== RUN TestExternalSignerProgramErrorKeepsProcess2615=== PAUSE TestExternalSignerProgramErrorKeepsProcess2616=== RUN TestExternalSignerClose2617=== PAUSE TestExternalSignerClose2618=== RUN TestExternalSignerRejectsInvalidPublicKey2619=== PAUSE TestExternalSignerRejectsInvalidPublicKey2620=== RUN TestExternalSignerCancellation2621=== PAUSE TestExternalSignerCancellation2622=== RUN TestGenerateFingerprint2623=== PAUSE TestGenerateFingerprint2624=== RUN TestParseSigningKey2625=== PAUSE TestParseSigningKey2626=== RUN TestSign2627=== PAUSE TestSign2628=== RUN TestSignBatch2629=== PAUSE TestSignBatch2630=== RUN TestNilKeyPublicKey2631=== PAUSE TestNilKeyPublicKey2632=== RUN TestSignErrors2633=== PAUSE TestSignErrors2634=== CONT TestExternalSigner2635=== CONT TestExternalSignerCancellation2636=== CONT TestSignBatch2637=== CONT TestParseSigningKey2638=== CONT TestGenerateFingerprint2639=== CONT TestExternalSignerProgramErrorKeepsProcess2640=== CONT TestExternalSignerRejectsInvalidPublicKey2641=== RUN TestExternalSignerRejectsInvalidPublicKey/#002642=== CONT TestExternalSignerClose2643=== CONT TestExternalSignerErrors2644=== CONT TestExternalSignerRestartsAfterCrash2645=== CONT TestExternalSignerWrongPublicKey2646=== CONT TestSign2647=== CONT TestSignErrors2648=== CONT TestNilKeyPublicKey2649=== RUN TestParseSigningKey/valid_32-byte_key2650=== RUN TestGenerateFingerprint/basic_with_references2651=== PAUSE TestGenerateFingerprint/basic_with_references2652=== RUN TestGenerateFingerprint/no_references2653=== PAUSE TestGenerateFingerprint/no_references2654=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2655=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2656=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2657=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2658=== RUN TestGenerateFingerprint/invalid_nar_hash_length2659=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2660=== RUN TestGenerateFingerprint/invalid_store_path_prefix2661=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2662=== RUN TestGenerateFingerprint/invalid_reference_prefix2663=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2664=== CONT TestGenerateFingerprint/basic_with_references2665=== CONT TestGenerateFingerprint/invalid_reference_prefix2666--- PASS: TestSignBatch (0.00s)2667=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002668=== CONT TestGenerateFingerprint/invalid_store_path_prefix2669=== CONT TestGenerateFingerprint/invalid_nar_hash_length2670=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2671=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2672=== CONT TestGenerateFingerprint/no_references2673=== PAUSE TestParseSigningKey/valid_32-byte_key2674=== RUN TestSignErrors/nil_key2675=== RUN TestExternalSignerErrors/exit_on_request2676=== PAUSE TestExternalSignerErrors/exit_on_request2677=== RUN TestExternalSignerErrors/wrong_signature_length2678=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2679=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2680--- PASS: TestNilKeyPublicKey (0.00s)2681--- PASS: TestSign (0.00s)2682=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2683--- PASS: TestGenerateFingerprint (0.00s)2684 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2685 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2686 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2687 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2688 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2689 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2690 --- PASS: TestGenerateFingerprint/no_references (0.00s)2691=== PAUSE TestSignErrors/nil_key2692=== PAUSE TestExternalSignerErrors/wrong_signature_length2693=== RUN TestSignErrors/nil_narinfo2694=== PAUSE TestSignErrors/nil_narinfo2695=== RUN TestSignErrors/invalid_narinfo2696=== PAUSE TestSignErrors/invalid_narinfo2697=== RUN TestSignErrors/canceled2698=== PAUSE TestSignErrors/canceled2699=== CONT TestSignErrors/nil_key2700=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2701=== RUN TestParseSigningKey/no_colon2702=== PAUSE TestParseSigningKey/no_colon2703=== RUN TestParseSigningKey/empty_name2704=== PAUSE TestParseSigningKey/empty_name2705=== CONT TestSignErrors/canceled2706=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2707=== RUN TestExternalSignerErrors/null_signatures2708=== PAUSE TestExternalSignerErrors/null_signatures2709=== CONT TestSignErrors/nil_narinfo2710=== CONT TestSignErrors/invalid_narinfo2711=== RUN TestParseSigningKey/invalid_base642712=== PAUSE TestParseSigningKey/invalid_base642713=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2714=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2715=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2716=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2717=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2718=== CONT TestExternalSignerRejectsInvalidPublicKey/#002719=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2720=== RUN TestExternalSignerErrors/too_few_signatures2721=== PAUSE TestExternalSignerErrors/too_few_signatures2722--- PASS: TestSignErrors (0.00s)2723 --- PASS: TestSignErrors/nil_key (0.00s)2724 --- PASS: TestSignErrors/canceled (0.00s)2725 --- PASS: TestSignErrors/nil_narinfo (0.00s)2726 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2727=== RUN TestParseSigningKey/wrong_length2728=== PAUSE TestParseSigningKey/wrong_length2729=== CONT TestParseSigningKey/valid_32-byte_key2730=== CONT TestParseSigningKey/wrong_length2731=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2732=== CONT TestParseSigningKey/no_colon2733=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2734=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2735=== RUN TestExternalSignerErrors/wrong_shape2736=== CONT TestParseSigningKey/empty_name2737=== CONT TestParseSigningKey/invalid_base642738=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2739--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2740 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2741 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2742 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2743 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2744 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2745--- PASS: TestParseSigningKey (0.00s)2746 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2747 --- PASS: TestParseSigningKey/wrong_length (0.00s)2748 --- PASS: TestParseSigningKey/no_colon (0.00s)2749 --- PASS: TestParseSigningKey/empty_name (0.00s)2750 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2751 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2752=== PAUSE TestExternalSignerErrors/wrong_shape2753=== RUN TestExternalSignerErrors/wrong_signatures_shape2754=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2755=== RUN TestExternalSignerErrors/unrequested_key2756=== PAUSE TestExternalSignerErrors/unrequested_key2757=== RUN TestExternalSignerErrors/invalid_signature_base642758=== PAUSE TestExternalSignerErrors/invalid_signature_base642759=== RUN TestExternalSignerErrors/program_error2760=== PAUSE TestExternalSignerErrors/program_error2761=== RUN TestExternalSignerErrors/exit_at_startup2762=== PAUSE TestExternalSignerErrors/exit_at_startup2763=== RUN TestExternalSignerErrors/invalid_JSON2764=== PAUSE TestExternalSignerErrors/invalid_JSON2765=== RUN TestExternalSignerErrors/null2766--- PASS: TestExternalSignerClose (0.00s)2767=== PAUSE TestExternalSignerErrors/null2768--- PASS: TestExternalSignerWrongPublicKey (0.00s)2769=== RUN TestExternalSignerErrors/wrong_id2770=== PAUSE TestExternalSignerErrors/wrong_id2771=== RUN TestExternalSignerErrors/missing_signatures2772=== PAUSE TestExternalSignerErrors/missing_signatures2773=== RUN TestExternalSignerErrors/missing_signature_name2774=== PAUSE TestExternalSignerErrors/missing_signature_name2775=== RUN TestExternalSignerErrors/wrong_signature_name2776=== PAUSE TestExternalSignerErrors/wrong_signature_name2777=== CONT TestExternalSignerErrors/exit_on_request2778=== CONT TestExternalSignerErrors/wrong_id2779=== CONT TestExternalSignerErrors/wrong_shape2780=== CONT TestExternalSignerErrors/too_few_signatures2781=== CONT TestExternalSignerErrors/program_error2782=== CONT TestExternalSignerErrors/invalid_JSON2783=== CONT TestExternalSignerErrors/wrong_signature_name2784=== CONT TestExternalSignerErrors/missing_signature_name2785=== CONT TestExternalSignerErrors/missing_signatures2786--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.01s)2787=== CONT TestExternalSignerErrors/null_signatures2788=== CONT TestExternalSignerErrors/unrequested_key2789=== CONT TestExternalSignerErrors/wrong_signature_length2790--- PASS: TestExternalSigner (0.01s)2791=== CONT TestExternalSignerErrors/invalid_signature_base642792=== CONT TestExternalSignerErrors/wrong_signatures_shape2793=== CONT TestExternalSignerErrors/null2794=== CONT TestExternalSignerErrors/exit_at_startup2795--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2796--- PASS: TestExternalSignerErrors (0.00s)2797 --- PASS: TestExternalSignerErrors/wrong_id (0.00s)2798 --- PASS: TestExternalSignerErrors/program_error (0.00s)2799 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2800 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)2801 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)2802 --- PASS: TestExternalSignerErrors/missing_signatures (0.00s)2803 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.00s)2804 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2805 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2806 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2807 --- PASS: TestExternalSignerErrors/null (0.00s)2808 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.00s)2809 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2810 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2811 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2812 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2813--- PASS: TestExternalSignerCancellation (0.02s)2814PASS2815Running OpenBao signer tests...2816=== RUN TestSign2817=== PAUSE TestSign2818=== RUN TestSignErrors2819=== PAUSE TestSignErrors2820=== RUN TestServe2821=== PAUSE TestServe2822=== RUN TestServeRejectsGarbage2823=== PAUSE TestServeRejectsGarbage2824=== CONT TestSign2825=== CONT TestSignErrors2826=== RUN TestSignErrors/http_error2827=== PAUSE TestSignErrors/http_error2828=== RUN TestSignErrors/invalid_json2829=== CONT TestServeRejectsGarbage2830=== CONT TestServe2831=== PAUSE TestSignErrors/invalid_json2832--- PASS: TestServeRejectsGarbage (0.00s)2833=== RUN TestSignErrors/no_prefix2834=== PAUSE TestSignErrors/no_prefix2835=== RUN TestSignErrors/invalid_base642836=== PAUSE TestSignErrors/invalid_base642837=== CONT TestSignErrors/http_error2838=== CONT TestSignErrors/invalid_base642839=== CONT TestSignErrors/no_prefix2840=== CONT TestSignErrors/invalid_json2841--- PASS: TestServe (0.00s)2842--- PASS: TestSignErrors (0.00s)2843 --- PASS: TestSignErrors/invalid_base64 (0.00s)2844 --- PASS: TestSignErrors/invalid_json (0.00s)2845 --- PASS: TestSignErrors/http_error (0.00s)2846 --- PASS: TestSignErrors/no_prefix (0.00s)2847--- PASS: TestSign (0.00s)2848PASS