niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #468
· raw
1tribuchet: building on mac022Running 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.08s)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 TestSetClientTLS115=== CONT TestRetryTimeoutOutlastsMaxRetries116=== CONT TestStreamPushGivesUpOnDeadServer117=== CONT TestStreamPushStopsWhenCanceled118--- PASS: TestStreamPushStopsWhenCanceled (0.00s)119=== CONT TestStaticToken120=== CONT TestClientSignaturesByStorePath121=== CONT TestDoWithRetry_FinalResponseBodyReadable122=== CONT TestStreamPushReportsSkippedPaths123=== CONT TestStreamPushReportsSignatures124=== CONT TestStreamPushRequestLine125=== CONT TestStreamPushReportsEveryPath126=== CONT TestStreamPushIsolatesFailures127=== CONT TestStreamPushBatchesUnderLoad1282026/11/06 08:18:22 ERROR Upload failed error="connection refused" count=201292026/11/06 08:18:22 ERROR Upload failed error=boom count=11302026/11/06 08:18:22 ERROR Server seems unavailable, giving up on batch untried=17131=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false1322026/11/06 08:18:22 ERROR Upload failed error=boom count=11332026/11/06 08:18:22 ERROR Upload failed error="bad path" count=3134=== CONT TestScriptTokenNoExpiryRerunsEveryCall135=== CONT TestScriptTokenEmptyCommand136=== CONT TestScriptTokenScriptFails137=== CONT TestScriptTokenBadJSON138=== CONT TestScriptTokenEmptyToken139=== CONT TestScriptTokenCachesUntilRefresh140=== CONT TestFileTokenReadsAndCaches141=== CONT TestFileTokenEmpty142=== CONT TestFileTokenMissing143=== CONT TestShellSplit144=== CONT TestShellSplitErrors145=== CONT TestSetClientTLSErrors146--- PASS: TestStaticToken (0.00s)147=== CONT TestSetClientTLSDoesNotMutateDefaultTransport148=== CONT TestResolveStorePath149=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess150=== CONT TestRateLimiterFeedback151=== RUN TestRateLimiterFeedback/429_enables_limiter152=== PAUSE TestRateLimiterFeedback/429_enables_limiter153=== RUN TestRateLimiterFeedback/503_enables_limiter154=== PAUSE TestRateLimiterFeedback/503_enables_limiter155=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter156=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter157=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter1582026/11/06 08:18:22 WARN Rate limiter enabled after throttle name=server-test rate=5159--- PASS: TestClientSignaturesByStorePath (0.00s)160--- PASS: TestStreamPushReportsSkippedPaths (0.00s)161=== CONT TestRegisterUploadedObject_OutlivesPush1622026/11/06 08:18:22 WARN Rate limiter enabled after throttle name=server-test rate=5163=== CONT TestEncodeNixBase32WithRealHash164=== CONT TestDoWithRetry_BodyReplayedViaGetBody165=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false166=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer167=== CONT TestPathInfoCACompatibility168=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter169--- PASS: TestStreamPushReportsEveryPath (0.00s)170=== CONT TestParsePathInfoJSONMultiplePaths171=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths172=== CONT TestParsePathInfoJSON173--- PASS: TestStreamPushReportsSignatures (0.00s)174--- PASS: TestStreamPushIsolatesFailures (0.00s)175--- PASS: TestScriptTokenEmptyCommand (0.00s)176--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)177--- PASS: TestShellSplit (0.00s)178--- PASS: TestShellSplitErrors (0.00s)179--- PASS: TestFileTokenReadsAndCaches (0.00s)180--- PASS: TestEncodeNixBase32WithRealHash (0.00s)181=== RUN TestPathInfoCACompatibility/null_ca_field182=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths183=== PAUSE TestPathInfoCACompatibility/null_ca_field1842026/11/06 08:18:22 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:572271852026/11/06 08:18:22 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:57226186=== RUN TestPathInfoCACompatibility/old_string_format_-_text187=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text188=== RUN TestSetClientTLSErrors/missing_cert_file189=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths190=== CONT TestPathInfoHashCompatibility191=== RUN TestParsePathInfoJSON/Nix_format192=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true193=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive194--- PASS: TestFileTokenEmpty (0.01s)195--- PASS: TestDoServerRequestAttachesToken (0.01s)196--- PASS: TestResolveStorePath (0.01s)197=== CONT TestGetStorePathHash198=== CONT TestConvertHashToNix32199=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths200--- PASS: TestFileTokenMissing (0.01s)201=== CONT TestUploadMultipart_PartsInParallel202=== CONT TestPartSizeForNAR2032026/11/06 08:18:22 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:572262042026/11/06 08:18:22 WARN Rate limiter backed off name=server-test rate=5205=== RUN TestSetClientTLS/rejects_connection_without_client_cert206=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert207=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA208=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA209=== RUN TestSetClientTLS/preserves_debug_logging_transport210=== PAUSE TestSetClientTLS/preserves_debug_logging_transport2112026/11/06 08:18:22 WARN Rate limiter enabled after throttle name=server-test rate=5212=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true213=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive214=== CONT TestDumpPathMatchesNix215=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)216=== RUN TestPartSizeForNAR/zero_stays_at_minimum2172026/11/06 08:18:22 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:572352182026/11/06 08:18:22 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:57226219=== RUN TestGetStorePathHash/valid_store_path220=== PAUSE TestParsePathInfoJSON/Nix_format221--- PASS: TestScriptTokenScriptFails (0.01s)222=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun223=== PAUSE TestSetClientTLSErrors/missing_cert_file224=== CONT TestUploadMultipart_ReturnsAfterDroppedBody225=== RUN TestConvertHashToNix32/SRI_format_to_Nix32226=== CONT TestFilterOversizedClosures2272026/11/06 08:18:22 WARN Rate limiter backed off name=server-test rate=52282026/11/06 08:18:22 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:572352292026/11/06 08:18:22 INFO Garbage collection started2302026/11/06 08:18:22 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:57226231=== CONT TestCaseHackSuffix2322026/11/06 08:18:22 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:57226233=== CONT TestEncodeNixBase32234=== CONT TestRegisterUploadedObjectReusesConnections235=== RUN TestPathInfoCACompatibility/new_structured_format_-_text236=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)237=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum238=== PAUSE TestGetStorePathHash/valid_store_path239=== RUN TestParsePathInfoJSON/Lix_format240--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)241=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32242=== RUN TestSetClientTLSErrors/missing_key_file243=== RUN TestFilterOversizedClosures/no_limit_keeps_everything244=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica245=== CONT TestDumpPathWriterError246=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry247=== PAUSE TestParsePathInfoJSON/Lix_format248=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text249=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method2502026/11/06 08:18:22 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:57236/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:57236/api/uploads/complete2512026/11/06 08:18:22 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"2522026/11/06 08:18:22 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:57236/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:57236/api/uploads/complete2532026/11/06 08:18:22 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"2542026/11/06 08:18:22 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:57236/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:57236/api/uploads/complete2552026/11/06 08:18:22 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"256=== RUN TestEncodeNixBase32/test_string_hash257=== PAUSE TestEncodeNixBase32/test_string_hash258=== RUN TestEncodeNixBase32/empty_input259=== PAUSE TestEncodeNixBase32/empty_input260=== PAUSE TestSetClientTLSErrors/missing_key_file261=== RUN TestSetClientTLSErrors/missing_ca_file262=== PAUSE TestSetClientTLSErrors/missing_ca_file263=== RUN TestSetClientTLSErrors/invalid_ca_file264=== PAUSE TestSetClientTLSErrors/invalid_ca_file265=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter266=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method267=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter268=== RUN TestParsePathInfoJSON/empty_input269=== PAUSE TestParsePathInfoJSON/empty_input270=== RUN TestParsePathInfoJSON/whitespace_only271=== PAUSE TestParsePathInfoJSON/whitespace_only272=== RUN TestParsePathInfoJSON/invalid_JSON273=== PAUSE TestParsePathInfoJSON/invalid_JSON274=== CONT TestRateLimiterFeedback/503_enables_limiter275=== CONT TestRateLimiterFeedback/429_enables_limiter276--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.09s)277--- PASS: TestRegisterUploadedObject_OutlivesPush (0.08s)278--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.08s)279--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)280--- PASS: TestScriptTokenEmptyToken (0.10s)281--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (0.12s)282=== RUN TestConvertHashToNix32/already_Nix32_format283=== PAUSE TestConvertHashToNix32/already_Nix32_format284=== RUN TestConvertHashToNix32/invalid_format285=== PAUSE TestConvertHashToNix32/invalid_format286=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon287=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon288=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI289=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI290=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512291=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512292=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths2932026/11/06 08:18:22 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:572262942026/11/06 08:18:22 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:57226295=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths296=== RUN TestGetStorePathHash/basename_without_hyphen_should_error2972026/11/06 08:18:22 WARN Rate limiter enabled after throttle name=server-test rate=52982026/11/06 08:18:22 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:57274299=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error3002026/11/06 08:18:22 INFO Garbage collection started3012026/11/06 08:18:22 WARN Rate limiter enabled after throttle name=server-test rate=5302=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything303=== RUN TestPartSizeForNAR/small_stays_at_minimum304=== CONT TestDumpPathSingleFile305=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false306=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true307=== CONT TestSetClientTLS/rejects_connection_without_client_cert308--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)309 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)310 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.01s)311=== CONT TestSetClientTLS/preserves_debug_logging_transport312=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error3132026/11/06 08:18:22 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:572783142026/11/06 08:18:22 WARN Rate limiter backed off name=server-test rate=53152026/11/06 08:18:22 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:57226316=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error317=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA3182026/11/06 08:18:22 WARN Rate limiter backed off name=server-test rate=5319--- PASS: TestRateLimiterFeedback (0.01s)320 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.03s)321 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.03s)322 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.05s)323 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.04s)324=== CONT TestEncodeNixBase32/test_string_hash325=== CONT TestPathInfoCACompatibility/null_ca_field326=== CONT TestParsePathInfoJSON/Nix_format327=== CONT TestSetClientTLSErrors/missing_cert_file328=== CONT TestSetClientTLSErrors/invalid_ca_file329=== CONT TestSetClientTLSErrors/missing_ca_file330=== CONT TestSetClientTLSErrors/missing_key_file331=== CONT TestEncodeNixBase32/empty_input332--- PASS: TestEncodeNixBase32 (0.00s)333 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)334 --- PASS: TestEncodeNixBase32/empty_input (0.00s)335=== CONT TestParsePathInfoJSON/whitespace_only336=== CONT TestParsePathInfoJSON/invalid_JSON337=== CONT TestConvertHashToNix32/SRI_format_to_Nix32338=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)339=== CONT TestParsePathInfoJSON/empty_input340=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method3412026/11/06 08:18:22 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=03422026/11/06 08:18:22 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:572263432026/11/06 08:18:22 WARN Garbage collection finished on another replica. Its statistics are not available here344--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.06s)345=== CONT TestPathInfoCACompatibility/new_structured_format_-_text3462026/11/06 08:18:22 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:57226347=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive348=== CONT TestPathInfoCACompatibility/old_string_format_-_text349=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped350=== PAUSE TestPartSizeForNAR/small_stays_at_minimum351=== CONT TestConvertHashToNix32/already_Nix32_format352=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum353=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum354--- PASS: TestStreamPushBatchesUnderLoad (0.09s)355 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.05s)356 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.05s)357=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped358=== RUN TestFilterOversizedClosures/all_closures_skipped359=== PAUSE TestFilterOversizedClosures/all_closures_skipped360=== CONT TestConvertHashToNix32/invalid_format361--- PASS: TestConvertHashToNix32 (0.14s)362 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)363 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)364 --- PASS: TestConvertHashToNix32/invalid_format (0.01s)365=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI366=== CONT TestFilterOversizedClosures/no_limit_keeps_everything367=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512368=== CONT TestFilterOversizedClosures/all_closures_skipped3692026/11/06 08:18:22 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-small nar_size=1000 max_nar_size=50370=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3712026/11/06 08:18:22 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=2000372--- PASS: TestFilterOversizedClosures (0.14s)373 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)374 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)375 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)376=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon377--- PASS: TestPathInfoHashCompatibility (0.14s)378 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)379 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)380 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)381 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)382=== CONT TestParsePathInfoJSON/Lix_format3832026/11/06 08:18:22 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:57226384--- PASS: TestSetClientTLSErrors (0.19s)385 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)386 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)387 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)388 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)389=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error390--- PASS: TestParsePathInfoJSON (0.12s)391 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)392 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)393 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)394 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)395 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)396=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error397=== CONT TestGetStorePathHash/valid_store_path398=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts399=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts400=== RUN TestPartSizeForNAR/1_TiB401=== PAUSE TestPartSizeForNAR/1_TiB402=== RUN TestPartSizeForNAR/5_TiB_S3_max_object403=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object404=== RUN TestPartSizeForNAR/capped_at_5_GiB405=== PAUSE TestPartSizeForNAR/capped_at_5_GiB406=== CONT TestPartSizeForNAR/zero_stays_at_minimum407=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error408=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error409=== CONT TestGetStorePathHash/basename_without_hyphen_should_error410--- PASS: TestGetStorePathHash (0.24s)411 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)412 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)413 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)414 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)415=== CONT TestPartSizeForNAR/capped_at_5_GiB416=== CONT TestPartSizeForNAR/5_TiB_S3_max_object417=== CONT TestPartSizeForNAR/1_TiB418=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts419=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum420=== CONT TestPartSizeForNAR/small_stays_at_minimum421--- PASS: TestPartSizeForNAR (0.24s)422 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)423 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)424 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)425 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)426 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)427 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)428 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)429--- PASS: TestScriptTokenBadJSON (0.26s)4302026/11/06 08:18:22 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:57226431--- PASS: TestPathInfoCACompatibility (0.19s)432 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)433 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.05s)434 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)435 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)436 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.10s)4372026/11/06 08:18:22 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:57226438--- PASS: TestUploadMultipart_ReturnsAfterDroppedBody (0.28s)439--- PASS: TestStreamPushRequestLine (0.38s)440--- PASS: TestScriptTokenCachesUntilRefresh (0.38s)4412026/11/06 08:18:22 WARN Rate limiter enabled after throttle name=s3-test rate=54422026/11/06 08:18:22 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:573264432026/11/06 08:18:22 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:57226444--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.27s)4452026/11/06 08:18:22 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:572264462026/11/06 08:18:22 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:572264472026/11/06 08:18:22 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:572264482026/11/06 08:18:22 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:572264492026/11/06 08:18:22 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:57226450--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.41s)4512026/11/06 08:18:22 http: TLS handshake error from 127.0.0.1:57322: read tcp 127.0.0.1:57232->127.0.0.1:57322: use of closed network connection452--- PASS: TestSetClientTLS (0.09s)453 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.21s)454 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.21s)455 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.32s)456--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.56s)457--- PASS: TestRegisterUploadedObjectReusesConnections (0.45s)458--- PASS: TestDumpPathWriterError (0.47s)459--- PASS: TestCaseHackSuffix (0.49s)460--- PASS: TestDumpPathSingleFile (0.42s)461--- PASS: TestDumpPathMatchesNix (0.65s)462--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.01s)463--- PASS: TestUploadMultipart_PartsInParallel (1.05s)464PASS465Running server tests...466The files belonging to this database system will be owned by user "_tribuchetbld3".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 /private/var/tb/3/scratch/8e9e0b393d193e6f/build/postgres1332618292/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 /private/var/tb/3/scratch/8e9e0b393d193e6f/build/postgres1332618292/data -l logfile start492493/private/var/tb/3/scratch/8e9e0b393d193e6f/build/postgres1332618292:5432 - no response4942026-11-06 08:18:24.538 UTC [1104] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4952026-11-06 08:18:24.538 UTC [1104] LOG: listening on Unix socket "/private/var/tb/3/scratch/8e9e0b393d193e6f/build/postgres1332618292/.s.PGSQL.5432"4962026-11-06 08:18:24.541 UTC [1111] LOG: database system was shut down at 2026-11-06 08:18:24 UTC4972026-11-06 08:18:24.546 UTC [1104] LOG: database system is ready to accept connections498/private/var/tb/3/scratch/8e9e0b393d193e6f/build/postgres1332618292:5432 - accepting connections499{"timestamp":"2026-11-06T08:18:24.77129Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"73350cc2-2874-4ec7-b77e-e5db3c1e6924","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":6,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(10)"}500{"timestamp":"2026-11-06T08:18:24.87877Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"347665c1-47fe-401b-9edc-6abc826a91a5","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(3)"}501=== RUN TestAbortSucceeded502=== PAUSE TestAbortSucceeded503=== RUN TestService_AuthMiddleware504=== PAUSE TestService_AuthMiddleware505=== RUN TestService_AuthMiddleware_MTLSProxyHeader506=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader507=== RUN TestService_AuthMiddleware_MTLSBoundSubjects508=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects509=== RUN TestService_ReadAuthMiddleware510=== PAUSE TestService_ReadAuthMiddleware511=== RUN TestService_AuthMiddleware_OIDC512=== PAUSE TestService_AuthMiddleware_OIDC513=== RUN TestService_RequireScope_OIDC514=== PAUSE TestService_RequireScope_OIDC515=== RUN TestService_ReadScope_PublicByDefault516=== PAUSE TestService_ReadScope_PublicByDefault517=== RUN TestCacheConfigHandler518=== PAUSE TestCacheConfigHandler519=== RUN TestCacheStatsHandler520=== PAUSE TestCacheStatsHandler521=== RUN TestClientCADerivations522=== PAUSE TestClientCADerivations523=== RUN TestClientErrorHandling524=== PAUSE TestClientErrorHandling525=== RUN TestClientIntegration526=== PAUSE TestClientIntegration527=== RUN TestClientMultipleUploads528=== PAUSE TestClientMultipleUploads529=== RUN TestClientWithDependencies530=== PAUSE TestClientWithDependencies531=== RUN TestClientSharedPathCommittedMidPush532=== PAUSE TestClientSharedPathCommittedMidPush533=== RUN TestPinProtectsFromGC534=== PAUSE TestPinProtectsFromGC535=== RUN TestClientPushesUseOnePush536=== PAUSE TestClientPushesUseOnePush537=== RUN TestClientFallsBackToClosures538=== PAUSE TestClientFallsBackToClosures539=== RUN TestDeleteClosuresRacingPins540=== PAUSE TestDeleteClosuresRacingPins541=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock542=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock543=== RUN TestResolveDBConnectionString544=== PAUSE TestResolveDBConnectionString545=== RUN TestConnectWaitsForAPeerMigration546=== PAUSE TestConnectWaitsForAPeerMigration547=== RUN TestLeadElectsOneAndHandsOver548=== PAUSE TestLeadElectsOneAndHandsOver549=== RUN TestLeadIncumbentWinsAfterRestart5502026/11/06 08:18:25 INFO lead: acquired remote=192.0.2.1:12345512026/11/06 08:18:25 INFO lead: released remote=192.0.2.1:12345522026/11/06 08:18:25 INFO lead: acquired remote=192.0.2.1:12345532026/11/06 08:18:26 INFO lead: released remote=192.0.2.1:1234554--- PASS: TestLeadIncumbentWinsAfterRestart (1.94s)555=== RUN TestLeadIncumbentAnnouncesAtOnce556=== PAUSE TestLeadIncumbentAnnouncesAtOnce557=== RUN TestLeadEndsOnShutdown558=== PAUSE TestLeadEndsOnShutdown559=== RUN TestLeadEndsWhenItsConnectionHangs5602026/11/06 08:18:27 INFO lead: acquired remote=192.0.2.1:12345612026-11-06 08:18:28.484 UTC [1153] FATAL: terminating connection due to administrator command5622026/11/06 08:18:28 INFO lead: acquired remote=192.0.2.1:12345632026/11/06 08:18:29 WARN lead: lock connection lost error="timeout: context deadline exceeded"5642026/11/06 08:18:29 INFO lead: released remote=192.0.2.1:12345652026/11/06 08:18:29 INFO lead: released remote=192.0.2.1:1234566--- PASS: TestLeadEndsWhenItsConnectionHangs (2.96s)567=== RUN TestGCAdvisoryLockBlocksConcurrentRun568=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun569=== RUN TestGCBugBareHashReferences570=== PAUSE TestGCBugBareHashReferences571=== RUN TestGCMetrics572=== PAUSE TestGCMetrics573=== RUN TestPushDedupSurvivesConcurrentGC574=== PAUSE TestPushDedupSurvivesConcurrentGC575=== RUN TestDeduplicatedObjectsRecordedAsPending576=== PAUSE TestDeduplicatedObjectsRecordedAsPending577=== RUN TestGCSweepSkipsPendingObjects578=== PAUSE TestGCSweepSkipsPendingObjects579=== RUN TestTombstonedObjectOfferedWithoutWaiting580=== PAUSE TestTombstonedObjectOfferedWithoutWaiting581=== RUN TestGCSweepDeliversEachKeyOnce582=== PAUSE TestGCSweepDeliversEachKeyOnce583=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection584=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection585=== RUN TestForceGCDuringPushOffersSweptObject586=== PAUSE TestForceGCDuringPushOffersSweptObject587=== RUN TestFailedS3DeleteKeepsTombstone588=== PAUSE TestFailedS3DeleteKeepsTombstone589=== RUN TestSweepSkipsRowsLockedByPush590=== PAUSE TestSweepSkipsRowsLockedByPush591=== RUN TestRegisterCompletedObjectNeedsPendingRow592=== PAUSE TestRegisterCompletedObjectNeedsPendingRow593=== RUN TestGetExistingObjectsLocksRows594=== PAUSE TestGetExistingObjectsLocksRows595=== RUN TestSweepRechecksPendingAfterLocking596=== PAUSE TestSweepRechecksPendingAfterLocking597=== RUN TestPushWaitsForSweepHoldingRow598=== PAUSE TestPushWaitsForSweepHoldingRow599=== RUN TestCommitRacingPendingCleanupKeepsObjects600=== PAUSE TestCommitRacingPendingCleanupKeepsObjects601=== RUN TestGCEndsOnShutdown602=== PAUSE TestGCEndsOnShutdown603=== RUN TestGCTaskStore_StartNew604=== PAUSE TestGCTaskStore_StartNew605=== RUN TestGCTaskStore_DeduplicateSameParams606=== PAUSE TestGCTaskStore_DeduplicateSameParams607=== RUN TestGCTaskStore_ConflictDifferentParams608=== PAUSE TestGCTaskStore_ConflictDifferentParams609=== RUN TestGCTaskStore_GetEmpty610=== PAUSE TestGCTaskStore_GetEmpty611=== RUN TestGCTaskStore_GetReturnsLatest612=== PAUSE TestGCTaskStore_GetReturnsLatest613=== RUN TestGCTaskStore_CompletedAllowsNewTask614=== PAUSE TestGCTaskStore_CompletedAllowsNewTask615=== RUN TestGCTaskStore_PhaseUpdates616=== PAUSE TestGCTaskStore_PhaseUpdates617=== RUN TestGCTaskStore_Fail618=== PAUSE TestGCTaskStore_Fail619=== RUN TestGracefulShutdownDrainsInflight620=== PAUSE TestGracefulShutdownDrainsInflight621=== RUN TestService_healthCheckHandler622=== PAUSE TestService_healthCheckHandler623=== RUN TestService_readinessHandler624=== PAUSE TestService_readinessHandler625=== RUN TestGenerateLandingPage626=== PAUSE TestGenerateLandingPage627=== RUN TestEnsureAbortUploadsRule628=== PAUSE TestEnsureAbortUploadsRule629=== RUN TestCacheConfigHandlerMaxNarSize630=== PAUSE TestCacheConfigHandlerMaxNarSize631=== RUN TestCreatePendingClosureRejectsOversizedNAR632=== PAUSE TestCreatePendingClosureRejectsOversizedNAR633=== RUN TestNARDeduplicationMetadataUploadBug634=== PAUSE TestNARDeduplicationMetadataUploadBug635=== RUN TestMetricsInventory636=== PAUSE TestMetricsInventory637=== RUN TestMetricsCommit638=== PAUSE TestMetricsCommit639=== RUN TestService_NativeMTLS640=== PAUSE TestService_NativeMTLS641=== RUN TestServerTLSConfig642=== PAUSE TestServerTLSConfig643=== RUN TestMultipartCleanup644=== PAUSE TestMultipartCleanup645=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded646=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded647=== RUN TestPendingCleanupUsesOneCutoff648=== PAUSE TestPendingCleanupUsesOneCutoff649=== RUN TestObjectStatsTrigger650=== PAUSE TestObjectStatsTrigger651=== RUN TestObjectStatsUpdatedOncePerCommit652=== PAUSE TestObjectStatsUpdatedOncePerCommit653=== RUN TestOrphanedObjectsGC654=== PAUSE TestOrphanedObjectsGC655=== RUN TestOrphanedObjectsGCStressTest656=== PAUSE TestOrphanedObjectsGCStressTest657=== RUN TestCreatePin_ReservedPins658=== PAUSE TestCreatePin_ReservedPins659=== RUN TestPresentReportsOnlyClosureRoots660=== PAUSE TestPresentReportsOnlyClosureRoots661=== RUN TestPresentRefreshesOnlyStaleClosures662=== PAUSE TestPresentRefreshesOnlyStaleClosures663=== RUN TestPresentNotReportedWhileGCDeletesClosure664=== PAUSE TestPresentNotReportedWhileGCDeletesClosure665=== RUN TestParseSingleRange666=== PAUSE TestParseSingleRange667=== RUN TestProxyHeadersOnlyTrustedOnSocket6682026/11/06 08:18:30 INFO Starting HTTP server address=127.0.0.1:573556692026/11/06 08:18:30 INFO Starting HTTP server address=proxy.sock6702026/11/06 08:18:30 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6712026/11/06 08:18:30 INFO Shutdown signal received, draining in-flight requests timeout=10s672--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.16s)673=== RUN TestIsValidCachePath674=== PAUSE TestIsValidCachePath675=== RUN TestReadProxyNarinfo676=== PAUSE TestReadProxyNarinfo677=== RUN TestReadProxyNarinfoAlreadyDecompressed678=== PAUSE TestReadProxyNarinfoAlreadyDecompressed679=== RUN TestReadProxyContentNegotiation680=== PAUSE TestReadProxyContentNegotiation681=== RUN TestReadProxyNarStreaming682=== PAUSE TestReadProxyNarStreaming683=== RUN TestReadProxy404684=== PAUSE TestReadProxy404685=== RUN TestReadProxyInvalidPath686=== PAUSE TestReadProxyInvalidPath687=== RUN TestReadProxyHead688=== PAUSE TestReadProxyHead689=== RUN TestReadProxyOutlastsServerWriteTimeout690=== PAUSE TestReadProxyOutlastsServerWriteTimeout691=== RUN TestReadProxyConditionalGet692=== PAUSE TestReadProxyConditionalGet693=== RUN TestReadProxyRootRedirectsToIndexHTML694=== PAUSE TestReadProxyRootRedirectsToIndexHTML695=== RUN TestReadProxyDisabled696=== PAUSE TestReadProxyDisabled697=== RUN TestReadRedirectNar698=== PAUSE TestReadRedirectNar699=== RUN TestReadRedirectKeepsNarinfoProxied700=== PAUSE TestReadRedirectKeepsNarinfoProxied701=== RUN TestReadProxyRangeRequest702=== PAUSE TestReadProxyRangeRequest703=== RUN TestReadRedirectUsesPublicS3URL704=== PAUSE TestReadRedirectUsesPublicS3URL705=== RUN TestPush_OverlappingRootsStoreOneRowPerKey706=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey707=== RUN TestPush_CompleteCommitsEveryRoot708=== PAUSE TestPush_CompleteCommitsEveryRoot709=== RUN TestPush_RepeatedRootCommitsOnce710=== PAUSE TestPush_RepeatedRootCommitsOnce711=== RUN TestPush_CompleteWaitsForCleanupOfThePush712=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush713=== RUN TestPush_RootsAreLockedInByteOrder714=== PAUSE TestPush_RootsAreLockedInByteOrder715=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit716=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit717=== RUN TestPush_RejectsBadRequests718=== PAUSE TestPush_RejectsBadRequests719=== RUN TestPush_SignsNarinfosOfItsPendingObjects720=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects721=== RUN TestSharedNarBothUploadsComplete722=== PAUSE TestSharedNarBothUploadsComplete723=== RUN TestCompleteMultipartUpload_ErrorButObjectExists724=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists725=== RUN TestCompletedNarNotReofferedAcrossClosures726=== PAUSE TestCompletedNarNotReofferedAcrossClosures727=== RUN TestPresignedUploadRegisteredBeforeCommit728=== PAUSE TestPresignedUploadRegisteredBeforeCommit729=== RUN TestService_Rustfstest730=== PAUSE TestService_Rustfstest731=== RUN TestParseSize732=== PAUSE TestParseSize733=== RUN TestSkippedUploadsHandler734=== PAUSE TestSkippedUploadsHandler735=== RUN TestSystemdListenerNotActivated736--- PASS: TestSystemdListenerNotActivated (0.00s)737=== RUN TestWatchdogBeatsWhenHealthy738--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)739=== RUN TestWatchdogSkipsWhenUnhealthy7402026/11/06 08:18:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7412026/11/06 08:18:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7422026/11/06 08:18:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7432026/11/06 08:18:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7442026/11/06 08:18:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7452026/11/06 08:18:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7462026/11/06 08:18:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7472026/11/06 08:18:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7482026/11/06 08:18:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7492026/11/06 08:18:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"750--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)751=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle752=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle753=== RUN TestProxyWriteTimeout754=== PAUSE TestProxyWriteTimeout755=== RUN TestPendingClosureWriteTimeout756=== PAUSE TestPendingClosureWriteTimeout757=== RUN TestIsValidUploadKey758=== PAUSE TestIsValidUploadKey759=== RUN TestUploadHandlersRejectInvalidKeys760=== PAUSE TestUploadHandlersRejectInvalidKeys761=== RUN TestUploadHandlersRejectOversizedBody762=== PAUSE TestUploadHandlersRejectOversizedBody763=== RUN TestService_cleanupPendingClosuresHandler764=== PAUSE TestService_cleanupPendingClosuresHandler765=== RUN TestService_createPendingClosureHandler766=== PAUSE TestService_createPendingClosureHandler767=== RUN TestService_verifyS3Integrity768=== PAUSE TestService_verifyS3Integrity769=== RUN TestService_verifyS3ReuploadsStaleNarinfo770=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo771=== RUN TestCompleteMultipartUnregistered772=== PAUSE TestCompleteMultipartUnregistered773=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT774=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT775=== CONT TestPush_RootsAreLockedInByteOrder776=== CONT TestAbortSucceeded777=== CONT TestGCTaskStore_GetReturnsLatest778=== CONT TestGCEndsOnShutdown779=== CONT TestCompleteMultipartUnregistered780=== CONT TestReadProxyRangeRequest781=== CONT TestConnectWaitsForAPeerMigration782=== CONT TestClientFallsBackToClosures783=== CONT TestProxyWriteTimeout784=== RUN TestProxyWriteTimeout/narinfo785=== PAUSE TestProxyWriteTimeout/narinfo786=== CONT TestResolveDBConnectionString787--- PASS: TestAbortSucceeded (0.00s)788=== CONT TestGCTaskStore_GetEmpty789--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)790--- PASS: TestGCTaskStore_GetEmpty (0.00s)791=== CONT TestClientMultipleUploads792=== CONT TestGCTaskStore_ConflictDifferentParams793--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)794=== CONT TestClientIntegration795=== CONT TestGCTaskStore_DeduplicateSameParams796--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)797=== CONT TestGCTaskStore_StartNew798--- PASS: TestGCTaskStore_StartNew (0.00s)799=== CONT TestClientCADerivations800=== CONT TestClientErrorHandling801=== RUN TestClientErrorHandling/InvalidStorePath802=== PAUSE TestClientErrorHandling/InvalidStorePath803=== RUN TestClientErrorHandling/InvalidAuthToken804=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT805=== PAUSE TestClientErrorHandling/InvalidAuthToken806=== RUN TestClientErrorHandling/ServerNotAvailable807=== PAUSE TestClientErrorHandling/ServerNotAvailable808=== CONT TestCacheStatsHandler809=== CONT TestPush_CompleteWaitsForCleanupOfThePush810=== CONT TestPush_CompleteCommitsEveryRoot811=== RUN TestGCEndsOnShutdown/before_the_run812=== RUN TestResolveDBConnectionString/flag_wins813=== CONT TestPush_OverlappingRootsStoreOneRowPerKey814=== PAUSE TestGCEndsOnShutdown/before_the_run815=== PAUSE TestResolveDBConnectionString/flag_wins816=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete817=== RUN TestResolveDBConnectionString/file_when_flag_empty818=== PAUSE TestResolveDBConnectionString/file_when_flag_empty819=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete820=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark821=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark822=== CONT TestReadRedirectUsesPublicS3URL823=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock824=== CONT TestDeleteClosuresRacingPins825=== CONT TestClientPushesUseOnePush826=== CONT TestPinProtectsFromGC827=== CONT TestClientSharedPathCommittedMidPush828=== CONT TestCacheConfigHandler829=== RUN TestCacheConfigHandler/full_config,_no_issuer830=== PAUSE TestCacheConfigHandler/full_config,_no_issuer831=== RUN TestCacheConfigHandler/no_cache_url_configured832=== PAUSE TestCacheConfigHandler/no_cache_url_configured833=== RUN TestCacheConfigHandler/no_signing_keys834=== PAUSE TestCacheConfigHandler/no_signing_keys835=== CONT TestClientWithDependencies836=== RUN TestProxyWriteTimeout/1_GiB_nar837=== PAUSE TestProxyWriteTimeout/1_GiB_nar838=== RUN TestProxyWriteTimeout/10_GiB_nar839=== PAUSE TestProxyWriteTimeout/10_GiB_nar840=== RUN TestProxyWriteTimeout/unknown_size841=== CONT TestPush_RepeatedRootCommitsOnce842=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator843=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator844=== PAUSE TestProxyWriteTimeout/unknown_size845=== RUN TestResolveDBConnectionString/missing_file_is_an_error846=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error847=== RUN TestResolveDBConnectionString/PGHOST_allows_empty848=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty849=== RUN TestResolveDBConnectionString/nothing_configured850=== CONT TestService_RequireScope_OIDC851=== CONT TestService_ReadScope_PublicByDefault852=== PAUSE TestResolveDBConnectionString/nothing_configured853=== CONT TestService_AuthMiddleware_OIDC8542026/11/06 08:18:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57357/oidc8552026/11/06 08:18:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57359/oidc8562026/11/06 08:18:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8572026/11/06 08:18:31 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst858--- PASS: TestCompleteMultipartUnregistered (0.93s)859=== CONT TestService_ReadAuthMiddleware8602026/11/06 08:18:31 INFO Received push request method=POST path=/api/pushes8612026/11/06 08:18:31 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)8622026/11/06 08:18:31 INFO Uploading 195hn1llc2y41lrd482g3q2k47vvg2d7-shared-dep (136B)8632026/11/06 08:18:31 INFO Uploading fccx2qw2ll47mg773dc9pr1bdwp074vc-top (264B)8642026/11/06 08:18:31 WARN Failed to register uploaded object key=fccx2qw2ll47mg773dc9pr1bdwp074vc.ls error="server returned 404: 404 page not found\n"8652026/11/06 08:18:31 WARN Failed to register uploaded object key=195hn1llc2y41lrd482g3q2k47vvg2d7.ls error="server returned 404: 404 page not found\n"8662026/11/06 08:18:31 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"8672026/11/06 08:18:31 WARN Failed to register uploaded object key=nar/1il4g56vfxm3950077425i7rcldwiwdc58vrhpiaw5ijdf207hly.nar.zst error="server returned 404: 404 page not found\n"8682026/11/06 08:18:31 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8692026/11/06 08:18:31 INFO Signed narinfos id=1 count=28702026/11/06 08:18:31 INFO Uploading 2 narinfos8712026/11/06 08:18:31 WARN Failed to register uploaded object key=195hn1llc2y41lrd482g3q2k47vvg2d7.narinfo error="server returned 404: 404 page not found\n"8722026/11/06 08:18:31 INFO Received complete push request method=POST path=/api/pushes/1/complete8732026/11/06 08:18:31 WARN Failed to register uploaded object key=fccx2qw2ll47mg773dc9pr1bdwp074vc.narinfo error="server returned 404: 404 page not found\n"8742026/11/06 08:18:31 INFO Completed push id=1 objects=6 duration=30.232292ms8752026/11/06 08:18:31 INFO Upload complete. (358ms)876=== NAME TestClientSharedPathCommittedMidPush877 client_integration_test.go:727: Retrieved narinfo from S3:878 StorePath: /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestClientSharedPathCommittedMidPush941774441/001/store/195hn1llc2y41lrd482g3q2k47vvg2d7-shared-dep879 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst880 Compression: zstd881 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82882 NarSize: 136883 References: 884 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n885--- PASS: TestReadProxyRangeRequest (1.49s)886=== CONT TestService_AuthMiddleware_MTLSBoundSubjects887=== NAME TestClientSharedPathCommittedMidPush888 client_integration_test.go:727: Retrieved narinfo from S3:889 StorePath: /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestClientSharedPathCommittedMidPush941774441/001/store/fccx2qw2ll47mg773dc9pr1bdwp074vc-top890 URL: nar/1il4g56vfxm3950077425i7rcldwiwdc58vrhpiaw5ijdf207hly.nar.zst891 Compression: zstd892 NarHash: sha256:1il4g56vfxm3950077425i7rcldwiwdc58vrhpiaw5ijdf207hly893 NarSize: 264894 References: /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestClientSharedPathCommittedMidPush941774441/001/store/195hn1llc2y41lrd482g3q2k47vvg2d7-shared-dep895 CA: text:sha256:0y08ssnlspkkrz04lwsshaafq1blxrrpq621g8zaacjrc941k96y896--- PASS: TestClientSharedPathCommittedMidPush (1.52s)897=== CONT TestService_AuthMiddleware_MTLSProxyHeader8982026/11/06 08:18:32 INFO Received push request method=POST path=/api/pushes8992026-11-06 08:18:32.236 UTC [1250] ERROR: could not obtain lock on row in relation "closures"9002026-11-06 08:18:32.236 UTC [1250] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9012026-11-06 08:18:32.249 UTC [1250] ERROR: could not obtain lock on row in relation "closures"9022026-11-06 08:18:32.249 UTC [1250] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9032026-11-06 08:18:32.255 UTC [1250] ERROR: could not obtain lock on row in relation "closures"9042026-11-06 08:18:32.255 UTC [1250] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9052026-11-06 08:18:32.257 UTC [1250] ERROR: could not obtain lock on row in relation "closures"9062026-11-06 08:18:32.257 UTC [1250] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9072026-11-06 08:18:32.265 UTC [1250] ERROR: could not obtain lock on row in relation "closures"9082026-11-06 08:18:32.265 UTC [1250] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT909--- PASS: TestPush_RootsAreLockedInByteOrder (1.99s)910=== CONT TestService_AuthMiddleware911--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (2.65s)912=== CONT TestGCSweepDeliversEachKeyOnce9132026/11/06 08:18:32 INFO Received uploads request method=POST path=/api/pending_closures9142026/11/06 08:18:32 INFO Received uploads request method=POST path=/api/pending_closures9152026/11/06 08:18:32 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)9162026/11/06 08:18:32 INFO Uploading zas6cdyy5jqxfz74r85bkl7rz2aa8kjl-a (256B)9172026/11/06 08:18:32 INFO Uploading kwnllzq87by7a53nn7k2j3ig82lb6mb6-shared-dep (136B)9182026/11/06 08:18:32 WARN Failed to register uploaded object key=7p1f25myi9fsmpc05m2h7skpmy0pab2c.ls error="server returned 404: 404 page not found\n"9192026/11/06 08:18:32 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"9202026/11/06 08:18:32 WARN Failed to register uploaded object key=nar/19sgw6dzvqsf9fjyzxbixdfzydccgk8xwv50qsyvg1nvmkp006g4.nar.zst error="server returned 404: 404 page not found\n"9212026/11/06 08:18:32 WARN Failed to register uploaded object key=kwnllzq87by7a53nn7k2j3ig82lb6mb6.ls error="server returned 404: 404 page not found\n"9222026/11/06 08:18:33 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign9232026/11/06 08:18:33 WARN Failed to register uploaded object key=zas6cdyy5jqxfz74r85bkl7rz2aa8kjl.ls error="server returned 404: 404 page not found\n"9242026/11/06 08:18:33 INFO Signed narinfos id=2 count=29252026/11/06 08:18:33 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9262026/11/06 08:18:33 INFO Signed narinfos id=1 count=29272026/11/06 08:18:33 INFO Uploading 4 narinfos9282026/11/06 08:18:33 WARN Failed to register uploaded object key=7p1f25myi9fsmpc05m2h7skpmy0pab2c.narinfo error="server returned 404: 404 page not found\n"9292026/11/06 08:18:33 WARN Failed to register uploaded object key=kwnllzq87by7a53nn7k2j3ig82lb6mb6.narinfo error="server returned 404: 404 page not found\n"9302026/11/06 08:18:33 WARN Failed to register uploaded object key=zas6cdyy5jqxfz74r85bkl7rz2aa8kjl.narinfo error="server returned 404: 404 page not found\n"9312026/11/06 08:18:33 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9322026/11/06 08:18:33 WARN Failed to register uploaded object key=kwnllzq87by7a53nn7k2j3ig82lb6mb6.narinfo error="server returned 404: 404 page not found\n"933=== NAME TestClientMultipleUploads934 client_integration_test.go:405: Created store path 0: /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestClientMultipleUploads3168628296/001/store/667bq4rq08ngb71clx7ji2hz6934334v-test-file-0.txt9352026/11/06 08:18:33 INFO Completed upload id=1 objects=6 duration=6.965417ms9362026/11/06 08:18:33 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete937=== NAME TestClientCADerivations938 client_ca_test.go:136: Built CA derivation: /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestClientCADerivations2500412731/001/store/ir5axxssa54d808a5ljb44rhvl71m0q5-ca-test9392026/11/06 08:18:33 INFO Completed upload id=2 objects=6 duration=920.875µs9402026/11/06 08:18:33 INFO Upload complete. (252ms)941=== NAME TestClientFallsBackToClosures942 client_pushes_test.go:112: Retrieved narinfo from S3:943 StorePath: /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestClientFallsBackToClosures2611082406/001/store/kwnllzq87by7a53nn7k2j3ig82lb6mb6-shared-dep944 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst945 Compression: zstd946 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82947 NarSize: 136948 References: 949 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n950 client_pushes_test.go:112: Retrieved narinfo from S3:951 StorePath: /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestClientFallsBackToClosures2611082406/001/store/zas6cdyy5jqxfz74r85bkl7rz2aa8kjl-a952 URL: nar/19sgw6dzvqsf9fjyzxbixdfzydccgk8xwv50qsyvg1nvmkp006g4.nar.zst953 Compression: zstd954 NarHash: sha256:19sgw6dzvqsf9fjyzxbixdfzydccgk8xwv50qsyvg1nvmkp006g4955 NarSize: 256956 References: /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestClientFallsBackToClosures2611082406/001/store/kwnllzq87by7a53nn7k2j3ig82lb6mb6-shared-dep957 CA: text:sha256:1ggr2p92ivqirf1hlsc5h8wxc2hppk5dlq524yxzkrzbph1yyx2a958 client_pushes_test.go:112: Retrieved narinfo from S3:959 StorePath: /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestClientFallsBackToClosures2611082406/001/store/7p1f25myi9fsmpc05m2h7skpmy0pab2c-b960 URL: nar/19sgw6dzvqsf9fjyzxbixdfzydccgk8xwv50qsyvg1nvmkp006g4.nar.zst961 Compression: zstd962 NarHash: sha256:19sgw6dzvqsf9fjyzxbixdfzydccgk8xwv50qsyvg1nvmkp006g4963 NarSize: 256964 References: /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestClientFallsBackToClosures2611082406/001/store/kwnllzq87by7a53nn7k2j3ig82lb6mb6-shared-dep965 CA: text:sha256:1ggr2p92ivqirf1hlsc5h8wxc2hppk5dlq524yxzkrzbph1yyx2a966--- PASS: TestClientFallsBackToClosures (2.86s)967=== CONT TestCommitRacingPendingCleanupKeepsObjects968=== NAME TestClientCADerivations969 client_ca_test.go:139: Found 1 dependencies (including self)970=== NAME TestClientMultipleUploads971 client_integration_test.go:405: Created store path 1: /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestClientMultipleUploads3168628296/001/store/rn7sj9p1dn5s1ji2sbwls9bm2plwcm17-test-file-1.txt972 client_integration_test.go:405: Created store path 2: /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestClientMultipleUploads3168628296/001/store/mfzrs7n6hi6g00h11aax48h9ccq4zbk4-test-file-2.txt9732026/11/06 08:18:33 INFO Received push request method=POST path=/api/pushes9742026/11/06 08:18:33 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9752026/11/06 08:18:33 INFO Uploading ir5axxssa54d808a5ljb44rhvl71m0q5-ca-test (144B)9762026/11/06 08:18:33 INFO Received push request method=POST path=/api/pushes9772026/11/06 08:18:33 INFO Received uploads request method=POST path=/api/pending_closures9782026/11/06 08:18:33 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)9792026/11/06 08:18:33 INFO Uploading mfzrs7n6hi6g00h11aax48h9ccq4zbk4-test-file-2.txt (160B)9802026/11/06 08:18:33 INFO Uploading rn7sj9p1dn5s1ji2sbwls9bm2plwcm17-test-file-1.txt (160B)9812026/11/06 08:18:33 INFO Uploading 667bq4rq08ngb71clx7ji2hz6934334v-test-file-0.txt (160B)9822026/11/06 08:18:33 WARN Failed to register uploaded object key=ir5axxssa54d808a5ljb44rhvl71m0q5.ls error="server returned 404: 404 page not found\n"9832026/11/06 08:18:33 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"9842026/11/06 08:18:33 WARN Failed to register uploaded object key=log/gkbzvh319m8dd8add2hzjj3h1ya400rc-ca-test.drv error="server returned 404: 404 page not found\n"9852026/11/06 08:18:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9862026/11/06 08:18:33 INFO Signed narinfos id=1 count=19872026/11/06 08:18:33 INFO Uploading 1 narinfos988--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (3.08s)989=== CONT TestPushWaitsForSweepHoldingRow9902026/11/06 08:18:33 WARN Failed to register uploaded object key=mfzrs7n6hi6g00h11aax48h9ccq4zbk4.ls error="server returned 404: 404 page not found\n"9912026/11/06 08:18:33 WARN Failed to register uploaded object key=rn7sj9p1dn5s1ji2sbwls9bm2plwcm17.ls error="server returned 404: 404 page not found\n"9922026/11/06 08:18:33 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"9932026/11/06 08:18:33 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"9942026/11/06 08:18:33 WARN Failed to register uploaded object key=667bq4rq08ngb71clx7ji2hz6934334v.ls error="server returned 404: 404 page not found\n"9952026/11/06 08:18:33 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"9962026/11/06 08:18:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9972026/11/06 08:18:33 INFO Signed narinfos id=1 count=39982026/11/06 08:18:33 INFO Uploading 3 narinfos9992026/11/06 08:18:33 INFO Received complete push request method=POST path=/api/pushes/1/complete10002026/11/06 08:18:33 WARN Failed to register uploaded object key=ir5axxssa54d808a5ljb44rhvl71m0q5.narinfo error="server returned 404: 404 page not found\n"10012026/11/06 08:18:33 INFO Completed push id=1 objects=4 duration=12.412792ms10022026/11/06 08:18:33 INFO Upload complete. (236ms)1003=== NAME TestClientCADerivations1004 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestClientCADerivations2500412731/001/store/ir5axxssa54d808a5ljb44rhvl71m0q5-ca-test1005 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1006 Compression: zstd1007 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1008 NarSize: 1441009 References: 1010 Deriver: /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestClientCADerivations2500412731/001/store/gkbzvh319m8dd8add2hzjj3h1ya400rc-ca-test.drv1011 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1012 client_ca_test.go:185: Checking for realisation files in S3...10132026/11/06 08:18:33 WARN Failed to register uploaded object key=mfzrs7n6hi6g00h11aax48h9ccq4zbk4.narinfo error="server returned 404: 404 page not found\n"10142026/11/06 08:18:33 WARN Failed to register uploaded object key=667bq4rq08ngb71clx7ji2hz6934334v.narinfo error="server returned 404: 404 page not found\n"1015 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1016 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1017=== NAME TestClientWithDependencies1018 client_integration_test.go:660: Built derivation: /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestClientWithDependencies225794728/001/store/ncv43ifh8vlyiw81byip70cbxy0wcf30-test-script10192026/11/06 08:18:33 INFO Received complete push request method=POST path=/api/pushes/1/complete10202026/11/06 08:18:33 WARN Failed to register uploaded object key=rn7sj9p1dn5s1ji2sbwls9bm2plwcm17.narinfo error="server returned 404: 404 page not found\n"10212026/11/06 08:18:33 INFO Completed push id=1 objects=9 duration=27.723667ms10222026/11/06 08:18:33 INFO Upload complete. (237ms)1023=== NAME TestClientMultipleUploads1024 client_integration_test.go:416: Uploaded 3 paths in 271.825959ms1025=== NAME TestClientWithDependencies1026 client_integration_test.go:662: Found 1 dependencies (including self)1027--- PASS: TestClientMultipleUploads (3.24s)1028=== CONT TestSweepRechecksPendingAfterLocking1029=== NAME TestClientCADerivations1030 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket10?endpoint=http://localhost:57333®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestClientCADerivations2500412731/001/store'1031 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 110322026/11/06 08:18:33 INFO Received push request method=POST path=/api/pushes1033--- PASS: TestClientCADerivations (3.27s)1034=== CONT TestGetExistingObjectsLocksRows10352026/11/06 08:18:33 INFO Received push request method=POST path=/api/pushes10362026/11/06 08:18:33 INFO Received complete push request method=POST path=/api/pushes/1/complete10372026/11/06 08:18:33 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10382026/11/06 08:18:33 INFO Uploading ncv43ifh8vlyiw81byip70cbxy0wcf30-test-script (136B)10392026/11/06 08:18:33 INFO Completed push id=1 objects=6 duration=32.661542ms1040--- PASS: TestPush_CompleteCommitsEveryRoot (3.36s)1041=== CONT TestRegisterCompletedObjectNeedsPendingRow10422026/11/06 08:18:33 WARN Failed to register uploaded object key=ncv43ifh8vlyiw81byip70cbxy0wcf30.ls error="server returned 404: 404 page not found\n"10432026/11/06 08:18:33 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"10442026/11/06 08:18:33 WARN Failed to register uploaded object key=log/4xdxm1fygazy1qpkvdzjs3888hk7052l-test-script.drv error="server returned 404: 404 page not found\n"10452026/11/06 08:18:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10462026/11/06 08:18:33 INFO Signed narinfos id=1 count=110472026/11/06 08:18:33 INFO Uploading 1 narinfos10482026/11/06 08:18:33 INFO Received complete push request method=POST path=/api/pushes/1/complete10492026/11/06 08:18:33 WARN Failed to register uploaded object key=ncv43ifh8vlyiw81byip70cbxy0wcf30.narinfo error="server returned 404: 404 page not found\n"10502026/11/06 08:18:33 INFO Completed push id=1 objects=4 duration=19.275583ms10512026/11/06 08:18:33 INFO Upload complete. (196ms)1052=== NAME TestClientWithDependencies1053 client_integration_test.go:664: Skipping nix copy test - isolated store (/private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestClientWithDependencies225794728/001/store) requires matching store prefix10542026/11/06 08:18:33 INFO Received push request method=POST path=/api/pushes1055--- PASS: TestClientWithDependencies (3.49s)1056=== CONT TestSweepSkipsRowsLockedByPush10572026-11-06 08:18:34.123 UTC [1304] ERROR: Push does not exist: id=110582026-11-06 08:18:34.123 UTC [1304] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE10592026-11-06 08:18:34.123 UTC [1304] STATEMENT: SELECT commit_push($1)1060--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (3.84s)1061=== CONT TestFailedS3DeleteKeepsTombstone1062=== NAME TestClientIntegration1063 client_integration_test.go:291: Created store path: /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestClientIntegration988770214/002/store/q7gp77whdzxbdqahmmx84w8lsxqw13k3-test-file.txt10642026/11/06 08:18:34 INFO Received push request method=POST path=/api/pushes10652026/11/06 08:18:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10662026/11/06 08:18:34 INFO Uploading q7gp77whdzxbdqahmmx84w8lsxqw13k3-test-file.txt (152B)10672026/11/06 08:18:34 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"10682026/11/06 08:18:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10692026/11/06 08:18:34 INFO Signed narinfos id=1 count=110702026/11/06 08:18:34 WARN Failed to register uploaded object key=q7gp77whdzxbdqahmmx84w8lsxqw13k3.ls error="server returned 404: 404 page not found\n"10712026/11/06 08:18:34 INFO Uploading 1 narinfos10722026/11/06 08:18:34 INFO Received complete push request method=POST path=/api/pushes/1/complete10732026/11/06 08:18:34 WARN Failed to register uploaded object key=q7gp77whdzxbdqahmmx84w8lsxqw13k3.narinfo error="server returned 404: 404 page not found\n"1074=== NAME TestPinProtectsFromGC1075 client_integration_test.go:778: Pinned store path: /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestPinProtectsFromGC4099634213/001/store/47mfhijbvjz155hqfr1rx5x5lz329h8d-pinned-file.txt1076 client_integration_test.go:779: Unpinned store path: /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestPinProtectsFromGC4099634213/001/store/y8q9mia8b11wwd76din6p9vnv5b63vps-unpinned-file.txt10772026/11/06 08:18:34 INFO Completed push id=1 objects=3 duration=41.388625ms10782026/11/06 08:18:34 INFO Upload complete. (249ms)10792026/11/06 08:18:34 INFO Received push request method=POST path=/api/pushes10802026/11/06 08:18:34 INFO All 1 paths already cached1081=== NAME TestClientIntegration1082 client_integration_test.go:317: Retrieved narinfo from S3:1083 StorePath: /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestClientIntegration988770214/002/store/q7gp77whdzxbdqahmmx84w8lsxqw13k3-test-file.txt1084 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1085 Compression: zstd1086 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11087 NarSize: 1521088 References: 1089 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11090 client_integration_test.go:318: Retrieved .ls file from S3 (compressed size: 77 bytes)1091 client_integration_test.go:318: Decompressed .ls content (64 bytes):1092 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1093--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (4.38s)1094=== CONT TestForceGCDuringPushOffersSweptObject1095=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1096=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1097=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1098=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1099=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection11002026/11/06 08:18:34 INFO Received push request method=POST path=/api/pushes11012026/11/06 08:18:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11022026/11/06 08:18:34 INFO Uploading 47mfhijbvjz155hqfr1rx5x5lz329h8d-pinned-file.txt (128B)11032026/11/06 08:18:34 WARN Failed to register uploaded object key=47mfhijbvjz155hqfr1rx5x5lz329h8d.ls error="server returned 404: 404 page not found\n"11042026/11/06 08:18:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11052026/11/06 08:18:34 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"11062026/11/06 08:18:34 INFO Signed narinfos id=1 count=111072026/11/06 08:18:34 INFO Uploading 1 narinfos11082026/11/06 08:18:34 INFO Received complete push request method=POST path=/api/pushes/1/complete11092026/11/06 08:18:34 WARN Failed to register uploaded object key=47mfhijbvjz155hqfr1rx5x5lz329h8d.narinfo error="server returned 404: 404 page not found\n"11102026/11/06 08:18:34 INFO Completed push id=1 objects=3 duration=14.304542ms11112026/11/06 08:18:34 INFO Upload complete. (212ms)11122026/11/06 08:18:34 INFO Received push request method=POST path=/api/pushes11132026/11/06 08:18:34 INFO Received push request method=POST path=/api/pushes11142026/11/06 08:18:34 INFO Received complete push request method=POST path=/api/pushes/1/complete11152026/11/06 08:18:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11162026/11/06 08:18:34 INFO Uploading y8q9mia8b11wwd76din6p9vnv5b63vps-unpinned-file.txt (128B)11172026/11/06 08:18:34 INFO Completed push id=1 objects=4 duration=31.324875ms1118--- PASS: TestPush_RepeatedRootCommitsOnce (4.63s)1119=== CONT TestCompletedNarNotReofferedAcrossClosures11202026/11/06 08:18:34 WARN Failed to register uploaded object key=y8q9mia8b11wwd76din6p9vnv5b63vps.ls error="server returned 404: 404 page not found\n"11212026/11/06 08:18:34 INFO Received push request method=POST path=/api/pushes11222026/11/06 08:18:34 INFO Object in database but missing from S3 key=q7gp77whdzxbdqahmmx84w8lsxqw13k3.ls11232026/11/06 08:18:34 WARN Found objects in DB but missing from S3, will re-upload count=111242026/11/06 08:18:34 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11252026/11/06 08:18:34 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11262026/11/06 08:18:34 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"11272026/11/06 08:18:34 INFO Signed narinfos id=2 count=111282026/11/06 08:18:34 INFO Uploading 1 narinfos11292026/11/06 08:18:34 INFO Received complete push request method=POST path=/api/pushes/2/complete11302026/11/06 08:18:34 WARN Failed to register uploaded object key=q7gp77whdzxbdqahmmx84w8lsxqw13k3.ls error="server returned 404: 404 page not found\n"11312026/11/06 08:18:34 INFO Completed push id=2 objects=3 duration=641.625µs11322026/11/06 08:18:34 INFO Upload complete. (118ms)1133=== NAME TestClientIntegration1134 client_integration_test.go:335: Retrieved .ls file from S3 (compressed size: 62 bytes)1135 client_integration_test.go:335: Decompressed .ls content (49 bytes):1136 {"version":1,"root":{"type":"regular","size":39}}11372026/11/06 08:18:34 INFO Received complete push request method=POST path=/api/pushes/2/complete11382026/11/06 08:18:34 WARN Failed to register uploaded object key=y8q9mia8b11wwd76din6p9vnv5b63vps.narinfo error="server returned 404: 404 page not found\n"11392026/11/06 08:18:34 INFO Completed push id=2 objects=3 duration=688.958µs11402026/11/06 08:18:34 INFO Upload complete. (149ms)11412026/11/06 08:18:35 INFO Starting cleanup of old closures method=DELETE path=/api/closures11422026/11/06 08:18:35 INFO Garbage collection started11432026/11/06 08:18:35 INFO Aborted multipart uploads count=0 kept=011442026/11/06 08:18:35 WARN Force mode enabled - objects will be deleted immediately without grace period1145--- PASS: TestService_ReadScope_PublicByDefault (4.77s)1146=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle11472026/11/06 08:18:35 INFO Received push request method=POST path=/api/pushes11482026/11/06 08:18:35 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11492026/11/06 08:18:35 INFO Received complete push request method=POST path=/api/pushes/3/complete11502026/11/06 08:18:35 WARN Failed to register uploaded object key=q7gp77whdzxbdqahmmx84w8lsxqw13k3.ls error="server returned 404: 404 page not found\n"11512026/11/06 08:18:35 INFO Completed push id=3 objects=3 duration=42.796625ms11522026/11/06 08:18:35 INFO Upload complete. (192ms)1153=== NAME TestClientIntegration11542026/11/06 08:18:35 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=01155 client_integration_test.go:352: Retrieved .ls file from S3 (compressed size: 62 bytes)1156 client_integration_test.go:352: Decompressed .ls content (49 bytes):1157 {"version":1,"root":{"type":"regular","size":39}}1158 client_integration_test.go:363: Testing garbage collection...11592026/11/06 08:18:35 INFO Vacuumed table table=pending_closures11602026/11/06 08:18:35 INFO Vacuumed table table=pending_objects11612026/11/06 08:18:35 INFO Vacuumed table table=multipart_uploads11622026/11/06 08:18:35 INFO Vacuumed table table=closures11632026/11/06 08:18:35 INFO Vacuumed table table=objects11642026/11/06 08:18:35 INFO Starting cleanup of old closures method=DELETE path=/api/closures11652026/11/06 08:18:35 INFO Garbage collection started11662026/11/06 08:18:35 INFO Aborted multipart uploads count=0 kept=011672026/11/06 08:18:35 WARN Force mode enabled - objects will be deleted immediately without grace period1168--- PASS: TestCacheStatsHandler (5.38s)1169=== CONT TestSkippedUploadsHandler11702026/11/06 08:18:35 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001171--- PASS: TestSkippedUploadsHandler (0.01s)1172=== CONT TestParseSize1173--- PASS: TestParseSize (0.00s)1174=== CONT TestService_Rustfstest11752026/11/06 08:18:35 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=011762026/11/06 08:18:35 INFO Vacuumed table table=pending_closures11772026/11/06 08:18:35 INFO Vacuumed table table=pending_objects11782026/11/06 08:18:35 INFO Vacuumed table table=multipart_uploads11792026/11/06 08:18:35 INFO Vacuumed table table=closures11802026/11/06 08:18:35 INFO Vacuumed table table=objects1181=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1182=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1183=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1184=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1185=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1186=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1187=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1188=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1189=== CONT TestPresignedUploadRegisteredBeforeCommit11902026/11/06 08:18:35 INFO Received push request method=POST path=/api/pushes11912026/11/06 08:18:35 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11922026/11/06 08:18:35 INFO Uploading cp6y9acs936rncsaxjpi7wgl66rpycxf-shared-dep (136B)11932026/11/06 08:18:35 INFO Uploading dnwx5djqr0fl5hk20zqw6dc7lx97yy6q-b (256B)11942026/11/06 08:18:35 WARN Failed to register uploaded object key=nar/0x4kzl2vhdy9wzvksk928qvl8qfy7whnw1mw4rmjc3zax00r1f0q.nar.zst error="server returned 404: 404 page not found\n"11952026/11/06 08:18:35 WARN Failed to register uploaded object key=dnwx5djqr0fl5hk20zqw6dc7lx97yy6q.ls error="server returned 404: 404 page not found\n"11962026/11/06 08:18:35 WARN Failed to register uploaded object key=cp6y9acs936rncsaxjpi7wgl66rpycxf.ls error="server returned 404: 404 page not found\n"11972026/11/06 08:18:35 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11982026/11/06 08:18:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11992026/11/06 08:18:35 WARN Failed to register uploaded object key=7vif2zgn2vqz0hfw211q0nk4sd4x3zbq.ls error="server returned 404: 404 page not found\n"12002026/11/06 08:18:35 INFO Signed narinfos id=1 count=312012026/11/06 08:18:35 INFO Uploading 3 narinfos12022026/11/06 08:18:35 WARN Failed to register uploaded object key=7vif2zgn2vqz0hfw211q0nk4sd4x3zbq.narinfo error="server returned 404: 404 page not found\n"12032026/11/06 08:18:35 WARN Failed to register uploaded object key=dnwx5djqr0fl5hk20zqw6dc7lx97yy6q.narinfo error="server returned 404: 404 page not found\n"12042026/11/06 08:18:35 INFO Received complete push request method=POST path=/api/pushes/1/complete12052026/11/06 08:18:35 WARN Failed to register uploaded object key=cp6y9acs936rncsaxjpi7wgl66rpycxf.narinfo error="server returned 404: 404 page not found\n"12062026/11/06 08:18:36 INFO Completed push id=1 objects=8 duration=19.900833ms12072026/11/06 08:18:36 INFO Upload complete. (201ms)1208=== NAME TestClientPushesUseOnePush1209 client_pushes_test.go:97: Retrieved narinfo from S3:1210 StorePath: /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestClientPushesUseOnePush2789111248/001/store/cp6y9acs936rncsaxjpi7wgl66rpycxf-shared-dep1211 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1212 Compression: zstd1213 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821214 NarSize: 1361215 References: 1216 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1217 client_pushes_test.go:97: Retrieved narinfo from S3:1218 StorePath: /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestClientPushesUseOnePush2789111248/001/store/7vif2zgn2vqz0hfw211q0nk4sd4x3zbq-a1219 URL: nar/0x4kzl2vhdy9wzvksk928qvl8qfy7whnw1mw4rmjc3zax00r1f0q.nar.zst1220 Compression: zstd1221 NarHash: sha256:0x4kzl2vhdy9wzvksk928qvl8qfy7whnw1mw4rmjc3zax00r1f0q1222 NarSize: 2561223 References: /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestClientPushesUseOnePush2789111248/001/store/cp6y9acs936rncsaxjpi7wgl66rpycxf-shared-dep1224 CA: text:sha256:11nnsy3fsfs1lnif71f2iryv9zpflcjm39fklml3brv6bfx4giav1225 client_pushes_test.go:97: Retrieved narinfo from S3:1226 StorePath: /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestClientPushesUseOnePush2789111248/001/store/dnwx5djqr0fl5hk20zqw6dc7lx97yy6q-b1227 URL: nar/0x4kzl2vhdy9wzvksk928qvl8qfy7whnw1mw4rmjc3zax00r1f0q.nar.zst1228 Compression: zstd1229 NarHash: sha256:0x4kzl2vhdy9wzvksk928qvl8qfy7whnw1mw4rmjc3zax00r1f0q1230 NarSize: 2561231 References: /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestClientPushesUseOnePush2789111248/001/store/cp6y9acs936rncsaxjpi7wgl66rpycxf-shared-dep1232 CA: text:sha256:11nnsy3fsfs1lnif71f2iryv9zpflcjm39fklml3brv6bfx4giav1233--- PASS: TestClientPushesUseOnePush (5.74s)1234=== CONT TestOrphanedObjectsGC1235=== RUN TestService_RequireScope_OIDC/builder_may_write1236=== PAUSE TestService_RequireScope_OIDC/builder_may_write1237=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1238=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1239=== RUN TestService_RequireScope_OIDC/ops_may_admin1240=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1241=== RUN TestService_RequireScope_OIDC/ops_may_not_write1242=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1243=== RUN TestService_RequireScope_OIDC/reader_may_not_write1244=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1245=== RUN TestService_RequireScope_OIDC/static_token_may_admin1246=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1247=== RUN TestService_RequireScope_OIDC/static_token_may_write1248=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1249=== RUN TestService_RequireScope_OIDC/reader_may_read1250=== PAUSE TestService_RequireScope_OIDC/reader_may_read1251=== RUN TestService_RequireScope_OIDC/writer_implies_read1252=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1253=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1254=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1255=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1256=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1257=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1258=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1259=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1260=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1261=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1262=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1263=== CONT TestReadRedirectKeepsNarinfoProxied1264--- PASS: TestReadRedirectUsesPublicS3URL (6.01s)1265=== CONT TestReadRedirectNar1266--- PASS: TestService_ReadAuthMiddleware (5.23s)1267=== CONT TestReadProxyDisabled1268--- PASS: TestDeleteClosuresRacingPins (6.21s)1269=== CONT TestReadProxyRootRedirectsToIndexHTML12702026/11/06 08:18:36 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"12712026/11/06 08:18:36 WARN mTLS auth: bound subjects configured but subject DN unavailable12722026/11/06 08:18:36 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1273--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (4.84s)1274=== CONT TestReadProxyConditionalGet1275--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (5.03s)1276=== CONT TestReadProxyOutlastsServerWriteTimeout12772026/11/06 08:18:37 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=012782026/11/06 08:18:37 INFO Received create pin request method=POST path=/api/pins/myapp12792026/11/06 08:18:37 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1280--- PASS: TestService_AuthMiddleware (4.88s)1281=== CONT TestReadProxyHead12822026/11/06 08:18:37 INFO Created/updated pin name=myapp store_path=/private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestPinProtectsFromGC4099634213/001/store/47mfhijbvjz155hqfr1rx5x5lz329h8d-pinned-file.txt narinfo_key=47mfhijbvjz155hqfr1rx5x5lz329h8d.narinfo12832026/11/06 08:18:37 INFO Starting cleanup of old closures method=DELETE path=/api/closures12842026/11/06 08:18:37 INFO Garbage collection started12852026/11/06 08:18:37 INFO Aborted multipart uploads count=0 kept=012862026/11/06 08:18:37 WARN Force mode enabled - objects will be deleted immediately without grace period12872026/11/06 08:18:37 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=012882026/11/06 08:18:37 INFO Vacuumed table table=pending_closures12892026/11/06 08:18:37 INFO Vacuumed table table=pending_objects12902026/11/06 08:18:37 INFO Vacuumed table table=multipart_uploads12912026/11/06 08:18:37 INFO Vacuumed table table=closures12922026/11/06 08:18:37 INFO Vacuumed table table=objects1293--- PASS: TestConnectWaitsForAPeerMigration (7.11s)1294=== CONT TestReadProxyInvalidPath12952026/11/06 08:18:37 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01296=== NAME TestClientIntegration1297 client_integration_test.go:370: Objects in database after GC:1298 client_integration_test.go:370: Successfully deleted all objects with GC --force1299--- PASS: TestClientIntegration (7.24s)1300=== CONT TestReadProxy40413012026/11/06 08:18:37 INFO Aborted multipart uploads count=0 kept=013022026/11/06 08:18:37 WARN Force mode enabled - objects will be deleted immediately without grace period13032026/11/06 08:18:37 INFO Aborted multipart uploads count=0 kept=013042026/11/06 08:18:37 WARN Force mode enabled - objects will be deleted immediately without grace period13052026/11/06 08:18:37 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=013062026/11/06 08:18:38 INFO Vacuumed table table=pending_closures13072026/11/06 08:18:38 INFO Vacuumed table table=pending_objects13082026/11/06 08:18:38 INFO Vacuumed table table=multipart_uploads13092026/11/06 08:18:38 INFO Vacuumed table table=closures13102026/11/06 08:18:38 INFO Vacuumed table table=objects13112026/11/06 08:18: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=013122026/11/06 08:18:38 INFO Received uploads request method=POST path=/api/pending_closures13132026/11/06 08:18:38 INFO Vacuumed table table=pending_closures13142026/11/06 08:18:38 INFO Vacuumed table table=pending_objects13152026/11/06 08:18:38 INFO Vacuumed table table=multipart_uploads13162026/11/06 08:18:38 INFO Vacuumed table table=closures13172026/11/06 08:18:38 INFO Vacuumed table table=objects1318--- PASS: TestGCSweepDeliversEachKeyOnce (5.25s)1319=== CONT TestReadProxyNarStreaming1320--- PASS: TestCommitRacingPendingCleanupKeepsObjects (5.04s)1321=== CONT TestReadProxyContentNegotiation13222026/11/06 08:18:38 INFO Aborted multipart uploads count=0 kept=013232026/11/06 08:18:38 WARN Force mode enabled - objects will be deleted immediately without grace period13242026/11/06 08:18: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=013252026/11/06 08:18:38 INFO Vacuumed table table=pending_closures1326--- PASS: TestPushWaitsForSweepHoldingRow (5.29s)1327=== CONT TestReadProxyNarinfoAlreadyDecompressed13282026/11/06 08:18:38 INFO Vacuumed table table=pending_objects13292026/11/06 08:18:38 INFO Vacuumed table table=multipart_uploads13302026/11/06 08:18:38 INFO Vacuumed table table=closures13312026/11/06 08:18:38 INFO Vacuumed table table=objects1332--- PASS: TestSweepRechecksPendingAfterLocking (5.19s)1333=== CONT TestReadProxyNarinfo1334--- PASS: TestGetExistingObjectsLocksRows (5.23s)1335=== CONT TestIsValidCachePath1336=== RUN TestIsValidCachePath/narinfo1337=== PAUSE TestIsValidCachePath/narinfo1338=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1339=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1340=== RUN TestIsValidCachePath/nar_zst1341=== PAUSE TestIsValidCachePath/nar_zst1342=== RUN TestIsValidCachePath/nar_xz1343=== PAUSE TestIsValidCachePath/nar_xz1344=== RUN TestIsValidCachePath/nar_bz21345=== PAUSE TestIsValidCachePath/nar_bz21346=== RUN TestIsValidCachePath/nar_uncompressed1347=== PAUSE TestIsValidCachePath/nar_uncompressed1348=== RUN TestIsValidCachePath/ls1349=== PAUSE TestIsValidCachePath/ls1350=== RUN TestIsValidCachePath/log1351=== PAUSE TestIsValidCachePath/log1352=== RUN TestIsValidCachePath/realisation1353=== PAUSE TestIsValidCachePath/realisation1354=== RUN TestIsValidCachePath/nix-cache-info1355=== PAUSE TestIsValidCachePath/nix-cache-info1356=== RUN TestIsValidCachePath/index.html1357=== PAUSE TestIsValidCachePath/index.html1358=== RUN TestIsValidCachePath/traversal_parent1359=== PAUSE TestIsValidCachePath/traversal_parent1360=== RUN TestIsValidCachePath/traversal_in_middle1361=== PAUSE TestIsValidCachePath/traversal_in_middle1362=== RUN TestIsValidCachePath/invalid_char_e1363=== PAUSE TestIsValidCachePath/invalid_char_e1364=== RUN TestIsValidCachePath/invalid_char_u1365=== PAUSE TestIsValidCachePath/invalid_char_u1366=== RUN TestIsValidCachePath/random_path1367=== PAUSE TestIsValidCachePath/random_path1368=== RUN TestIsValidCachePath/empty1369=== PAUSE TestIsValidCachePath/empty1370=== RUN TestIsValidCachePath/leading_slash1371=== PAUSE TestIsValidCachePath/leading_slash1372=== RUN TestIsValidCachePath/wrong_extension1373=== PAUSE TestIsValidCachePath/wrong_extension1374=== RUN TestIsValidCachePath/short_hash1375=== PAUSE TestIsValidCachePath/short_hash1376=== CONT TestParseSingleRange1377=== RUN TestParseSingleRange/none1378=== PAUSE TestParseSingleRange/none1379=== RUN TestParseSingleRange/unknown_unit1380=== PAUSE TestParseSingleRange/unknown_unit1381=== RUN TestParseSingleRange/multi-range_ignored1382=== PAUSE TestParseSingleRange/multi-range_ignored1383=== RUN TestParseSingleRange/malformed_no_dash1384=== PAUSE TestParseSingleRange/malformed_no_dash1385=== RUN TestParseSingleRange/malformed_both_empty1386=== PAUSE TestParseSingleRange/malformed_both_empty1387=== RUN TestParseSingleRange/malformed_end_before_start1388=== PAUSE TestParseSingleRange/malformed_end_before_start1389=== RUN TestParseSingleRange/closed1390=== PAUSE TestParseSingleRange/closed1391=== RUN TestParseSingleRange/open-ended1392=== PAUSE TestParseSingleRange/open-ended1393=== RUN TestParseSingleRange/end_clamped_to_size1394=== PAUSE TestParseSingleRange/end_clamped_to_size1395=== RUN TestParseSingleRange/suffix1396=== PAUSE TestParseSingleRange/suffix1397=== RUN TestParseSingleRange/suffix_exceeds_size1398=== PAUSE TestParseSingleRange/suffix_exceeds_size1399=== RUN TestParseSingleRange/single_byte1400=== PAUSE TestParseSingleRange/single_byte1401=== RUN TestParseSingleRange/start_past_EOF1402=== PAUSE TestParseSingleRange/start_past_EOF1403=== RUN TestParseSingleRange/start_far_past_EOF1404=== PAUSE TestParseSingleRange/start_far_past_EOF1405=== CONT TestPresentNotReportedWhileGCDeletesClosure1406=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1407=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1408=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1409=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1410=== CONT TestPresentRefreshesOnlyStaleClosures1411--- PASS: TestRegisterCompletedObjectNeedsPendingRow (5.41s)1412=== CONT TestPresentReportsOnlyClosureRoots1413=== NAME TestPinProtectsFromGC1414 client_integration_test.go:887: Pin successfully protected closure from garbage collection1415--- PASS: TestPinProtectsFromGC (8.94s)1416=== CONT TestCreatePin_ReservedPins14172026/11/06 08:18:39 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57569/oidc14182026/11/06 08:18:39 INFO Aborted multipart uploads count=0 kept=014192026/11/06 08:18:39 WARN Force mode enabled - objects will be deleted immediately without grace period14202026/11/06 08:18:39 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=014212026/11/06 08:18:39 INFO Vacuumed table table=pending_closures14222026/11/06 08:18:39 INFO Vacuumed table table=pending_objects14232026/11/06 08:18:39 INFO Vacuumed table table=multipart_uploads14242026/11/06 08:18:39 INFO Vacuumed table table=closures14252026/11/06 08:18:39 INFO Vacuumed table table=objects14262026/11/06 08:18:39 INFO Aborted multipart uploads count=0 kept=014272026/11/06 08:18:39 WARN Force mode enabled - objects will be deleted immediately without grace period14282026/11/06 08:18:39 INFO Received uploads request method=POST path=/api/pending_closures14292026/11/06 08:18:39 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=014302026/11/06 08:18:39 INFO Vacuumed table table=pending_closures14312026/11/06 08:18:39 INFO Vacuumed table table=pending_objects14322026/11/06 08:18:39 INFO Vacuumed table table=multipart_uploads14332026/11/06 08:18:39 INFO Vacuumed table table=closures14342026/11/06 08:18:39 INFO Vacuumed table table=objects1435--- PASS: TestSweepSkipsRowsLockedByPush (5.92s)1436=== CONT TestOrphanedObjectsGCStressTest14372026/11/06 08:18:39 INFO Received uploads request method=POST path=/api/pending_closures14382026/11/06 08:18:39 INFO Aborted multipart uploads count=0 kept=014392026/11/06 08:18:39 WARN Force mode enabled - objects will be deleted immediately without grace period14402026/11/06 08:18:39 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."14412026/11/06 08:18:39 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1442--- PASS: TestFailedS3DeleteKeepsTombstone (5.74s)1443=== CONT TestService_cleanupPendingClosuresHandler1444--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (5.43s)1445=== CONT TestService_verifyS3ReuploadsStaleNarinfo1446=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed1447=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed1448=== RUN TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed1449=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed1450=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost1451=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost1452=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed1453=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed1454=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed1455=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed1456=== CONT TestService_verifyS3Integrity14572026/11/06 08:18:40 INFO Received uploads request method=POST path=/api/pending_closures14582026/11/06 08:18:40 INFO Received uploads request method=POST path=/api/pending_closures1459--- PASS: TestService_Rustfstest (4.96s)1460=== CONT TestService_createPendingClosureHandler14612026/11/06 08:18:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14622026/11/06 08:18:40 INFO Received uploads request method=POST path=/api/pending_closures14632026/11/06 08:18:41 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst14642026/11/06 08:18:41 INFO Received uploads request method=POST path=/api/pending_closures1465--- PASS: TestPresignedUploadRegisteredBeforeCommit (5.17s)1466=== CONT TestPush_SignsNarinfosOfItsPendingObjects1467--- PASS: TestReadRedirectKeepsNarinfoProxied (5.45s)1468=== CONT TestCompleteMultipartUpload_ErrorButObjectExists14692026/11/06 08:18:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1470--- PASS: TestReadRedirectNar (5.59s)1471=== CONT TestSharedNarBothUploadsComplete14722026/11/06 08:18:42 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MDQ1ZGRlY2MtMGQ3My00ZTczLThjZDEtYTVlZTc5OTIzMmFkLjhhOTg2NWE4LWFkMTYtNGY2Zi05MGZjLWNhOTE4YTE3YzI1OHgxNzkzOTUzMTIwMTQzOTYyMDAw parts=1214732026/11/06 08:18:42 INFO Received uploads request method=POST path=/api/pending_closures1474--- PASS: TestCompletedNarNotReofferedAcrossClosures (7.10s)1475=== CONT TestUploadHandlersRejectInvalidKeys1476=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1477=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1478=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1479=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1480=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1481=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1482=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1483=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1484=== CONT TestUploadHandlersRejectOversizedBody1485=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1486=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1487=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1488=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1489=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1490=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1491=== CONT TestNARDeduplicationMetadataUploadBug1492--- PASS: TestReadProxyDisabled (5.68s)1493=== CONT TestObjectStatsUpdatedOncePerCommit1494--- PASS: TestReadProxyRootRedirectsToIndexHTML (5.93s)1495=== CONT TestObjectStatsTrigger1496--- PASS: TestReadProxyConditionalGet (6.14s)1497=== CONT TestPendingCleanupUsesOneCutoff1498=== NAME TestOrphanedObjectsGC1499 orphaned_objects_gc_test.go:287: GC Test Summary:1500 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1501 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1502 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1503 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1504 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1505--- PASS: TestOrphanedObjectsGC (7.13s)1506=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1507--- PASS: TestReadProxyHead (6.34s)1508=== CONT TestMultipartCleanup1509--- PASS: TestReadProxyInvalidPath (6.31s)1510=== CONT TestServerTLSConfig1511=== RUN TestServerTLSConfig/no_client_CA1512=== PAUSE TestServerTLSConfig/no_client_CA1513=== RUN TestServerTLSConfig/missing_CA_file1514=== PAUSE TestServerTLSConfig/missing_CA_file1515=== RUN TestServerTLSConfig/not_a_PEM_file1516=== PAUSE TestServerTLSConfig/not_a_PEM_file1517=== CONT TestService_NativeMTLS1518--- PASS: TestReadProxyNarStreaming (6.12s)1519=== CONT TestMetricsCommit1520--- PASS: TestReadProxy404 (6.94s)1521=== CONT TestMetricsInventory1522--- PASS: TestReadProxyContentNegotiation (6.47s)1523=== CONT TestIsValidUploadKey1524=== RUN TestIsValidUploadKey/narinfo1525=== PAUSE TestIsValidUploadKey/narinfo1526=== RUN TestIsValidUploadKey/nar_zst1527=== PAUSE TestIsValidUploadKey/nar_zst1528=== RUN TestIsValidUploadKey/nar_xz1529=== PAUSE TestIsValidUploadKey/nar_xz1530=== RUN TestIsValidUploadKey/nar_plain1531=== PAUSE TestIsValidUploadKey/nar_plain1532=== RUN TestIsValidUploadKey/listing1533=== PAUSE TestIsValidUploadKey/listing1534=== RUN TestIsValidUploadKey/build_log1535=== PAUSE TestIsValidUploadKey/build_log1536=== RUN TestIsValidUploadKey/build_log_home-manager_file1537=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1538=== RUN TestIsValidUploadKey/build_log_plus_in_name1539=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1540=== RUN TestIsValidUploadKey/build_log_question_mark1541=== PAUSE TestIsValidUploadKey/build_log_question_mark1542=== RUN TestIsValidUploadKey/build_log_equals1543=== PAUSE TestIsValidUploadKey/build_log_equals1544=== RUN TestIsValidUploadKey/realisation1545=== PAUSE TestIsValidUploadKey/realisation1546=== RUN TestIsValidUploadKey/realisation_plus_in_output1547=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1548=== RUN TestIsValidUploadKey/nix-cache-info1549=== PAUSE TestIsValidUploadKey/nix-cache-info1550=== RUN TestIsValidUploadKey/index.html1551=== PAUSE TestIsValidUploadKey/index.html1552=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1553=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1554=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1555=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1556=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1557=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1558=== RUN TestIsValidUploadKey/traversal1559=== PAUSE TestIsValidUploadKey/traversal1560=== RUN TestIsValidUploadKey/traversal_nar1561=== PAUSE TestIsValidUploadKey/traversal_nar1562=== RUN TestIsValidUploadKey/absolute1563=== PAUSE TestIsValidUploadKey/absolute1564=== RUN TestIsValidUploadKey/empty_key1565=== PAUSE TestIsValidUploadKey/empty_key1566=== RUN TestIsValidUploadKey/unknown_type1567=== PAUSE TestIsValidUploadKey/unknown_type1568=== CONT TestGCMetrics1569--- PASS: TestReadProxyNarinfoAlreadyDecompressed (6.10s)1570=== CONT TestTombstonedObjectOfferedWithoutWaiting15712026/11/06 08:18:45 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1572--- PASS: TestReadProxyNarinfo (6.37s)1573=== CONT TestGCSweepSkipsPendingObjects1574--- PASS: TestPresentRefreshesOnlyStaleClosures (6.40s)1575=== CONT TestDeduplicatedObjectsRecordedAsPending1576--- PASS: TestPresentReportsOnlyClosureRoots (6.33s)1577=== CONT TestPushDedupSurvivesConcurrentGC15782026/11/06 08:18:45 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15792026/11/06 08:18:45 WARN Refused reserved pin name=worker-x86_64-linux15802026/11/06 08:18:45 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15812026/11/06 08:18:45 INFO Received create pin request method=POST path=/api/pins/my-app15822026/11/06 08:18:45 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1583--- PASS: TestCreatePin_ReservedPins (6.42s)1584=== CONT TestPush_RejectsBadRequests15852026/11/06 08:18:46 WARN Rate limiter enabled after throttle name=s3-test rate=515862026/11/06 08:18:46 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1587=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1588 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101589 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001590--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (10.96s)1591=== CONT TestPendingClosureWriteTimeout1592=== RUN TestPendingClosureWriteTimeout/empty1593=== PAUSE TestPendingClosureWriteTimeout/empty1594=== RUN TestPendingClosureWriteTimeout/400_objects1595=== PAUSE TestPendingClosureWriteTimeout/400_objects1596=== RUN TestPendingClosureWriteTimeout/670k_objects1597=== PAUSE TestPendingClosureWriteTimeout/670k_objects1598=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1599=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1600=== CONT TestLeadEndsOnShutdown16012026/11/06 08:18:46 INFO Received cleanup request method=DELETE path=/api/pending_closures16022026/11/06 08:18:46 INFO Aborted multipart uploads count=0 kept=016032026/11/06 08:18:46 INFO Received uploads request method=POST path=/api/pending_closures16042026/11/06 08:18:46 INFO Received cleanup request method=DELETE path=/api/pending_closures16052026/11/06 08:18:46 INFO Aborted multipart uploads count=1 kept=016062026/11/06 08:18:46 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16072026-11-06 08:18:46.626 UTC [1446] ERROR: Closure does not exist: id=116082026-11-06 08:18:46.626 UTC [1446] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE16092026-11-06 08:18:46.626 UTC [1446] STATEMENT: -- name: CommitPendingClosure :one1610 SELECT commit_pending_closure($1::bigint)::bigint1611 1612--- PASS: TestService_cleanupPendingClosuresHandler (6.75s)1613=== CONT TestGCBugBareHashReferences16142026/11/06 08:18:46 INFO Received uploads request method=POST path=/api/pending_closures16152026/11/06 08:18:47 INFO Received uploads request method=POST path=/api/pending_closures16162026/11/06 08:18:47 INFO Received uploads request method=POST path=/api/pending_closures16172026/11/06 08:18:47 INFO Received uploads request method=POST path=/api/pending_closures16182026/11/06 08:18:47 INFO Received push request method=POST path=/api/pushes1619--- PASS: TestReadProxyOutlastsServerWriteTimeout (10.64s)1620=== CONT TestGCAdvisoryLockBlocksConcurrentRun16212026/11/06 08:18:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16222026/11/06 08:18:47 INFO Signed narinfos id=1 count=116232026/11/06 08:18:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16242026/11/06 08:18:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16252026/11/06 08:18:47 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"16262026/11/06 08:18:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16272026/11/06 08:18:47 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"16282026/11/06 08:18:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16292026/11/06 08:18:47 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=116302026/11/06 08:18:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16312026/11/06 08:18:47 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1632--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (6.56s)1633=== CONT TestLeadIncumbentAnnouncesAtOnce16342026/11/06 08:18:47 INFO Received uploads request method=POST path=/api/pending_closures16352026/11/06 08:18:48 INFO Received uploads request method=POST path=/api/pending_closures16362026/11/06 08:18:48 INFO Received uploads request method=POST path=/api/pending_closures16372026/11/06 08:18:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16382026/11/06 08:18:48 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MDQ1ZGRlY2MtMGQ3My00ZTczLThjZDEtYTVlZTc5OTIzMmFkLmVjZTIyY2UxLTk2NjUtNDZiOC05ZTE2LTMyN2U1MGJmZjY4ZHgxNzkzOTUzMTI2ODM4NzI0MDAw parts=1016392026/11/06 08:18:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16402026/11/06 08:18:48 INFO Completed upload id=1 objects=2 duration=74.679292ms16412026/11/06 08:18:48 INFO Received uploads request method=POST path=/api/pending_closures16422026/11/06 08:18:48 INFO Received uploads request method=POST path=/api/pending_closures16432026/11/06 08:18:48 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo16442026/11/06 08:18:48 WARN Found objects in DB but missing from S3, will re-upload count=11645--- PASS: TestService_verifyS3Integrity (8.77s)1646=== CONT TestService_readinessHandler16472026/11/06 08:18:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16482026/11/06 08:18:49 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MDQ1ZGRlY2MtMGQ3My00ZTczLThjZDEtYTVlZTc5OTIzMmFkLjBjZjlhMjdkLWU3MTktNGVjNS05YTU3LWEzMDdmN2QzYmFkY3gxNzkzOTUzMTI3MTc5MTA2MDAw parts=1016492026/11/06 08:18:49 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16502026/11/06 08:18:49 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16512026/11/06 08:18:49 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MDQ1ZGRlY2MtMGQ3My00ZTczLThjZDEtYTVlZTc5OTIzMmFkLjg0YThmMzljLTg3ZDEtNGUzOC04YmJlLTBkMmM5YTIxMjc0NXgxNzkzOTUzMTI3ODQ3MTQ1MDAw1652--- PASS: TestObjectStatsUpdatedOncePerCommit (7.01s)16532026/11/06 08:18:49 INFO Completed upload id=1 objects=2 duration=40.601ms1654=== CONT TestCreatePendingClosureRejectsOversizedNAR16552026/11/06 08:18:49 INFO Received uploads request method=POST path=/api/pending_closures1656--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1657=== CONT TestCacheConfigHandlerMaxNarSize1658--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1659=== CONT TestEnsureAbortUploadsRule16602026/11/06 08:18:49 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000016612026/11/06 08:18:49 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MDQ1ZGRlY2MtMGQ3My00ZTczLThjZDEtYTVlZTc5OTIzMmFkLjg0YThmMzljLTg3ZDEtNGUzOC04YmJlLTBkMmM5YTIxMjc0NXgxNzkzOTUzMTI3ODQ3MTQ1MDAw parts=116622026/11/06 08:18:49 INFO Received uploads request method=POST path=/api/pending_closures1663=== NAME TestNARDeduplicationMetadataUploadBug1664 metadata_upload_test.go:48: First store path: /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestNARDeduplicationMetadataUploadBug2898504459/001/store/9bj6fnc5c3khlpcapnmpbfw2c3bn37xy-file1.txt16652026/11/06 08:18:49 INFO Starting cleanup of old closures method=DELETE path=/api/closures1666--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (7.61s)1667=== CONT TestGenerateLandingPage1668--- PASS: TestGenerateLandingPage (0.00s)1669=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit16702026/11/06 08:18:49 INFO Aborted multipart uploads count=0 kept=016712026/11/06 08:18:49 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=01672--- PASS: TestObjectStatsTrigger (6.79s)1673=== CONT TestGCTaskStore_Fail1674--- PASS: TestGCTaskStore_Fail (0.00s)1675=== CONT TestService_healthCheckHandler16762026/11/06 08:18:49 INFO Vacuumed table table=pending_closures16772026/11/06 08:18:49 INFO Vacuumed table table=pending_objects16782026/11/06 08:18:49 INFO Vacuumed table table=multipart_uploads16792026/11/06 08:18:49 INFO Received push request method=POST path=/api/pushes16802026/11/06 08:18:49 INFO Vacuumed table table=closures16812026/11/06 08:18:49 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16822026/11/06 08:18:49 INFO Uploading 9bj6fnc5c3khlpcapnmpbfw2c3bn37xy-file1.txt (160B)16832026/11/06 08:18:49 INFO Vacuumed table table=objects16842026/11/06 08:18:49 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001685--- PASS: TestService_createPendingClosureHandler (8.78s)16862026/11/06 08:18:49 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"1687=== CONT TestGracefulShutdownDrainsInflight16882026/11/06 08:18:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16892026/11/06 08:18:49 WARN Failed to register uploaded object key=9bj6fnc5c3khlpcapnmpbfw2c3bn37xy.ls error="server returned 404: 404 page not found\n"16902026/11/06 08:18:49 INFO Starting HTTP server address=127.0.0.1:5770016912026/11/06 08:18:49 INFO Signed narinfos id=1 count=116922026/11/06 08:18:49 INFO Shutdown signal received, draining in-flight requests timeout=10s16932026/11/06 08:18:49 INFO Uploading 1 narinfos16942026/11/06 08:18:49 INFO Received uploads request method=POST path=/api/pending_closures16952026/11/06 08:18:49 INFO Received complete push request method=POST path=/api/pushes/1/complete16962026/11/06 08:18:49 WARN Failed to register uploaded object key=9bj6fnc5c3khlpcapnmpbfw2c3bn37xy.narinfo error="server returned 404: 404 page not found\n"1697--- PASS: TestGracefulShutdownDrainsInflight (0.08s)1698=== CONT TestGCTaskStore_PhaseUpdates1699--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1700=== CONT TestGCTaskStore_CompletedAllowsNewTask1701--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1702=== CONT TestLeadElectsOneAndHandsOver17032026/11/06 08:18:49 INFO Completed push id=1 objects=3 duration=24.4985ms17042026/11/06 08:18:49 INFO Upload complete. (299ms)1705=== NAME TestNARDeduplicationMetadataUploadBug1706 metadata_upload_test.go:54: Retrieved narinfo from S3:1707 StorePath: /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestNARDeduplicationMetadataUploadBug2898504459/001/store/9bj6fnc5c3khlpcapnmpbfw2c3bn37xy-file1.txt1708 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1709 Compression: zstd1710 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1711 NarSize: 1601712 References: 1713 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1714 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1715 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1716 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}17172026/11/06 08:18:49 INFO Received uploads request method=POST path=/api/pending_closures17182026/11/06 08:18:49 INFO Received cleanup request method=DELETE path=/api/pending_closures1719 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestNARDeduplicationMetadataUploadBug2898504459/001/store/djmd5p62sllrr3p5s3a4pqa03q6p06fa-file2.txt17202026/11/06 08:18:49 INFO Received uploads request method=POST path=/api/pending_closures17212026/11/06 08:18:49 INFO Received push request method=POST path=/api/pushes17222026/11/06 08:18:49 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17232026/11/06 08:18:49 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17242026/11/06 08:18:49 WARN Failed to register uploaded object key=djmd5p62sllrr3p5s3a4pqa03q6p06fa.ls error="server returned 404: 404 page not found\n"17252026/11/06 08:18:49 INFO Signed narinfos id=2 count=117262026/11/06 08:18:49 INFO Uploading 1 narinfos1727--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (6.72s)1728=== CONT TestClientErrorHandling/InvalidStorePath17292026/11/06 08:18:49 INFO Received complete push request method=POST path=/api/pushes/2/complete17302026/11/06 08:18:49 WARN Failed to register uploaded object key=djmd5p62sllrr3p5s3a4pqa03q6p06fa.narinfo error="server returned 404: 404 page not found\n"17312026/11/06 08:18:49 INFO Completed push id=2 objects=3 duration=930.25µs17322026/11/06 08:18:49 INFO Upload complete. (213ms)1733=== NAME TestNARDeduplicationMetadataUploadBug1734 metadata_upload_test.go:76: Retrieved narinfo from S3:1735 StorePath: /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestNARDeduplicationMetadataUploadBug2898504459/001/store/djmd5p62sllrr3p5s3a4pqa03q6p06fa-file2.txt1736 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1737 Compression: zstd1738 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1739 NarSize: 1601740 References: 1741 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1742 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1743 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1744 {"version":1,"root":{"type":"regular","size":44}}1745--- PASS: TestNARDeduplicationMetadataUploadBug (7.90s)1746=== CONT TestClientErrorHandling/ServerNotAvailable17472026/11/06 08:18:50 INFO Received uploads request method=POST path=/api/pending_closures17482026/11/06 08:18:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17492026/11/06 08:18:50 INFO Received cleanup request method=DELETE path=/api/pending_closures17502026/11/06 08:18:50 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket73/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""17512026/11/06 08:18:50 INFO Aborted multipart uploads count=0 kept=117522026/11/06 08:18:50 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MDQ1ZGRlY2MtMGQ3My00ZTczLThjZDEtYTVlZTc5OTIzMmFkLmNhZTBiYjk5LTNmZjItNGFlMi04Zjc2LTM1MDFlMGJkZjBiM3gxNzkzOTUzMTI4MjQzNzc5MDAw parts=1217532026/11/06 08:18:50 INFO Received cleanup request method=DELETE path=/api/pending_closures17542026/11/06 08:18:50 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/present17552026/11/06 08:18:50 INFO Aborted multipart uploads count=1 kept=01756--- PASS: TestMultipartCleanup (6.84s)1757=== CONT TestClientErrorHandling/InvalidAuthToken17582026/11/06 08:18:50 WARN mTLS auth: subject not in bound subjects subject="CN=reader"17592026/11/06 08:18:50 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1760--- PASS: TestService_NativeMTLS (6.66s)1761=== CONT TestGCEndsOnShutdown/before_the_run17622026/11/06 08:18:50 WARN Request failed, retrying attempt=2 backoff=210.774922ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17632026/11/06 08:18:50 INFO Received push request method=POST path=/api/pushes17642026/11/06 08:18:50 WARN Request failed, retrying attempt=3 backoff=378.303135ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17652026/11/06 08:18:50 INFO Received complete push request method=POST path=/api/pushes/1/complete17662026/11/06 08:18:50 INFO Completed push id=1 objects=4 duration=41.566667ms17672026/11/06 08:18:50 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17682026/11/06 08:18:50 INFO Completed upload id=2 objects=2 duration=1.303625ms1769--- PASS: TestMetricsCommit (6.50s)1770=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark17712026/11/06 08:18:51 WARN Request failed, retrying attempt=4 backoff=824.567911ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1772--- PASS: TestMetricsInventory (6.57s)1773=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete17742026/11/06 08:18:51 INFO Aborted multipart uploads count=0 kept=017752026/11/06 08:18:51 WARN Force mode enabled - objects will be deleted immediately without grace period17762026/11/06 08:18:51 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=017772026/11/06 08:18:51 INFO Vacuumed table table=pending_closures17782026/11/06 08:18:51 INFO Vacuumed table table=pending_objects17792026/11/06 08:18:51 INFO Vacuumed table table=multipart_uploads17802026/11/06 08:18:51 INFO Vacuumed table table=closures17812026/11/06 08:18:51 INFO Vacuumed table table=objects1782--- PASS: TestGCMetrics (6.84s)1783=== CONT TestCacheConfigHandler/full_config,_no_issuer1784=== CONT TestProxyWriteTimeout/narinfo1785=== CONT TestProxyWriteTimeout/unknown_size1786=== CONT TestProxyWriteTimeout/10_GiB_nar1787=== CONT TestProxyWriteTimeout/1_GiB_nar1788--- PASS: TestProxyWriteTimeout (0.00s)1789 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1790 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1791 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1792 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1793=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1794=== CONT TestCacheConfigHandler/no_cache_url_configured1795=== CONT TestCacheConfigHandler/no_signing_keys1796--- PASS: TestCacheConfigHandler (0.00s)1797 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1798 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1799 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1800 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1801=== CONT TestResolveDBConnectionString/flag_wins1802=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1803=== CONT TestResolveDBConnectionString/nothing_configured1804=== CONT TestResolveDBConnectionString/missing_file_is_an_error1805=== CONT TestResolveDBConnectionString/file_when_flag_empty1806=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1807--- PASS: TestResolveDBConnectionString (0.02s)1808 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1809 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1810 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1811 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1812 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)18132026/11/06 08:18:51 INFO Received uploads request method=POST path=/api/pending_closures1814--- PASS: TestTombstonedObjectOfferedWithoutWaiting (7.05s)1815=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check18162026/11/06 08:18:51 WARN Request failed, retrying attempt=5 backoff=1.641208847s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18172026/11/06 08:18:52 INFO Received uploads request method=POST path=/api/pending_closures18182026/11/06 08:18:52 INFO Aborted multipart uploads count=0 kept=018192026/11/06 08:18:52 WARN Force mode enabled - objects will be deleted immediately without grace period18202026/11/06 08:18:52 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=018212026/11/06 08:18:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18222026/11/06 08:18:52 INFO Vacuumed table table=pending_closures18232026/11/06 08:18:52 INFO Vacuumed table table=pending_objects18242026/11/06 08:18:52 INFO Vacuumed table table=multipart_uploads18252026/11/06 08:18:52 INFO Vacuumed table table=closures18262026/11/06 08:18:52 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MDQ1ZGRlY2MtMGQ3My00ZTczLThjZDEtYTVlZTc5OTIzMmFkLjBkZDFhMTE4LWZmYjktNDFmOC1iZThlLWU5ZjAyZTJjY2EwNXgxNzkzOTUzMTI4MjkzMTYzMDAw parts=121827--- PASS: TestSharedNarBothUploadsComplete (10.51s)1828=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1829=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18302026/11/06 08:18:52 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]1831=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1832=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18332026/11/06 08:18:52 WARN Authentication failed token_preview=eyJhbGciOi...vdYoorJkrQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1834=== CONT TestService_RequireScope_OIDC/builder_may_write1835=== CONT TestService_RequireScope_OIDC/reader_may_read18362026/11/06 08:18:52 INFO Vacuumed table table=objects1837=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1838=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18392026/11/06 08:18:52 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]1840=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1841=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1842--- PASS: TestService_AuthMiddleware_OIDC (5.58s)1843 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1844 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1845 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1846 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)1847=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1848=== CONT TestService_RequireScope_OIDC/writer_implies_read1849=== CONT TestService_RequireScope_OIDC/reader_may_not_write1850=== CONT TestService_RequireScope_OIDC/static_token_may_write1851=== CONT TestService_RequireScope_OIDC/static_token_may_admin1852=== CONT TestService_RequireScope_OIDC/ops_may_admin1853=== CONT TestService_RequireScope_OIDC/ops_may_not_write1854=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1855=== CONT TestIsValidCachePath/narinfo1856=== CONT TestIsValidCachePath/traversal_parent1857=== CONT TestIsValidCachePath/index.html1858=== CONT TestIsValidCachePath/nix-cache-info1859=== CONT TestIsValidCachePath/realisation1860=== CONT TestIsValidCachePath/log1861--- PASS: TestService_RequireScope_OIDC (5.84s)1862 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1863 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1864 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1865 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1866 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1867 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1868 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1869 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1870 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1871 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1872 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1873 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1874 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1875 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1876=== CONT TestIsValidCachePath/ls1877=== CONT TestIsValidCachePath/nar_uncompressed18782026/11/06 08:18:52 INFO Received uploads request method=POST path=/api/pending_closures1879=== CONT TestIsValidCachePath/nar_bz21880=== CONT TestIsValidCachePath/nar_xz1881=== CONT TestIsValidCachePath/nar_zst1882=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1883=== CONT TestIsValidCachePath/empty1884=== CONT TestIsValidCachePath/short_hash1885=== CONT TestIsValidCachePath/wrong_extension1886=== CONT TestIsValidCachePath/leading_slash1887=== CONT TestIsValidCachePath/random_path1888=== CONT TestIsValidCachePath/invalid_char_e1889--- PASS: TestGCSweepSkipsPendingObjects (7.37s)1890=== CONT TestIsValidCachePath/invalid_char_u1891=== CONT TestIsValidCachePath/traversal_in_middle1892=== CONT TestParseSingleRange/none1893=== CONT TestParseSingleRange/start_far_past_EOF1894--- PASS: TestIsValidCachePath (0.00s)1895 --- PASS: TestIsValidCachePath/narinfo (0.00s)1896 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1897 --- PASS: TestIsValidCachePath/index.html (0.00s)1898 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1899 --- PASS: TestIsValidCachePath/realisation (0.00s)1900 --- PASS: TestIsValidCachePath/log (0.00s)1901 --- PASS: TestIsValidCachePath/ls (0.00s)1902 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1903 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1904 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1905 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1906 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1907 --- PASS: TestIsValidCachePath/empty (0.00s)1908 --- PASS: TestIsValidCachePath/short_hash (0.00s)1909 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1910 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1911 --- PASS: TestIsValidCachePath/random_path (0.00s)1912 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1913 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1914 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1915=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1916=== CONT TestParseSingleRange/start_past_EOF1917=== CONT TestParseSingleRange/single_byte1918=== CONT TestParseSingleRange/suffix_exceeds_size1919=== CONT TestParseSingleRange/suffix1920=== CONT TestParseSingleRange/end_clamped_to_size1921=== CONT TestParseSingleRange/open-ended1922=== CONT TestParseSingleRange/closed1923=== CONT TestParseSingleRange/malformed_end_before_start1924=== CONT TestParseSingleRange/malformed_both_empty1925=== CONT TestParseSingleRange/malformed_no_dash1926=== CONT TestParseSingleRange/multi-range_ignored1927=== CONT TestParseSingleRange/unknown_unit1928=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1929--- PASS: TestParseSingleRange (0.00s)1930 --- PASS: TestParseSingleRange/none (0.00s)1931 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1932 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1933 --- PASS: TestParseSingleRange/single_byte (0.00s)1934 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1935 --- PASS: TestParseSingleRange/suffix (0.00s)1936 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1937 --- PASS: TestParseSingleRange/open-ended (0.00s)1938 --- PASS: TestParseSingleRange/closed (0.00s)1939 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1940 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1941 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1942 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1943 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1944--- PASS: TestDeduplicatedObjectsRecordedAsPending (7.32s)1945=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed19462026/11/06 08:18:52 INFO Received uploads request method=POST path=/api/pending_closures1947=== RUN TestPush_RejectsBadRequests/no_roots1948=== PAUSE TestPush_RejectsBadRequests/no_roots1949=== RUN TestPush_RejectsBadRequests/no_objects1950=== PAUSE TestPush_RejectsBadRequests/no_objects1951=== RUN TestPush_RejectsBadRequests/bad_root1952=== PAUSE TestPush_RejectsBadRequests/bad_root1953=== RUN TestPush_RejectsBadRequests/root_not_in_objects1954=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1955=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost19562026/11/06 08:18:53 INFO Aborted multipart uploads count=0 kept=019572026/11/06 08:18:53 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=019582026/11/06 08:18:53 INFO Vacuumed table table=pending_closures19592026/11/06 08:18:53 INFO Vacuumed table table=pending_objects19602026/11/06 08:18:53 INFO Vacuumed table table=multipart_uploads19612026/11/06 08:18:53 INFO Vacuumed table table=closures19622026/11/06 08:18:53 INFO Vacuumed table table=objects19632026/11/06 08:18:53 INFO Aborted multipart uploads count=0 kept=019642026/11/06 08:18:53 WARN Force mode enabled - objects will be deleted immediately without grace period19652026/11/06 08:18:53 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=019662026/11/06 08:18:53 INFO Vacuumed table table=pending_closures19672026/11/06 08:18:53 INFO Vacuumed table table=pending_objects19682026/11/06 08:18:53 INFO Vacuumed table table=multipart_uploads19692026/11/06 08:18:53 INFO Vacuumed table table=closures19702026/11/06 08:18:53 INFO Vacuumed table table=objects1971--- PASS: TestPushDedupSurvivesConcurrentGC (8.02s)1972=== CONT TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed19732026/11/06 08:18:53 INFO lead: acquired remote=192.0.2.1:123419742026/11/06 08:18:53 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-config19752026/11/06 08:18:53 WARN Request failed, retrying attempt=2 backoff=202.976571ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19762026/11/06 08:18:53 WARN Request failed, retrying attempt=3 backoff=404.233699ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19772026/11/06 08:18:54 INFO lead: acquired remote=192.0.2.1:123419782026/11/06 08:18:54 INFO lead: released remote=192.0.2.1:12341979--- PASS: TestLeadIncumbentAnnouncesAtOnce (6.47s)1980=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed1981--- PASS: TestGCBugBareHashReferences (7.45s)1982=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed19832026/11/06 08:18:54 WARN Request failed, retrying attempt=4 backoff=765.88895ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19842026/11/06 08:18:54 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld3 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1985--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (6.90s)1986=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info19872026/11/06 08:18:54 INFO Received uploads request method=POST path=/1988=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key19892026/11/06 08:18:54 INFO Received request for more parts method=POST path=/1990=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal19912026/11/06 08:18:54 INFO Received uploads request method=POST path=/1992=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key19932026/11/06 08:18:54 INFO Received complete multipart upload request method=POST path=/1994=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19952026/11/06 08:18:54 INFO Received uploads request method=POST path=/1996--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1997 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1998 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1999 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.01s)2000 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)20012026/11/06 08:18:54 INFO lead: released remote=192.0.2.1:12342002--- PASS: TestLeadEndsOnShutdown (8.49s)2003=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts20042026/11/06 08:18:54 INFO Received request for more parts method=POST path=/2005=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart20062026/11/06 08:18:54 INFO Received complete multipart upload request method=POST path=/2007=== CONT TestServerTLSConfig/no_client_CA2008=== CONT TestServerTLSConfig/not_a_PEM_file2009=== CONT TestServerTLSConfig/missing_CA_file2010=== CONT TestIsValidUploadKey/narinfo2011--- PASS: TestServerTLSConfig (0.00s)2012 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2013 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)2014 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2015=== CONT TestIsValidUploadKey/realisation_plus_in_output2016=== CONT TestIsValidUploadKey/unknown_type2017=== CONT TestIsValidUploadKey/empty_key2018=== CONT TestIsValidUploadKey/absolute2019=== CONT TestIsValidUploadKey/traversal_nar2020=== CONT TestIsValidUploadKey/traversal2021=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2022=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2023=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2024=== CONT TestIsValidUploadKey/index.html2025=== CONT TestIsValidUploadKey/nix-cache-info2026=== CONT TestIsValidUploadKey/build_log_home-manager_file2027=== CONT TestIsValidUploadKey/realisation2028=== CONT TestIsValidUploadKey/build_log_equals2029=== CONT TestIsValidUploadKey/build_log_question_mark2030=== CONT TestIsValidUploadKey/build_log_plus_in_name2031=== CONT TestIsValidUploadKey/nar_plain2032=== CONT TestIsValidUploadKey/build_log2033=== CONT TestIsValidUploadKey/listing2034=== CONT TestIsValidUploadKey/nar_xz2035=== CONT TestIsValidUploadKey/nar_zst2036--- PASS: TestIsValidUploadKey (0.00s)2037 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2038 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2039 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2040 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2041 --- PASS: TestIsValidUploadKey/absolute (0.00s)2042 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2043 --- PASS: TestIsValidUploadKey/traversal (0.00s)2044 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2045 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2046 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2047 --- PASS: TestIsValidUploadKey/index.html (0.00s)2048 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2049 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2050 --- PASS: TestIsValidUploadKey/realisation (0.00s)2051 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2052 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2053 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2054 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2055 --- PASS: TestIsValidUploadKey/build_log (0.00s)2056 --- PASS: TestIsValidUploadKey/listing (0.00s)2057 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2058 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2059=== CONT TestPendingClosureWriteTimeout/empty2060=== CONT TestPendingClosureWriteTimeout/670k_objects2061=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline20622026/11/06 08:18:54 WARN readiness check failed error="closed pool"2063--- PASS: TestService_readinessHandler (5.77s)2064=== CONT TestPendingClosureWriteTimeout/400_objects2065=== CONT TestPush_RejectsBadRequests/no_roots20662026/11/06 08:18:54 INFO Received push request method=POST path=/api/pushes2067=== CONT TestPush_RejectsBadRequests/bad_root20682026/11/06 08:18:54 INFO Received push request method=POST path=/api/pushes2069=== CONT TestPush_RejectsBadRequests/root_not_in_objects20702026/11/06 08:18:54 INFO Received push request method=POST path=/api/pushes2071=== CONT TestPush_RejectsBadRequests/no_objects20722026/11/06 08:18:54 INFO Received push request method=POST path=/api/pushes2073--- PASS: TestPush_RejectsBadRequests (7.46s)2074 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2075 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2076 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2077 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2078--- PASS: TestUploadHandlersRejectOversizedBody (0.09s)2079 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.03s)2080 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)2081 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.36s)20822026/11/06 08:18:55 INFO Installed lifecycle rule aborting incomplete NAR uploads bucket=bucket88 days=22083--- PASS: TestEnsureAbortUploadsRule (5.91s)20842026/11/06 08:18:55 WARN Request failed, retrying attempt=5 backoff=1.597554623s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2085--- PASS: TestService_healthCheckHandler (5.99s)20862026/11/06 08:18:55 INFO Received push request method=POST path=/api/pushes20872026/11/06 08:18:55 INFO Aborted multipart uploads count=1 kept=020882026/11/06 08:18:55 INFO Received complete push request method=POST path=/api/pushes/1/complete20892026/11/06 08:18:55 INFO Received cleanup request method=DELETE path=/api/pending_closures20902026/11/06 08:18:55 INFO Completed push id=1 objects=4 duration=65.480333ms20912026/11/06 08:18:55 INFO Received push request method=POST path=/api/pushes20922026/11/06 08:18:55 INFO Aborted multipart uploads count=1 kept=02093--- PASS: TestPendingCleanupUsesOneCutoff (12.98s)20942026/11/06 08:18:55 INFO Aborted multipart uploads count=0 kept=020952026/11/06 08:18:55 WARN Force mode enabled - objects will be deleted immediately without grace period20962026/11/06 08:18:55 INFO lead: acquired remote=192.0.2.1:123420972026/11/06 08:18:55 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=020982026/11/06 08:18:55 INFO Vacuumed table table=pending_closures20992026/11/06 08:18:55 INFO Vacuumed table table=pending_objects21002026/11/06 08:18:55 INFO Vacuumed table table=multipart_uploads21012026/11/06 08:18:55 INFO Vacuumed table table=closures21022026/11/06 08:18:55 INFO Vacuumed table table=objects21032026/11/06 08:18:55 INFO Received complete push request method=POST path=/api/pushes/2/complete21042026/11/06 08:18:55 INFO Completed push id=2 objects=4 duration=6.901666ms2105--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (6.77s)21062026/11/06 08:18:56 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21072026/11/06 08:18:56 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21082026/11/06 08:18:56 INFO Aborted multipart uploads count=0 kept=021092026/11/06 08:18:56 WARN Force mode enabled - objects will be deleted immediately without grace period21102026-11-06 08:18:56.688 UTC [1602] ERROR: canceling statement due to user request21112026-11-06 08:18:56.688 UTC [1602] STATEMENT: -- name: MarkStaleObjects :execrows2112 WITH RECURSIVE ct AS (2113 SELECT timezone('UTC', now()) AS now2114 ),2115 closure_reach AS (2116 -- Start with all closure keys2117 SELECT o.key, o.refs2118 FROM objects o2119 INNER JOIN closures c ON o.key = c.key2120 UNION2121 -- Recursively add all referenced objects2122 SELECT o.key, o.refs2123 FROM objects o2124 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2125 ),2126 reachable_objects AS (2127 SELECT DISTINCT key FROM closure_reach2128 ),2129 stale_objects AS (2130 SELECT o.key2131 FROM objects AS o, ct2132 WHERE2133 NOT EXISTS (2134 SELECT 12135 FROM reachable_objects ro2136 WHERE ro.key = o.key2137 )2138 AND NOT EXISTS (2139 SELECT 12140 FROM pending_objects AS po2141 WHERE po.key = o.key2142 )2143 AND o.deleted_at IS NULL -- Only mark fresh objects2144 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2145 FOR UPDATE2146 )2147 UPDATE objects2148 SET2149 deleted_at = ct.now,2150 first_deleted_at = COALESCE(first_deleted_at, ct.now)2151 FROM stale_objects, ct2152 WHERE objects.key = stale_objects.key2153 21542026/11/06 08:18:56 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"21552026/11/06 08:18:56 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-config21562026/11/06 08:18:56 WARN Request failed, retrying attempt=2 backoff=217.374303ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21572026/11/06 08:18:56 INFO Aborted multipart uploads count=0 kept=021582026/11/06 08:18:56 WARN Force mode enabled - objects will be deleted immediately without grace period21592026/11/06 08:18:56 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:57333/bucket96/?delete=\": context canceled"2160--- PASS: TestGCEndsOnShutdown (0.00s)2161 --- PASS: TestGCEndsOnShutdown/before_the_run (6.13s)2162 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (5.88s)2163 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (5.84s)21642026/11/06 08:18:57 WARN Request failed, retrying attempt=3 backoff=369.32505ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21652026/11/06 08:18:57 INFO Received uploads request method=POST path=/api/pending_closures21662026/11/06 08:18:57 INFO Aborted multipart uploads count=0 kept=021672026/11/06 08:18:57 WARN Force mode enabled - objects will be deleted immediately without grace period21682026/11/06 08:18:57 INFO lead: released remote=192.0.2.1:123421692026/11/06 08:18:57 INFO lead: acquired remote=192.0.2.1:123421702026/11/06 08:18:57 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=021712026/11/06 08:18:57 INFO Vacuumed table table=pending_closures21722026/11/06 08:18:57 INFO Vacuumed table table=pending_objects21732026/11/06 08:18:57 INFO Vacuumed table table=multipart_uploads21742026/11/06 08:18:57 INFO Vacuumed table table=closures21752026/11/06 08:18:57 INFO Vacuumed table table=objects21762026/11/06 08:18:57 INFO Received uploads request method=POST path=/api/pending_closures21772026/11/06 08:18:57 INFO Aborted multipart uploads count=0 kept=021782026/11/06 08:18:57 WARN Force mode enabled - objects will be deleted immediately without grace period21792026/11/06 08:18:57 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=021802026/11/06 08:18:57 INFO Vacuumed table table=pending_closures21812026/11/06 08:18:57 INFO Vacuumed table table=pending_objects21822026/11/06 08:18:57 INFO Vacuumed table table=multipart_uploads21832026/11/06 08:18:57 INFO Vacuumed table table=closures2184=== NAME TestOrphanedObjectsGCStressTest2185 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains21862026/11/06 08:18:57 WARN Request failed, retrying attempt=4 backoff=817.230534ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21872026/11/06 08:18:57 INFO Vacuumed table table=objects2188 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion2189--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2190 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (5.84s)2191 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (5.62s)21922026/11/06 08:18:57 INFO Received uploads request method=POST path=/api/pending_closures21932026/11/06 08:18:58 INFO Received uploads request method=POST path=/api/pending_closures2194--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2195 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (5.48s)2196 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (5.66s)21972026/11/06 08:18:58 INFO lead: released remote=192.0.2.1:12342198--- PASS: TestLeadElectsOneAndHandsOver (8.65s)21992026/11/06 08:18:58 WARN Request failed, retrying attempt=5 backoff=1.556421055s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22002026/11/06 08:18:58 INFO Received uploads request method=POST path=/api/pending_closures22012026/11/06 08:18:58 INFO Received uploads request method=POST path=/api/pending_closures22022026/11/06 08:18:59 INFO Received uploads request method=POST path=/api/pending_closures22032026/11/06 08:18:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22042026/11/06 08:18:59 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst upload_id=MDQ1ZGRlY2MtMGQ3My00ZTczLThjZDEtYTVlZTc5OTIzMmFkLjIyOGQ1NDZmLTI2NWItNDkyMS05NzI1LTBkNzBjNjVmMjhiMHgxNzkzOTUzMTM3ODY4OTIxMDAw parts=1022052026/11/06 08:18:59 INFO Received uploads request method=POST path=/api/pending_closures22062026/11/06 08:18:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22072026/11/06 08:18:59 INFO Completed upload id=1 objects=3 duration=18.926833ms22082026/11/06 08:18:59 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_closures22092026/11/06 08:18:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22102026/11/06 08:18:59 WARN Request failed, retrying attempt=2 backoff=196.08422ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22112026/11/06 08:18:59 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst upload_id=MDQ1ZGRlY2MtMGQ3My00ZTczLThjZDEtYTVlZTc5OTIzMmFkLjA3MWI1ZmI1LTE0MDctNDNjNC04ZjBkLWIwMGFmODYyNThmM3gxNzkzOTUzMTM4MTE3ODk4MDAw parts=1022122026/11/06 08:18:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22132026/11/06 08:18:59 INFO Completed upload id=1 objects=3 duration=14.289916ms22142026/11/06 08:18:59 INFO Received uploads request method=POST path=/api/pending_closures22152026/11/06 08:19:00 WARN Request failed, retrying attempt=3 backoff=385.370486ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22162026/11/06 08:19:00 INFO Received uploads request method=POST path=/api/pending_closures22172026/11/06 08:19:00 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst22182026/11/06 08:19:00 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0001.narinfo22192026/11/06 08:19:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22202026/11/06 08:19:00 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000200000000000000000000.nar.zst upload_id=MDQ1ZGRlY2MtMGQ3My00ZTczLThjZDEtYTVlZTc5OTIzMmFkLjAxMjhlOGI4LTVhYmMtNDQ4MS1iNTBmLWI2MWE2YjJjNzEwY3gxNzkzOTUzMTM4NDIyNzM1MDAw parts=1022212026/11/06 08:19:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete2222--- PASS: TestPendingClosureWriteTimeout (0.00s)2223 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2224 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2225 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2226 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (5.82s)22272026/11/06 08:19:00 INFO Completed upload id=1 objects=3 duration=22.762ms22282026/11/06 08:19:00 INFO Received uploads request method=POST path=/api/pending_closures22292026/11/06 08:19:00 WARN Request failed, retrying attempt=4 backoff=725.629607ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22302026/11/06 08:19:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22312026/11/06 08:19:00 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst upload_id=MDQ1ZGRlY2MtMGQ3My00ZTczLThjZDEtYTVlZTc5OTIzMmFkLjY0NDZiNWEyLTg4YmEtNDQ2Ni05MjNiLTlmMWRiYjk3OTI3MXgxNzkzOTUzMTM4NzcyMDA2MDAw parts=1022322026/11/06 08:19:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22332026/11/06 08:19:00 INFO Completed upload id=1 objects=3 duration=13.374625ms22342026/11/06 08:19:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22352026/11/06 08:19:00 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst upload_id=MDQ1ZGRlY2MtMGQ3My00ZTczLThjZDEtYTVlZTc5OTIzMmFkLmM2ZmM1M2NkLTRiNTMtNGY3Yi1hNjI4LTdmNTJhMTMwNGQwZngxNzkzOTUzMTM5MTYxNzYyMDAw parts=1022362026/11/06 08:19:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22372026/11/06 08:19:00 INFO Completed upload id=1 objects=3 duration=10.407292ms22382026/11/06 08:19:00 INFO Received uploads request method=POST path=/api/pending_closures22392026/11/06 08:19:01 INFO Received uploads request method=POST path=/api/pending_closures22402026/11/06 08:19:01 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst22412026/11/06 08:19:01 WARN Found objects in DB but missing from S3, will re-upload count=122422026/11/06 08:19:01 WARN Request failed, retrying attempt=5 backoff=1.596589431s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22432026/11/06 08:19:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22442026/11/06 08:19:01 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100300000000000000000000.nar.zst upload_id=MDQ1ZGRlY2MtMGQ3My00ZTczLThjZDEtYTVlZTc5OTIzMmFkLjYzNjJlNWJhLTEwMGItNDgyZC05OTQwLTg5MjRjZTY4OTljZngxNzkzOTUzMTQwMDAxNTYyMDAw parts=1022452026/11/06 08:19:01 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22462026/11/06 08:19:01 INFO Completed upload id=2 objects=3 duration=1.590917ms22472026/11/06 08:19:01 INFO Received uploads request method=POST path=/api/pending_closures22482026/11/06 08:19:01 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst22492026/11/06 08:19:01 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0003.narinfo22502026/11/06 08:19:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22512026/11/06 08:19:02 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100400000000000000000000.nar.zst upload_id=MDQ1ZGRlY2MtMGQ3My00ZTczLThjZDEtYTVlZTc5OTIzMmFkLmZiNzE1OGE5LWFlNWEtNDI2OC05MDFlLTdhNDU3MjNhZTViZngxNzkzOTUzMTQwOTI4ODIwMDAw parts=1022522026/11/06 08:19:02 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22532026/11/06 08:19:02 INFO Completed upload id=2 objects=3 duration=827.333µs22542026/11/06 08:19:02 INFO Received uploads request method=POST path=/api/pending_closures22552026/11/06 08:19:02 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst22562026/11/06 08:19:02 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0004.narinfo2257--- PASS: TestService_verifyS3ReuploadsStaleNarinfo (0.00s)2258 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed (7.62s)2259 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed (7.03s)2260 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed (6.99s)2261 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost (8.64s)2262 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed (8.20s)2263--- PASS: TestClientErrorHandling (0.00s)2264 --- PASS: TestClientErrorHandling/InvalidStorePath (6.29s)2265 --- PASS: TestClientErrorHandling/InvalidAuthToken (6.22s)2266 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.80s)2267=== NAME TestOrphanedObjectsGCStressTest2268 orphaned_objects_gc_test.go:503: Stress test completed successfully:2269 orphaned_objects_gc_test.go:504: - Active objects preserved: 202270 orphaned_objects_gc_test.go:505: - Objects deleted: 2102271 orphaned_objects_gc_test.go:506: - Total GC'd: 2102272--- PASS: TestOrphanedObjectsGCStressTest (29.60s)2273PASS2274{"timestamp":"2026-11-06T08:19:09.303888Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:57690","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(11)"}2275{"timestamp":"2026-11-06T08:19:09.305459Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:57505","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(5)"}22762026-11-06 08:19:09.447 UTC [1104] LOG: received smart shutdown request22772026-11-06 08:19:09.449 UTC [1104] LOG: background worker "logical replication launcher" (PID 1114) exited with exit code 122782026-11-06 08:19:09.456 UTC [1109] LOG: shutting down22792026-11-06 08:19:09.458 UTC [1109] LOG: checkpoint starting: shutdown immediate22802026-11-06 08:19:11.167 UTC [1109] LOG: checkpoint complete: wrote 12206 buffers (74.5%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.933 s, sync=0.709 s, total=1.711 s; sync files=36061, longest=0.017 s, average=0.001 s; distance=529949 kB, estimate=529949 kB; lsn=0/21D14420, redo lsn=0/21D1442022812026-11-06 08:19:11.178 UTC [1104] LOG: database system is shut down2282Running OIDC tests...2283=== RUN TestAudienceForIssuer2284=== PAUSE TestAudienceForIssuer2285=== RUN TestGlobMatch2286=== PAUSE TestGlobMatch2287=== RUN TestValidateToken_ValidToken2288=== PAUSE TestValidateToken_ValidToken2289=== RUN TestValidateToken_WrongAudience2290=== PAUSE TestValidateToken_WrongAudience2291=== RUN TestValidateToken_Expired2292=== PAUSE TestValidateToken_Expired2293=== RUN TestValidateToken_BoundClaimsMismatch2294=== PAUSE TestValidateToken_BoundClaimsMismatch2295=== RUN TestValidateToken_BoundSubjectMismatch2296=== PAUSE TestValidateToken_BoundSubjectMismatch2297=== RUN TestValidateToken_MultipleProviders2298=== PAUSE TestValidateToken_MultipleProviders2299=== RUN TestValidateToken_NoMatchingProvider2300=== PAUSE TestValidateToken_NoMatchingProvider2301=== RUN TestValidateToken_KubernetesServiceAccount2302=== PAUSE TestValidateToken_KubernetesServiceAccount2303=== RUN TestNewValidator_KubernetesRequiresCA2304=== PAUSE TestNewValidator_KubernetesRequiresCA2305=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2306=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2307=== RUN TestPins_ReservedForMatchingRule2308=== PAUSE TestPins_ReservedForMatchingRule2309=== RUN TestPins_TopLevelShorthand2310=== PAUSE TestPins_TopLevelShorthand2311=== RUN TestPins_ConfigValidation2312=== PAUSE TestPins_ConfigValidation2313=== RUN TestScopes_LegacyProviderDefaultsToWrite2314=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2315=== RUN TestScopes_Rules2316=== PAUSE TestScopes_Rules2317=== RUN TestScopes_ConfigValidation2318=== PAUSE TestScopes_ConfigValidation2319=== CONT TestAudienceForIssuer2320--- PASS: TestAudienceForIssuer (0.00s)2321=== CONT TestValidateToken_NoMatchingProvider2322=== CONT TestPins_ConfigValidation2323=== CONT TestValidateToken_Expired2324=== CONT TestValidateToken_KubernetesServiceAccount2325=== CONT TestPins_TopLevelShorthand2326=== CONT TestPins_ReservedForMatchingRule2327=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2328--- PASS: TestPins_ConfigValidation (0.01s)2329=== CONT TestNewValidator_KubernetesRequiresCA2330=== CONT TestScopes_Rules2331=== CONT TestScopes_ConfigValidation2332=== CONT TestScopes_LegacyProviderDefaultsToWrite2333--- PASS: TestScopes_ConfigValidation (0.00s)2334=== CONT TestValidateToken_ValidToken2335=== CONT TestValidateToken_WrongAudience2336=== CONT TestGlobMatch2337=== RUN TestGlobMatch/foo_foo2338=== PAUSE TestGlobMatch/foo_foo2339=== RUN TestGlobMatch/foo_bar2340=== PAUSE TestGlobMatch/foo_bar2341=== RUN TestGlobMatch/*_2342=== PAUSE TestGlobMatch/*_2343=== RUN TestGlobMatch/*_anything2344=== PAUSE TestGlobMatch/*_anything2345=== RUN TestGlobMatch/foo*_foo2346=== PAUSE TestGlobMatch/foo*_foo2347=== RUN TestGlobMatch/foo*_foobar2348=== PAUSE TestGlobMatch/foo*_foobar2349=== RUN TestGlobMatch/foo*_bar2350=== PAUSE TestGlobMatch/foo*_bar2351=== RUN TestGlobMatch/*bar_bar2352=== PAUSE TestGlobMatch/*bar_bar2353=== RUN TestGlobMatch/*bar_foobar2354=== PAUSE TestGlobMatch/*bar_foobar2355=== RUN TestGlobMatch/*bar_foo2356=== PAUSE TestGlobMatch/*bar_foo2357=== RUN TestGlobMatch/foo*bar_foobar2358=== PAUSE TestGlobMatch/foo*bar_foobar2359=== RUN TestGlobMatch/foo*bar_foo123bar2360=== PAUSE TestGlobMatch/foo*bar_foo123bar2361=== RUN TestGlobMatch/foo*bar_foobarbaz2362=== PAUSE TestGlobMatch/foo*bar_foobarbaz2363=== RUN TestGlobMatch/*/*_foo/bar2364=== PAUSE TestGlobMatch/*/*_foo/bar2365=== RUN TestGlobMatch/*/*_foo2366=== PAUSE TestGlobMatch/*/*_foo2367=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2368=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2369=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02370=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02371=== RUN TestGlobMatch/refs/*/main_refs/heads/main2372=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2373=== RUN TestGlobMatch/fo?_foo2374=== PAUSE TestGlobMatch/fo?_foo2375=== RUN TestGlobMatch/fo?_fo2376=== PAUSE TestGlobMatch/fo?_fo2377=== RUN TestGlobMatch/fo?_fooo2378=== PAUSE TestGlobMatch/fo?_fooo2379=== RUN TestGlobMatch/?oo_foo2380=== PAUSE TestGlobMatch/?oo_foo2381=== RUN TestGlobMatch/?oo_boo2382=== PAUSE TestGlobMatch/?oo_boo2383=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2384=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2385=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2386=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2387=== CONT TestGlobMatch/foo_foo2388=== CONT TestValidateToken_BoundSubjectMismatch2389=== CONT TestGlobMatch/*/*_foo/bar2390=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2391=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2392=== CONT TestGlobMatch/?oo_boo2393=== CONT TestGlobMatch/?oo_foo2394=== CONT TestGlobMatch/fo?_fooo2395=== CONT TestGlobMatch/fo?_fo2396=== CONT TestGlobMatch/fo?_foo2397=== CONT TestGlobMatch/refs/*/main_refs/heads/main2398=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02399=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2400=== CONT TestGlobMatch/*/*_foo2401=== CONT TestGlobMatch/*bar_bar2402=== CONT TestGlobMatch/foo*bar_foobarbaz2403=== CONT TestGlobMatch/foo*bar_foo123bar2404=== CONT TestGlobMatch/foo*bar_foobar2405=== CONT TestGlobMatch/*bar_foo2406=== CONT TestGlobMatch/*bar_foobar2407=== CONT TestGlobMatch/foo*_foo2408=== CONT TestGlobMatch/foo*_bar2409=== CONT TestGlobMatch/foo*_foobar2410=== CONT TestGlobMatch/*_2411=== CONT TestGlobMatch/*_anything2412=== CONT TestGlobMatch/foo_bar2413--- PASS: TestGlobMatch (0.00s)2414 --- PASS: TestGlobMatch/foo_foo (0.00s)2415 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2416 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2417 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2418 --- PASS: TestGlobMatch/?oo_boo (0.00s)2419 --- PASS: TestGlobMatch/?oo_foo (0.00s)2420 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2421 --- PASS: TestGlobMatch/fo?_fo (0.00s)2422 --- PASS: TestGlobMatch/fo?_foo (0.00s)2423 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2424 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2425 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2426 --- PASS: TestGlobMatch/*/*_foo (0.00s)2427 --- PASS: TestGlobMatch/*bar_bar (0.00s)2428 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2429 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2430 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2431 --- PASS: TestGlobMatch/*bar_foo (0.00s)2432 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2433 --- PASS: TestGlobMatch/foo*_foo (0.00s)2434 --- PASS: TestGlobMatch/foo*_bar (0.00s)2435 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2436 --- PASS: TestGlobMatch/*_ (0.00s)2437 --- PASS: TestGlobMatch/*_anything (0.00s)2438 --- PASS: TestGlobMatch/foo_bar (0.00s)2439=== CONT TestValidateToken_MultipleProviders2440=== CONT TestValidateToken_BoundClaimsMismatch24412026/11/06 08:19:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57872/oidc24422026/11/06 08:19:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57873/oidc2443--- PASS: TestScopes_Rules (0.06s)24442026/11/06 08:19:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57878/oidc2445--- PASS: TestValidateToken_BoundSubjectMismatch (0.07s)24462026/11/06 08:19:12 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:578802447--- PASS: TestValidateToken_Expired (0.10s)24482026/11/06 08:19:12 http: TLS handshake error from 127.0.0.1:57877: read tcp 127.0.0.1:57876->127.0.0.1:57877: use of closed network connection2449--- PASS: TestNewValidator_KubernetesRequiresCA (0.09s)24502026/11/06 08:19:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57883/oidc2451--- PASS: TestValidateToken_KubernetesServiceAccount (0.10s)24522026/11/06 08:19:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57885/oidc2453--- PASS: TestValidateToken_ValidToken (0.08s)2454--- PASS: TestValidateToken_BoundClaimsMismatch (0.08s)24552026/11/06 08:19:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57889/oidc2456--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.09s)24572026/11/06 08:19:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57891/oidc2458--- PASS: TestValidateToken_WrongAudience (0.09s)24592026/11/06 08:19:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57893/oidc2460--- PASS: TestPins_ReservedForMatchingRule (0.13s)24612026/11/06 08:19:12 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232462--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.13s)24632026/11/06 08:19:12 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:57897/oidc24642026/11/06 08:19:12 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:57888/oidc24652026/11/06 08:19:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57900/oidc2466--- PASS: TestValidateToken_MultipleProviders (0.13s)2467--- PASS: TestPins_TopLevelShorthand (0.16s)24682026/11/06 08:19:13 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:57882/oidc2469--- PASS: TestValidateToken_NoMatchingProvider (0.18s)2470PASS2471Running hook tests...2472=== RUN TestSendPathsEmpty2473=== PAUSE TestSendPathsEmpty2474=== RUN TestQueueEnqueueAndFetch2475=== PAUSE TestQueueEnqueueAndFetch2476=== RUN TestQueueDeduplication2477=== PAUSE TestQueueDeduplication2478=== RUN TestQueueRemove2479=== PAUSE TestQueueRemove2480=== RUN TestQueueFetchBatchLimit2481=== PAUSE TestQueueFetchBatchLimit2482=== RUN TestQueueRetryMovesToBack2483=== PAUSE TestQueueRetryMovesToBack2484=== RUN TestQueueFetchRemoveLifecycle2485=== PAUSE TestQueueFetchRemoveLifecycle2486=== RUN TestQueueConcurrentWriters2487=== PAUSE TestQueueConcurrentWriters2488=== RUN TestQueueRemoveLargeClosure2489=== PAUSE TestQueueRemoveLargeClosure2490=== RUN TestServerClientIntegration2491--- PASS: TestServerClientIntegration (0.00s)2492=== RUN TestServerQueueError24932026/11/06 08:19:13 ERROR Failed to queue paths error="permission denied" count=12494--- PASS: TestServerQueueError (0.00s)2495=== RUN TestGetListenerSocketActivation2496 server_test.go:145: systemd socket activation does not exist on darwin2497--- SKIP: TestGetListenerSocketActivation (0.00s)2498=== RUN TestServerStalledClientDoesNotBlockShutdown2499=== PAUSE TestServerStalledClientDoesNotBlockShutdown2500=== RUN TestServerBacksOffOnAcceptErrors2501=== PAUSE TestServerBacksOffOnAcceptErrors2502=== RUN TestDrainIsolatesPoisonPath2503=== PAUSE TestDrainIsolatesPoisonPath2504=== RUN TestRunNotBlockedByPoisonHead2505=== PAUSE TestRunNotBlockedByPoisonHead2506=== RUN TestDrainGivesUpWhenServerDown2507=== PAUSE TestDrainGivesUpWhenServerDown2508=== RUN TestFailedPathPrunedByLaterClosure2509=== PAUSE TestFailedPathPrunedByLaterClosure2510=== RUN TestWorkerUploadsAndRemoves2511=== PAUSE TestWorkerUploadsAndRemoves2512=== RUN TestWorkerSkipsGCdPaths2513=== PAUSE TestWorkerSkipsGCdPaths2514=== RUN TestWorkerPrunesClosureDeps2515=== PAUSE TestWorkerPrunesClosureDeps2516=== RUN TestDrainTimeout2517=== PAUSE TestDrainTimeout2518=== RUN TestWorkerRemoveFailureIsNotProgress2519=== PAUSE TestWorkerRemoveFailureIsNotProgress2520=== RUN TestWorkerKeepsPathItCannotStat2521=== PAUSE TestWorkerKeepsPathItCannotStat2522=== CONT TestSendPathsEmpty2523=== CONT TestDrainIsolatesPoisonPath2524--- PASS: TestSendPathsEmpty (0.00s)2525=== CONT TestServerBacksOffOnAcceptErrors2526=== CONT TestServerStalledClientDoesNotBlockShutdown25272026/11/06 08:19:13 ERROR Accept failed error="too many open files"2528=== CONT TestQueueRemoveLargeClosure2529=== CONT TestQueueConcurrentWriters2530=== CONT TestQueueRemove2531=== CONT TestQueueDeduplication2532=== CONT TestQueueFetchBatchLimit2533=== CONT TestQueueEnqueueAndFetch2534=== CONT TestWorkerSkipsGCdPaths2535=== CONT TestWorkerKeepsPathItCannotStat2536=== CONT TestQueueFetchRemoveLifecycle2537=== CONT TestWorkerRemoveFailureIsNotProgress2538=== CONT TestDrainTimeout2539=== CONT TestWorkerPrunesClosureDeps2540=== CONT TestQueueRetryMovesToBack2541=== CONT TestFailedPathPrunedByLaterClosure2542=== CONT TestWorkerUploadsAndRemoves2543=== CONT TestDrainGivesUpWhenServerDown2544=== CONT TestRunNotBlockedByPoisonHead25452026/11/06 08:19:13 ERROR Accept failed error="too many open files"25462026/11/06 08:19:13 INFO Upload queue status pending=225472026/11/06 08:19:13 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestWorkerSkipsGCdPaths2529063204/002/nonexistent25482026/11/06 08:19:13 INFO Uploading batch count=125492026/11/06 08:19:13 INFO Uploading batch count=225502026/11/06 08:19:13 INFO Uploading batch count=425512026/11/06 08:19:13 ERROR Upload failed error="upload failed" count=42552--- PASS: TestQueueFetchBatchLimit (0.01s)25532026/11/06 08:19:13 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestDrainIsolatesPoisonPath3894376941/002/bbb25542026/11/06 08:19:13 INFO Upload queue status pending=225552026/11/06 08:19:13 INFO Uploading batch count=225562026/11/06 08:19:13 ERROR Accept failed error="too many open files"25572026/11/06 08:19:13 WARN Cannot stat store path, will retry later path=/private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestWorkerKeepsPathItCannotStat3992306813/002/locked/aaa error="stat /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestWorkerKeepsPathItCannotStat3992306813/002/locked/aaa: permission denied"25582026/11/06 08:19:13 INFO Uploading batch count=125592026/11/06 08:19:13 ERROR Upload failed error="upload failed" count=125602026/11/06 08:19:13 INFO Upload queue status pending=225612026/11/06 08:19:13 INFO Uploading batch count=125622026/11/06 08:19:13 INFO Uploading batch count=125632026/11/06 08:19:13 ERROR Upload failed error="upload failed" count=125642026/11/06 08:19:13 INFO Uploading batch count=125652026/11/06 08:19:13 ERROR Upload failed error="upload failed" count=12566--- PASS: TestQueueEnqueueAndFetch (0.02s)25672026/11/06 08:19:13 INFO Upload queue status pending=325682026/11/06 08:19:13 ERROR Drain finished with paths left in queue remaining=125692026/11/06 08:19:13 WARN Cannot stat store path, will retry later path=/private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestWorkerKeepsPathItCannotStat3992306813/002/locked/aaa error="stat /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestWorkerKeepsPathItCannotStat3992306813/002/locked/aaa: permission denied"2570--- PASS: TestQueueDeduplication (0.02s)25712026/11/06 08:19:13 INFO Uploading batch count=125722026/11/06 08:19:13 ERROR Upload failed error="upload failed" count=125732026/11/06 08:19:13 WARN Cannot stat store path, will retry later path=/private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestWorkerKeepsPathItCannotStat3992306813/002/locked/aaa error="stat /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestWorkerKeepsPathItCannotStat3992306813/002/locked/aaa: permission denied"25742026/11/06 08:19:13 INFO Uploading batch count=125752026/11/06 08:19:13 ERROR Upload failed error="upload failed" count=125762026/11/06 08:19:13 INFO Uploading batch count=125772026/11/06 08:19:13 INFO Uploading batch count=225782026/11/06 08:19:13 ERROR Upload failed error="upload failed" count=225792026/11/06 08:19:13 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestDrainGivesUpWhenServerDown2996211247/002/a25802026/11/06 08:19:13 INFO Uploading batch count=125812026/11/06 08:19:13 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestDrainGivesUpWhenServerDown2996211247/002/b25822026/11/06 08:19:13 ERROR Drain finished with paths left in queue remaining=12583--- PASS: TestQueueFetchRemoveLifecycle (0.02s)2584--- PASS: TestDrainIsolatesPoisonPath (0.02s)25852026/11/06 08:19:13 INFO Uploading batch count=225862026/11/06 08:19:13 ERROR Upload failed error="upload failed" count=225872026/11/06 08:19:13 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestDrainGivesUpWhenServerDown2996211247/002/c25882026/11/06 08:19:13 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestDrainGivesUpWhenServerDown2996211247/002/d2589--- PASS: TestWorkerKeepsPathItCannotStat (0.02s)25902026/11/06 08:19:13 INFO Uploading batch count=225912026/11/06 08:19:13 ERROR Upload failed error="upload failed" count=225922026/11/06 08:19:13 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestDrainGivesUpWhenServerDown2996211247/002/e2593--- PASS: TestQueueRemove (0.02s)25942026/11/06 08:19:13 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestDrainGivesUpWhenServerDown2996211247/002/f2595--- PASS: TestQueueRetryMovesToBack (0.02s)25962026/11/06 08:19:13 ERROR Drain finished with paths left in queue remaining=102597--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)25982026/11/06 08:19:13 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestWorkerRemoveFailureIsNotProgress3141056310/002/nonexistent25992026/11/06 08:19:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=126002026/11/06 08:19:13 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestWorkerRemoveFailureIsNotProgress3141056310/002/nonexistent26012026/11/06 08:19:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=126022026/11/06 08:19:13 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestWorkerRemoveFailureIsNotProgress3141056310/002/nonexistent26032026/11/06 08:19:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=126042026/11/06 08:19:13 ERROR Drain finished with paths left in queue remaining=12605--- PASS: TestWorkerRemoveFailureIsNotProgress (0.02s)2606--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2607--- PASS: TestWorkerSkipsGCdPaths (0.03s)2608--- PASS: TestWorkerUploadsAndRemoves (0.03s)26092026/11/06 08:19:13 ERROR Accept failed error="too many open files"2610--- PASS: TestWorkerPrunesClosureDeps (0.03s)2611--- PASS: TestQueueRemoveLargeClosure (0.04s)2612--- PASS: TestQueueConcurrentWriters (0.04s)26132026/11/06 08:19:13 ERROR Accept failed error="too many open files"26142026/11/06 08:19:13 ERROR Accept failed error="too many open files"26152026/11/06 08:19:13 ERROR Failed to decode request error="read unix /private/var/tb/3/scratch/8e9e0b393d193e6f/build/hook2050510127/test.sock->: i/o timeout"26162026/11/06 08:19:13 ERROR Failed to write response error="write unix /private/var/tb/3/scratch/8e9e0b393d193e6f/build/hook2050510127/test.sock->: i/o timeout"2617--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)26182026/11/06 08:19:13 ERROR Upload failed error="context deadline exceeded" count=226192026/11/06 08:19:13 ERROR Drain finished with paths left in queue remaining=42620--- PASS: TestDrainTimeout (0.21s)26212026/11/06 08:19:13 ERROR Accept failed error="too many open files"26222026/11/06 08:19:13 ERROR Accept failed error="too many open files"2623--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)26242026/11/06 08:19:14 INFO Uploading batch count=126252026/11/06 08:19:14 INFO Uploading batch count=126262026/11/06 08:19:14 INFO Uploading batch count=126272026/11/06 08:19:14 ERROR Upload failed error="upload failed" count=126282026/11/06 08:19:14 INFO Uploading batch count=126292026/11/06 08:19:14 ERROR Upload failed error="upload failed" count=126302026/11/06 08:19:14 INFO Uploading batch count=126312026/11/06 08:19:14 ERROR Upload failed error="upload failed" count=126322026/11/06 08:19:14 INFO Uploading batch count=126332026/11/06 08:19:14 ERROR Upload failed error="upload failed" count=126342026/11/06 08:19:14 ERROR Drain finished with paths left in queue remaining=12635--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2636PASS2637Running signing tests...2638=== RUN TestExternalSigner2639=== PAUSE TestExternalSigner2640=== RUN TestExternalSignerWrongPublicKey2641=== PAUSE TestExternalSignerWrongPublicKey2642=== RUN TestExternalSignerErrors2643=== PAUSE TestExternalSignerErrors2644=== RUN TestExternalSignerRestartsAfterCrash2645=== PAUSE TestExternalSignerRestartsAfterCrash2646=== RUN TestExternalSignerProgramErrorKeepsProcess2647=== PAUSE TestExternalSignerProgramErrorKeepsProcess2648=== RUN TestExternalSignerClose2649=== PAUSE TestExternalSignerClose2650=== RUN TestExternalSignerRejectsInvalidPublicKey2651=== PAUSE TestExternalSignerRejectsInvalidPublicKey2652=== RUN TestExternalSignerCancellation2653=== PAUSE TestExternalSignerCancellation2654=== RUN TestGenerateFingerprint2655=== PAUSE TestGenerateFingerprint2656=== RUN TestParseSigningKey2657=== PAUSE TestParseSigningKey2658=== RUN TestSign2659=== PAUSE TestSign2660=== RUN TestSignBatch2661=== PAUSE TestSignBatch2662=== RUN TestNilKeyPublicKey2663=== PAUSE TestNilKeyPublicKey2664=== RUN TestSignErrors2665=== PAUSE TestSignErrors2666=== CONT TestExternalSigner2667=== CONT TestExternalSignerProgramErrorKeepsProcess2668=== CONT TestSignBatch2669=== CONT TestExternalSignerErrors2670=== RUN TestExternalSignerErrors/exit_on_request2671=== CONT TestParseSigningKey2672=== PAUSE TestExternalSignerErrors/exit_on_request2673=== RUN TestExternalSignerErrors/null2674=== CONT TestGenerateFingerprint2675=== CONT TestExternalSignerRejectsInvalidPublicKey2676=== RUN TestGenerateFingerprint/basic_with_references2677=== CONT TestExternalSignerCancellation2678=== PAUSE TestGenerateFingerprint/basic_with_references2679=== RUN TestGenerateFingerprint/no_references2680=== PAUSE TestGenerateFingerprint/no_references2681=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2682=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2683=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2684=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2685=== RUN TestGenerateFingerprint/invalid_nar_hash_length2686=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2687=== RUN TestGenerateFingerprint/invalid_store_path_prefix2688=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2689=== RUN TestGenerateFingerprint/invalid_reference_prefix2690=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2691=== CONT TestGenerateFingerprint/basic_with_references2692=== CONT TestGenerateFingerprint/invalid_reference_prefix2693=== CONT TestGenerateFingerprint/invalid_store_path_prefix2694=== CONT TestGenerateFingerprint/invalid_nar_hash_length2695=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2696=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2697=== CONT TestGenerateFingerprint/no_references2698--- PASS: TestGenerateFingerprint (0.00s)2699 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2700 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2701 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2702 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2703 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2704 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2705 --- PASS: TestGenerateFingerprint/no_references (0.00s)2706=== RUN TestExternalSignerRejectsInvalidPublicKey/#002707=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002708=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2709=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2710=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2711=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2712=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2713=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2714=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2715=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2716=== CONT TestExternalSignerRejectsInvalidPublicKey/#002717=== CONT TestSignErrors2718=== CONT TestSign2719=== CONT TestExternalSignerRestartsAfterCrash2720=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2721=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2722=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2723=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2724--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2725 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2726 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2727 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2728 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2729 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2730=== RUN TestParseSigningKey/valid_32-byte_key2731=== PAUSE TestParseSigningKey/valid_32-byte_key2732=== CONT TestNilKeyPublicKey2733--- PASS: TestNilKeyPublicKey (0.00s)2734=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2735=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2736=== RUN TestParseSigningKey/no_colon2737=== CONT TestExternalSignerClose2738=== PAUSE TestParseSigningKey/no_colon2739=== RUN TestParseSigningKey/empty_name2740=== PAUSE TestParseSigningKey/empty_name2741=== RUN TestParseSigningKey/invalid_base642742=== PAUSE TestParseSigningKey/invalid_base642743=== RUN TestParseSigningKey/wrong_length2744=== PAUSE TestParseSigningKey/wrong_length2745=== CONT TestParseSigningKey/valid_32-byte_key2746=== CONT TestParseSigningKey/wrong_length2747=== CONT TestParseSigningKey/invalid_base642748=== CONT TestParseSigningKey/empty_name2749=== CONT TestParseSigningKey/no_colon2750=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2751=== CONT TestExternalSignerWrongPublicKey2752=== PAUSE TestExternalSignerErrors/null2753=== RUN TestExternalSignerErrors/too_few_signatures2754=== PAUSE TestExternalSignerErrors/too_few_signatures2755=== RUN TestExternalSignerErrors/unrequested_key2756=== PAUSE TestExternalSignerErrors/unrequested_key2757=== RUN TestExternalSignerErrors/missing_signature_name2758=== PAUSE TestExternalSignerErrors/missing_signature_name2759=== RUN TestExternalSignerErrors/exit_at_startup2760=== PAUSE TestExternalSignerErrors/exit_at_startup2761=== RUN TestExternalSignerErrors/missing_signatures2762=== PAUSE TestExternalSignerErrors/missing_signatures2763=== RUN TestExternalSignerErrors/null_signatures2764=== PAUSE TestExternalSignerErrors/null_signatures2765=== RUN TestExternalSignerErrors/wrong_signatures_shape2766=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2767=== RUN TestExternalSignerErrors/program_error2768=== PAUSE TestExternalSignerErrors/program_error2769=== RUN TestExternalSignerErrors/invalid_JSON2770=== PAUSE TestExternalSignerErrors/invalid_JSON2771=== RUN TestExternalSignerErrors/wrong_shape2772=== PAUSE TestExternalSignerErrors/wrong_shape2773=== RUN TestExternalSignerErrors/wrong_id2774=== PAUSE TestExternalSignerErrors/wrong_id2775=== RUN TestExternalSignerErrors/invalid_signature_base642776=== PAUSE TestExternalSignerErrors/invalid_signature_base642777=== RUN TestExternalSignerErrors/wrong_signature_name2778=== PAUSE TestExternalSignerErrors/wrong_signature_name2779=== RUN TestExternalSignerErrors/wrong_signature_length2780=== PAUSE TestExternalSignerErrors/wrong_signature_length2781=== CONT TestExternalSignerErrors/exit_on_request2782--- PASS: TestSign (0.00s)2783--- PASS: TestParseSigningKey (0.00s)2784 --- PASS: TestParseSigningKey/wrong_length (0.00s)2785 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2786 --- PASS: TestParseSigningKey/empty_name (0.00s)2787 --- PASS: TestParseSigningKey/no_colon (0.00s)2788 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2789 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2790=== CONT TestExternalSignerErrors/program_error2791=== CONT TestExternalSignerErrors/exit_at_startup2792--- PASS: TestSignBatch (0.00s)2793=== CONT TestExternalSignerErrors/null_signatures2794=== CONT TestExternalSignerErrors/invalid_signature_base642795=== CONT TestExternalSignerErrors/wrong_id2796=== CONT TestExternalSignerErrors/missing_signature_name2797=== CONT TestExternalSignerErrors/too_few_signatures2798=== CONT TestExternalSignerErrors/wrong_signatures_shape2799=== CONT TestExternalSignerErrors/wrong_signature_length2800=== CONT TestExternalSignerErrors/null2801=== CONT TestExternalSignerErrors/wrong_signature_name2802=== CONT TestExternalSignerErrors/wrong_shape2803=== CONT TestExternalSignerErrors/invalid_JSON2804=== CONT TestExternalSignerErrors/missing_signatures2805=== CONT TestExternalSignerErrors/unrequested_key2806=== RUN TestSignErrors/nil_key2807=== PAUSE TestSignErrors/nil_key2808=== RUN TestSignErrors/nil_narinfo2809=== PAUSE TestSignErrors/nil_narinfo2810=== RUN TestSignErrors/invalid_narinfo2811=== PAUSE TestSignErrors/invalid_narinfo2812=== RUN TestSignErrors/canceled2813=== PAUSE TestSignErrors/canceled2814=== CONT TestSignErrors/nil_key2815=== CONT TestSignErrors/canceled2816=== CONT TestSignErrors/invalid_narinfo2817=== CONT TestSignErrors/nil_narinfo2818--- PASS: TestSignErrors (0.00s)2819 --- PASS: TestSignErrors/nil_key (0.00s)2820 --- PASS: TestSignErrors/canceled (0.00s)2821 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2822 --- PASS: TestSignErrors/nil_narinfo (0.00s)2823--- PASS: TestExternalSignerCancellation (0.11s)2824--- PASS: TestExternalSignerRestartsAfterCrash (0.19s)2825/private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestExternalSignerRestartsAfterCrash2734423582/001/sign program: line 7: /private/var/tb/3/scratch/8e9e0b393d193e6f/build/TestExternalSignerRestartsAfterCrash2734423582/001/sign program.starts: No such file or directory2826--- PASS: TestExternalSigner (0.50s)2827--- PASS: TestExternalSignerClose (0.57s)2828--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.72s)2829--- PASS: TestExternalSignerWrongPublicKey (0.95s)2830--- PASS: TestExternalSignerErrors (0.00s)2831 --- PASS: TestExternalSignerErrors/exit_at_startup (0.25s)2832 --- PASS: TestExternalSignerErrors/missing_signature_name (0.33s)2833 --- PASS: TestExternalSignerErrors/exit_on_request (0.40s)2834 --- PASS: TestExternalSignerErrors/program_error (0.64s)2835 --- PASS: TestExternalSignerErrors/too_few_signatures (0.80s)2836 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.87s)2837 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (1.03s)2838 --- PASS: TestExternalSignerErrors/null_signatures (1.10s)2839 --- PASS: TestExternalSignerErrors/null (1.18s)2840 --- PASS: TestExternalSignerErrors/wrong_shape (1.25s)2841 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (1.33s)2842 --- PASS: TestExternalSignerErrors/unrequested_key (1.41s)2843 --- PASS: TestExternalSignerErrors/invalid_JSON (1.49s)2844 --- PASS: TestExternalSignerErrors/missing_signatures (1.56s)2845 --- PASS: TestExternalSignerErrors/wrong_signature_length (1.64s)2846 --- PASS: TestExternalSignerErrors/wrong_id (1.72s)2847PASS2848Running OpenBao signer tests...2849=== RUN TestSign2850=== PAUSE TestSign2851=== RUN TestSignErrors2852=== PAUSE TestSignErrors2853=== RUN TestServe2854=== PAUSE TestServe2855=== RUN TestServeRejectsGarbage2856=== PAUSE TestServeRejectsGarbage2857=== CONT TestSign2858=== CONT TestServeRejectsGarbage2859=== CONT TestSignErrors2860=== RUN TestSignErrors/invalid_base642861=== CONT TestServe2862=== PAUSE TestSignErrors/invalid_base642863=== RUN TestSignErrors/http_error2864--- PASS: TestServeRejectsGarbage (0.00s)2865=== PAUSE TestSignErrors/http_error2866=== RUN TestSignErrors/invalid_json2867=== PAUSE TestSignErrors/invalid_json2868=== RUN TestSignErrors/no_prefix2869=== PAUSE TestSignErrors/no_prefix2870=== CONT TestSignErrors/invalid_base642871=== CONT TestSignErrors/invalid_json2872=== CONT TestSignErrors/http_error2873=== CONT TestSignErrors/no_prefix2874--- PASS: TestServe (0.00s)2875--- PASS: TestSignErrors (0.00s)2876 --- PASS: TestSignErrors/invalid_base64 (0.00s)2877 --- PASS: TestSignErrors/no_prefix (0.00s)2878 --- PASS: TestSignErrors/invalid_json (0.00s)2879 --- PASS: TestSignErrors/http_error (0.00s)2880--- PASS: TestSign (0.00s)2881PASS