niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #472
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestUploadMultipart_PartsInParallel18=== PAUSE TestUploadMultipart_PartsInParallel19=== RUN TestUploadMultipart_ReturnsAfterDroppedBody20=== PAUSE TestUploadMultipart_ReturnsAfterDroppedBody21=== RUN TestPartSizeForNAR22=== PAUSE TestPartSizeForNAR23=== RUN TestDumpPathCaseHackMatchesNix24--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)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 TestRetryTimeoutOutlastsMaxRetries115=== CONT TestEncodeNixBase32WithRealHash116--- PASS: TestEncodeNixBase32WithRealHash (0.00s)117=== CONT TestDoWithRetry_BodyReplayedViaGetBody118=== CONT TestResolveStorePath119=== CONT TestRegisterUploadedObject_OutlivesPush120=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer121=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess122--- PASS: TestResolveStorePath (0.00s)123=== CONT TestScriptTokenNoExpiryRerunsEveryCall124=== CONT TestRateLimiterFeedback125=== RUN TestRateLimiterFeedback/429_enables_limiter126=== PAUSE TestRateLimiterFeedback/429_enables_limiter127=== RUN TestRateLimiterFeedback/503_enables_limiter128=== PAUSE TestRateLimiterFeedback/503_enables_limiter129=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter130=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter131=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter1322026/11/09 12:01:14 WARN Rate limiter enabled after throttle name=server-test rate=5133=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter134=== CONT TestPathInfoCACompatibility135=== RUN TestPathInfoCACompatibility/null_ca_field136=== PAUSE TestPathInfoCACompatibility/null_ca_field137=== RUN TestPathInfoCACompatibility/old_string_format_-_text138=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text139=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive140=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive141=== RUN TestPathInfoCACompatibility/new_structured_format_-_text142=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text143=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method144=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method145=== CONT TestFileTokenEmpty146=== CONT TestParsePathInfoJSONMultiplePaths147=== CONT TestParsePathInfoJSON148=== CONT TestPathInfoHashCompatibility149=== CONT TestGetStorePathHash150=== RUN TestGetStorePathHash/valid_store_path151=== CONT TestConvertHashToNix32152=== CONT TestDumpPathSingleFile153=== CONT TestEncodeNixBase32154=== CONT TestDumpPathWriterError155=== CONT TestSetClientTLS156=== CONT TestScriptTokenEmptyCommand157=== CONT TestScriptTokenScriptFails158=== CONT TestScriptTokenBadJSON159=== CONT TestScriptTokenEmptyToken160=== CONT TestUploadMultipart_PartsInParallel161=== CONT TestScriptTokenCachesUntilRefresh162=== CONT TestFileTokenMissing163=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths164=== RUN TestParsePathInfoJSON/Nix_format165=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)166=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)167=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon168=== PAUSE TestGetStorePathHash/valid_store_path169=== PAUSE TestParsePathInfoJSON/Nix_format170=== RUN TestConvertHashToNix32/SRI_format_to_Nix32171=== RUN TestEncodeNixBase32/test_string_hash172--- PASS: TestFileTokenEmpty (0.00s)173=== RUN TestGetStorePathHash/basename_without_hyphen_should_error174=== CONT TestStaticToken175=== CONT TestSetClientTLSErrors176--- PASS: TestFileTokenMissing (0.00s)177=== CONT TestFileTokenReadsAndCaches178=== RUN TestParsePathInfoJSON/Lix_format179--- PASS: TestScriptTokenEmptyCommand (0.00s)180--- PASS: TestStaticToken (0.00s)181=== PAUSE TestEncodeNixBase32/test_string_hash182=== RUN TestEncodeNixBase32/empty_input183=== PAUSE TestEncodeNixBase32/empty_input184=== CONT TestDumpPathMatchesNix185=== CONT TestSetClientTLSDoesNotMutateDefaultTransport186=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon187=== CONT TestStreamPushGivesUpOnDeadServer188=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32189=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error190=== PAUSE TestParsePathInfoJSON/Lix_format191=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths192=== CONT TestStreamPushStopsWhenCanceled193=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths194--- PASS: TestScriptTokenScriptFails (0.00s)195--- PASS: TestFileTokenReadsAndCaches (0.00s)196--- PASS: TestStreamPushStopsWhenCanceled (0.00s)197=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI198=== RUN TestConvertHashToNix32/already_Nix32_format199=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI200--- PASS: TestScriptTokenEmptyToken (0.00s)201--- PASS: TestScriptTokenBadJSON (0.00s)202=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths203=== CONT TestUploadMultipart_ReturnsAfterDroppedBody2042026/11/09 12:01:14 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:33697205=== CONT TestPartSizeForNAR206=== CONT TestClientSignaturesByStorePath207--- PASS: TestClientSignaturesByStorePath (0.00s)208=== CONT TestStreamPushReportsSignatures209--- PASS: TestRegisterUploadedObject_OutlivesPush (0.09s)210=== CONT TestStreamPushReportsSkippedPaths211=== PAUSE TestConvertHashToNix32/already_Nix32_format212=== CONT TestStreamPushRequestLine213--- PASS: TestDoServerRequestAttachesToken (0.09s)214=== CONT TestFilterOversizedClosures215=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error2162026/11/09 12:01:14 ERROR Upload failed error="connection refused" count=202172026/11/09 12:01:14 ERROR Server seems unavailable, giving up on batch untried=17218=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error219=== CONT TestRegisterUploadedObjectReusesConnections2202026/11/09 12:01:14 WARN Rate limiter enabled after throttle name=server-test rate=5221=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica2222026/11/09 12:01:14 ERROR Upload failed error=boom count=1223=== CONT TestStreamPushReportsEveryPath224=== RUN TestParsePathInfoJSON/empty_input2252026/11/09 12:01:14 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:44033226=== CONT TestShellSplit227=== PAUSE TestParsePathInfoJSON/empty_input228=== CONT TestStreamPushIsolatesFailures229=== RUN TestParsePathInfoJSON/whitespace_only2302026/11/09 12:01:14 ERROR Upload failed error=boom count=1231=== PAUSE TestParsePathInfoJSON/whitespace_only232=== RUN TestParsePathInfoJSON/invalid_JSON233=== PAUSE TestParsePathInfoJSON/invalid_JSON234=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512235=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512236=== CONT TestShellSplitErrors237=== CONT TestDoWithRetry_FinalResponseBodyReadable2382026/11/09 12:01:14 WARN Rate limiter backed off name=server-test rate=52392026/11/09 12:01:14 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:44033240=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry241=== RUN TestSetClientTLSErrors/missing_cert_file242=== PAUSE TestSetClientTLSErrors/missing_cert_file243=== RUN TestSetClientTLSErrors/missing_key_file244=== PAUSE TestSetClientTLSErrors/missing_key_file245=== RUN TestSetClientTLSErrors/missing_ca_file2462026/11/09 12:01:14 ERROR Upload failed error="bad path" count=3247=== PAUSE TestSetClientTLSErrors/missing_ca_file248=== RUN TestSetClientTLSErrors/invalid_ca_file249=== PAUSE TestSetClientTLSErrors/invalid_ca_file250=== CONT TestRateLimiterFeedback/429_enables_limiter251--- PASS: TestStreamPushReportsSkippedPaths (0.00s)252--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.08s)253--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.09s)254--- PASS: TestStreamPushGivesUpOnDeadServer (0.08s)255--- PASS: TestStreamPushReportsEveryPath (0.00s)256--- PASS: TestShellSplit (0.00s)257--- PASS: TestShellSplitErrors (0.00s)258--- PASS: TestStreamPushReportsSignatures (0.00s)259--- PASS: TestStreamPushIsolatesFailures (0.00s)260=== CONT TestStreamPushBatchesUnderLoad261=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false262=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false263=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true264=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true265=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun266=== RUN TestPartSizeForNAR/zero_stays_at_minimum267=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum268=== CONT TestPathInfoCACompatibility/null_ca_field269=== CONT TestCaseHackSuffix270--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.09s)271=== RUN TestPartSizeForNAR/small_stays_at_minimum272=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter2732026/11/09 12:01:14 INFO Garbage collection started2742026/11/09 12:01:14 WARN Rate limiter enabled after throttle name=server-test rate=52752026/11/09 12:01:14 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:37541276=== PAUSE TestPartSizeForNAR/small_stays_at_minimum277=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum278=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum279=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts280=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts281=== RUN TestPartSizeForNAR/1_TiB282=== PAUSE TestPartSizeForNAR/1_TiB283=== RUN TestPartSizeForNAR/5_TiB_S3_max_object284=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object285=== RUN TestPartSizeForNAR/capped_at_5_GiB286=== PAUSE TestPartSizeForNAR/capped_at_5_GiB287=== RUN TestConvertHashToNix32/invalid_format288=== PAUSE TestConvertHashToNix32/invalid_format2892026/11/09 12:01:14 WARN Rate limiter backed off name=server-test rate=5290=== RUN TestSetClientTLS/rejects_connection_without_client_cert291=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert2922026/11/09 12:01:14 WARN Rate limiter enabled after throttle name=server-test rate=5293=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA2942026/11/09 12:01:14 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:33261295=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA296=== CONT TestRateLimiterFeedback/503_enables_limiter297=== RUN TestSetClientTLS/preserves_debug_logging_transport298=== PAUSE TestSetClientTLS/preserves_debug_logging_transport299=== CONT TestEncodeNixBase32/test_string_hash300=== CONT TestEncodeNixBase32/empty_input301=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths3022026/11/09 12:01:14 INFO Garbage collection started303=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths3042026/11/09 12:01:14 WARN Rate limiter backed off name=server-test rate=5305=== CONT TestParsePathInfoJSON/Nix_format306=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)307=== CONT TestParsePathInfoJSON/invalid_JSON308=== CONT TestParsePathInfoJSON/whitespace_only309=== CONT TestParsePathInfoJSON/empty_input310=== CONT TestParsePathInfoJSON/Lix_format311=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512312=== CONT TestSetClientTLSErrors/missing_cert_file313=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter314=== CONT TestPathInfoCACompatibility/old_string_format_-_text315=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon316=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false317=== CONT TestSetClientTLSErrors/missing_ca_file3182026/11/09 12:01:14 WARN Rate limiter enabled after throttle name=server-test rate=5319=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI3202026/11/09 12:01:14 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:41249321=== CONT TestSetClientTLSErrors/invalid_ca_file322=== CONT TestSetClientTLSErrors/missing_key_file323=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true3242026/11/09 12:01:14 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=0325=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error3262026/11/09 12:01:14 WARN Rate limiter backed off name=server-test rate=5327=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error328=== RUN TestFilterOversizedClosures/no_limit_keeps_everything329=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything3302026/11/09 12:01:14 WARN Rate limiter enabled after throttle name=s3-test rate=5331=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3322026/11/09 12:01:14 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:34687333=== CONT TestPathInfoCACompatibility/new_structured_format_-_text334--- PASS: TestUploadMultipart_ReturnsAfterDroppedBody (0.08s)335=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive336=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method3372026/11/09 12:01:14 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:33697338=== CONT TestConvertHashToNix32/SRI_format_to_Nix32339=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum340=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA341=== CONT TestPartSizeForNAR/zero_stays_at_minimum3422026/11/09 12:01:14 WARN Garbage collection finished on another replica. Its statistics are not available here343=== CONT TestSetClientTLS/preserves_debug_logging_transport344=== CONT TestPartSizeForNAR/capped_at_5_GiB345=== CONT TestPartSizeForNAR/5_TiB_S3_max_object346=== CONT TestPartSizeForNAR/1_TiB347=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped348=== CONT TestGetStorePathHash/basename_without_hyphen_should_error349=== CONT TestConvertHashToNix32/invalid_format350=== CONT TestPartSizeForNAR/small_stays_at_minimum351--- PASS: TestEncodeNixBase32 (0.00s)352 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)353 --- PASS: TestEncodeNixBase32/empty_input (0.00s)354--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.00s)355=== CONT TestConvertHashToNix32/already_Nix32_format3562026/11/09 12:01:14 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:33697357=== CONT TestSetClientTLS/rejects_connection_without_client_cert358=== CONT TestGetStorePathHash/valid_store_path359=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error360=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error361=== RUN TestFilterOversizedClosures/all_closures_skipped362=== PAUSE TestFilterOversizedClosures/all_closures_skipped363=== CONT TestFilterOversizedClosures/no_limit_keeps_everything364=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3652026/11/09 12:01:14 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=2000366=== CONT TestFilterOversizedClosures/all_closures_skipped3672026/11/09 12:01:14 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=50368--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)369--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.00s)370=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts371--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)372--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)373 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)374 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)375--- PASS: TestStreamPushBatchesUnderLoad (0.00s)376 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)377 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)378--- PASS: TestPathInfoHashCompatibility (0.08s)379 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)380 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)381 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)382 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)383--- PASS: TestParsePathInfoJSON (0.08s)384 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)385 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)386 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)387 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)388 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)389--- PASS: TestConvertHashToNix32 (0.09s)390 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)391 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)392 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)393--- PASS: TestGetStorePathHash (0.09s)394 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)395 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)396 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)397 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)398--- PASS: TestSetClientTLSErrors (0.08s)399 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)400 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)401 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)402 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)403--- PASS: TestScriptTokenCachesUntilRefresh (0.08s)404--- PASS: TestFilterOversizedClosures (0.01s)405 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)406 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)407 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)408--- PASS: TestRateLimiterFeedback (0.00s)409 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)410 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)411 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)412 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)4132026/11/09 12:01:14 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:33697414--- PASS: TestPathInfoCACompatibility (0.00s)415 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)416 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)417 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)418 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)419 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)420--- PASS: TestPartSizeForNAR (0.00s)421 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)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/small_stays_at_minimum (0.00s)427 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)4282026/11/09 12:01:14 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:336974292026/11/09 12:01:14 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:336974302026/11/09 12:01:14 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:35677/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:35677/api/uploads/complete4312026/11/09 12:01:14 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4322026/11/09 12:01:14 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:35677/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:35677/api/uploads/complete4332026/11/09 12:01:14 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4342026/11/09 12:01:14 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:35677/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:35677/api/uploads/complete4352026/11/09 12:01:14 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4362026/11/09 12:01:14 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:33697437--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (0.11s)4382026/11/09 12:01:14 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:336974392026/11/09 12:01:14 http: TLS handshake error from 127.0.0.1:52904: remote error: tls: bad certificate440--- PASS: TestSetClientTLS (0.09s)441 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)442 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)443 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)4442026/11/09 12:01:14 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:33697445--- PASS: TestStreamPushRequestLine (0.02s)4462026/11/09 12:01:14 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:336974472026/11/09 12:01:14 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:336974482026/11/09 12:01:14 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:336974492026/11/09 12:01:14 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:336974502026/11/09 12:01:14 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:336974512026/11/09 12:01:14 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:336974522026/11/09 12:01:14 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:336974532026/11/09 12:01:14 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:33697454--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)4552026/11/09 12:01:14 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:33697456--- PASS: TestDumpPathSingleFile (0.12s)457--- PASS: TestDumpPathWriterError (0.12s)4582026/11/09 12:01:14 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:33697459--- PASS: TestCaseHackSuffix (0.04s)460--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.12s)461--- PASS: TestDumpPathMatchesNix (0.17s)462--- PASS: TestUploadMultipart_PartsInParallel (0.71s)463--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)464PASS465Running server tests...466The files belonging to this database system will be owned by user "nixbld".467This user must also own the server process.468469The database cluster will be initialized with locale "C".470The default database encoding has accordingly been set to "SQL_ASCII".471The default text search configuration will be set to "english".472473Data page checksums are enabled.474475creating directory /build/postgres3741922677/data ... ok476creating subdirectories ... ok477selecting dynamic shared memory implementation ... posix478selecting default "max_connections" ... 100479selecting default "shared_buffers" ... 128MB480selecting default time zone ... UTC481creating configuration files ... ok482running bootstrap script ... ok483performing post-bootstrap initialization ... ok484syncing data to disk ... ok485486initdb: warning: enabling "trust" authentication for local connections487initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.488489Success. You can now start the database server using:490491 pg_ctl -D /build/postgres3741922677/data -l logfile start492493/build/postgres3741922677:5432 - no response4942026-11-09 12:01:15.939 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4952026-11-09 12:01:15.940 UTC [129] LOG: listening on Unix socket "/build/postgres3741922677/.s.PGSQL.5432"4962026-11-09 12:01:15.945 UTC [136] LOG: database system was shut down at 2026-11-09 12:01:15 UTC4972026-11-09 12:01:15.949 UTC [129] LOG: database system is ready to accept connections498/build/postgres3741922677:5432 - accepting connections499{"timestamp":"2026-11-09T12:01:16.443280377Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"01b614f4-c97b-4a6e-a34b-8f0921076ccd","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(398)"}500=== RUN TestAbortSucceeded501=== PAUSE TestAbortSucceeded502=== RUN TestService_AuthMiddleware503=== PAUSE TestService_AuthMiddleware504=== RUN TestService_AuthMiddleware_MTLSProxyHeader505=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader506=== RUN TestService_AuthMiddleware_MTLSBoundSubjects507=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects508=== RUN TestService_ReadAuthMiddleware509=== PAUSE TestService_ReadAuthMiddleware510=== RUN TestService_AuthMiddleware_OIDC511=== PAUSE TestService_AuthMiddleware_OIDC512=== RUN TestService_RequireScope_OIDC513=== PAUSE TestService_RequireScope_OIDC514=== RUN TestService_ReadScope_PublicByDefault515=== PAUSE TestService_ReadScope_PublicByDefault516=== RUN TestCacheConfigHandler517=== PAUSE TestCacheConfigHandler518=== RUN TestCacheStatsHandler519=== PAUSE TestCacheStatsHandler520=== RUN TestClientCADerivations521=== PAUSE TestClientCADerivations522=== RUN TestClientErrorHandling523=== PAUSE TestClientErrorHandling524=== RUN TestClientIntegration525=== PAUSE TestClientIntegration526=== RUN TestClientMultipleUploads527=== PAUSE TestClientMultipleUploads528=== RUN TestClientWithDependencies529=== PAUSE TestClientWithDependencies530=== RUN TestClientSharedPathCommittedMidPush531=== PAUSE TestClientSharedPathCommittedMidPush532=== RUN TestPinProtectsFromGC533=== PAUSE TestPinProtectsFromGC534=== RUN TestClientPushesUseOnePush535=== PAUSE TestClientPushesUseOnePush536=== RUN TestClientFallsBackToClosures537=== PAUSE TestClientFallsBackToClosures538=== RUN TestDeleteClosuresRacingPins539=== PAUSE TestDeleteClosuresRacingPins540=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock541=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock542=== RUN TestRetryableCompletionError543=== PAUSE TestRetryableCompletionError544=== RUN TestCompleteMultipartUploadRetriesTransientFailure545=== PAUSE TestCompleteMultipartUploadRetriesTransientFailure546=== RUN TestResolveDBConnectionString547=== PAUSE TestResolveDBConnectionString548=== RUN TestConnectWaitsForAPeerMigration549=== PAUSE TestConnectWaitsForAPeerMigration550=== RUN TestLeadElectsOneAndHandsOver551=== PAUSE TestLeadElectsOneAndHandsOver552=== RUN TestLeadIncumbentWinsAfterRestart5532026/11/09 12:01:16 INFO lead: acquired remote=192.0.2.1:12345542026/11/09 12:01:17 INFO lead: released remote=192.0.2.1:12345552026/11/09 12:01:17 INFO lead: acquired remote=192.0.2.1:12345562026/11/09 12:01:18 INFO lead: released remote=192.0.2.1:1234557--- PASS: TestLeadIncumbentWinsAfterRestart (1.89s)558=== RUN TestLeadIncumbentAnnouncesAtOnce559=== PAUSE TestLeadIncumbentAnnouncesAtOnce560=== RUN TestLeadEndsOnShutdown561=== PAUSE TestLeadEndsOnShutdown562=== RUN TestLeadEndsWhenItsConnectionHangs5632026/11/09 12:01:18 INFO lead: acquired remote=192.0.2.1:12345642026-11-09 12:01:19.944 UTC [575] FATAL: terminating connection due to administrator command5652026/11/09 12:01:20 INFO lead: acquired remote=192.0.2.1:12345662026/11/09 12:01:21 WARN lead: lock connection lost error="timeout: context deadline exceeded"5672026/11/09 12:01:21 INFO lead: released remote=192.0.2.1:12345682026/11/09 12:01:21 INFO lead: released remote=192.0.2.1:1234569--- PASS: TestLeadEndsWhenItsConnectionHangs (2.91s)570=== RUN TestGCAdvisoryLockBlocksConcurrentRun571=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun572=== RUN TestGCBugBareHashReferences573=== PAUSE TestGCBugBareHashReferences574=== RUN TestGCMetrics575=== PAUSE TestGCMetrics576=== RUN TestPushDedupSurvivesConcurrentGC577=== PAUSE TestPushDedupSurvivesConcurrentGC578=== RUN TestDeduplicatedObjectsRecordedAsPending579=== PAUSE TestDeduplicatedObjectsRecordedAsPending580=== RUN TestGCSweepSkipsPendingObjects581=== PAUSE TestGCSweepSkipsPendingObjects582=== RUN TestTombstonedObjectOfferedWithoutWaiting583=== PAUSE TestTombstonedObjectOfferedWithoutWaiting584=== RUN TestGCSweepDeliversEachKeyOnce585=== PAUSE TestGCSweepDeliversEachKeyOnce586=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection587=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection588=== RUN TestForceGCDuringPushOffersSweptObject589=== PAUSE TestForceGCDuringPushOffersSweptObject590=== RUN TestFailedS3DeleteKeepsTombstone591=== PAUSE TestFailedS3DeleteKeepsTombstone592=== RUN TestSweepSkipsRowsLockedByPush593=== PAUSE TestSweepSkipsRowsLockedByPush594=== RUN TestRegisterCompletedObjectNeedsPendingRow595=== PAUSE TestRegisterCompletedObjectNeedsPendingRow596=== RUN TestGetExistingObjectsLocksRows597=== PAUSE TestGetExistingObjectsLocksRows598=== RUN TestSweepRechecksPendingAfterLocking599=== PAUSE TestSweepRechecksPendingAfterLocking600=== RUN TestPushWaitsForSweepHoldingRow601=== PAUSE TestPushWaitsForSweepHoldingRow602=== RUN TestCommitRacingPendingCleanupKeepsObjects603=== PAUSE TestCommitRacingPendingCleanupKeepsObjects604=== RUN TestGCEndsOnShutdown605=== PAUSE TestGCEndsOnShutdown606=== RUN TestGCTaskStore_StartNew607=== PAUSE TestGCTaskStore_StartNew608=== RUN TestGCTaskStore_DeduplicateSameParams609=== PAUSE TestGCTaskStore_DeduplicateSameParams610=== RUN TestGCTaskStore_ConflictDifferentParams611=== PAUSE TestGCTaskStore_ConflictDifferentParams612=== RUN TestGCTaskStore_GetEmpty613=== PAUSE TestGCTaskStore_GetEmpty614=== RUN TestGCTaskStore_GetReturnsLatest615=== PAUSE TestGCTaskStore_GetReturnsLatest616=== RUN TestGCTaskStore_CompletedAllowsNewTask617=== PAUSE TestGCTaskStore_CompletedAllowsNewTask618=== RUN TestGCTaskStore_PhaseUpdates619=== PAUSE TestGCTaskStore_PhaseUpdates620=== RUN TestGCTaskStore_Fail621=== PAUSE TestGCTaskStore_Fail622=== RUN TestGracefulShutdownDrainsInflight623=== PAUSE TestGracefulShutdownDrainsInflight624=== RUN TestService_healthCheckHandler625=== PAUSE TestService_healthCheckHandler626=== RUN TestService_readinessHandler627=== PAUSE TestService_readinessHandler628=== RUN TestGenerateLandingPage629=== PAUSE TestGenerateLandingPage630=== RUN TestEnsureAbortUploadsRule631=== PAUSE TestEnsureAbortUploadsRule632=== RUN TestCacheConfigHandlerMaxNarSize633=== PAUSE TestCacheConfigHandlerMaxNarSize634=== RUN TestCreatePendingClosureRejectsOversizedNAR635=== PAUSE TestCreatePendingClosureRejectsOversizedNAR636=== RUN TestNARDeduplicationMetadataUploadBug637=== PAUSE TestNARDeduplicationMetadataUploadBug638=== RUN TestMetricsInventory639=== PAUSE TestMetricsInventory640=== RUN TestMetricsCommit641=== PAUSE TestMetricsCommit642=== RUN TestService_NativeMTLS643=== PAUSE TestService_NativeMTLS644=== RUN TestServerTLSConfig645=== PAUSE TestServerTLSConfig646=== RUN TestMultipartCleanup647=== PAUSE TestMultipartCleanup648=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded649=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded650=== RUN TestPendingCleanupUsesOneCutoff651=== PAUSE TestPendingCleanupUsesOneCutoff652=== RUN TestObjectStatsTrigger653=== PAUSE TestObjectStatsTrigger654=== RUN TestObjectStatsUpdatedOncePerCommit655=== PAUSE TestObjectStatsUpdatedOncePerCommit656=== RUN TestOrphanedObjectsGC657=== PAUSE TestOrphanedObjectsGC658=== RUN TestOrphanedObjectsGCStressTest659=== PAUSE TestOrphanedObjectsGCStressTest660=== RUN TestCreatePin_ReservedPins661=== PAUSE TestCreatePin_ReservedPins662=== RUN TestPresentReportsOnlyClosureRoots663=== PAUSE TestPresentReportsOnlyClosureRoots664=== RUN TestPresentRefreshesOnlyStaleClosures665=== PAUSE TestPresentRefreshesOnlyStaleClosures666=== RUN TestPresentNotReportedWhileGCDeletesClosure667=== PAUSE TestPresentNotReportedWhileGCDeletesClosure668=== RUN TestParseSingleRange669=== PAUSE TestParseSingleRange670=== RUN TestProxyHeadersOnlyTrustedOnSocket6712026/11/09 12:01:21 INFO Starting HTTP server address=proxy.sock6722026/11/09 12:01:21 INFO Starting HTTP server address=127.0.0.1:462976732026/11/09 12:01:21 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6742026/11/09 12:01:21 INFO Shutdown signal received, draining in-flight requests timeout=10s675--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.11s)676=== RUN TestIsValidCachePath677=== PAUSE TestIsValidCachePath678=== RUN TestReadProxyNarinfo679=== PAUSE TestReadProxyNarinfo680=== RUN TestReadProxyNarinfoAlreadyDecompressed681=== PAUSE TestReadProxyNarinfoAlreadyDecompressed682=== RUN TestReadProxyContentNegotiation683=== PAUSE TestReadProxyContentNegotiation684=== RUN TestReadProxyNarStreaming685=== PAUSE TestReadProxyNarStreaming686=== RUN TestReadProxy404687=== PAUSE TestReadProxy404688=== RUN TestReadProxyInvalidPath689=== PAUSE TestReadProxyInvalidPath690=== RUN TestReadProxyHead691=== PAUSE TestReadProxyHead692=== RUN TestReadProxyOutlastsServerWriteTimeout693=== PAUSE TestReadProxyOutlastsServerWriteTimeout694=== RUN TestReadProxyConditionalGet695=== PAUSE TestReadProxyConditionalGet696=== RUN TestReadProxyRootRedirectsToIndexHTML697=== PAUSE TestReadProxyRootRedirectsToIndexHTML698=== RUN TestReadProxyDisabled699=== PAUSE TestReadProxyDisabled700=== RUN TestReadRedirectNar701=== PAUSE TestReadRedirectNar702=== RUN TestReadRedirectKeepsNarinfoProxied703=== PAUSE TestReadRedirectKeepsNarinfoProxied704=== RUN TestReadProxyRangeRequest705=== PAUSE TestReadProxyRangeRequest706=== RUN TestReadRedirectUsesPublicS3URL707=== PAUSE TestReadRedirectUsesPublicS3URL708=== RUN TestPush_OverlappingRootsStoreOneRowPerKey709=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey710=== RUN TestPush_CompleteCommitsEveryRoot711=== PAUSE TestPush_CompleteCommitsEveryRoot712=== RUN TestPush_RepeatedRootCommitsOnce713=== PAUSE TestPush_RepeatedRootCommitsOnce714=== RUN TestPush_CompleteWaitsForCleanupOfThePush715=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush716=== RUN TestPush_RootsAreLockedInByteOrder717=== PAUSE TestPush_RootsAreLockedInByteOrder718=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit719=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit720=== RUN TestPush_RejectsBadRequests721=== PAUSE TestPush_RejectsBadRequests722=== RUN TestPush_SignsNarinfosOfItsPendingObjects723=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects724=== RUN TestSharedNarBothUploadsComplete725=== PAUSE TestSharedNarBothUploadsComplete726=== RUN TestCompleteMultipartUpload_ErrorButObjectExists727=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists728=== RUN TestCompletedNarNotReofferedAcrossClosures729=== PAUSE TestCompletedNarNotReofferedAcrossClosures730=== RUN TestPresignedUploadRegisteredBeforeCommit731=== PAUSE TestPresignedUploadRegisteredBeforeCommit732=== RUN TestService_Rustfstest733=== PAUSE TestService_Rustfstest734=== RUN TestParseSize735=== PAUSE TestParseSize736=== RUN TestSkippedUploadsHandler737=== PAUSE TestSkippedUploadsHandler738=== RUN TestSystemdListenerNotActivated739--- PASS: TestSystemdListenerNotActivated (0.00s)740=== RUN TestWatchdogBeatsWhenHealthy741--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)742=== RUN TestWatchdogSkipsWhenUnhealthy7432026/11/09 12:01:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7442026/11/09 12:01:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7452026/11/09 12:01:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7462026/11/09 12:01:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7472026/11/09 12:01:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7482026/11/09 12:01:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7492026/11/09 12:01:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7502026/11/09 12:01:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7512026/11/09 12:01:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7522026/11/09 12:01:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"753--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)754=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle755=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle756=== RUN TestProxyWriteTimeout757=== PAUSE TestProxyWriteTimeout758=== RUN TestPendingClosureWriteTimeout759=== PAUSE TestPendingClosureWriteTimeout760=== RUN TestIsValidUploadKey761=== PAUSE TestIsValidUploadKey762=== RUN TestUploadHandlersRejectInvalidKeys763=== PAUSE TestUploadHandlersRejectInvalidKeys764=== RUN TestUploadHandlersRejectOversizedBody765=== PAUSE TestUploadHandlersRejectOversizedBody766=== RUN TestService_cleanupPendingClosuresHandler767=== PAUSE TestService_cleanupPendingClosuresHandler768=== RUN TestService_createPendingClosureHandler769=== PAUSE TestService_createPendingClosureHandler770=== RUN TestService_verifyS3Integrity771=== PAUSE TestService_verifyS3Integrity772=== RUN TestService_verifyS3ReuploadsStaleNarinfo773=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo774=== RUN TestCompleteMultipartUnregistered775=== PAUSE TestCompleteMultipartUnregistered776=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT777=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT778=== CONT TestAbortSucceeded779=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT780--- PASS: TestAbortSucceeded (0.00s)781=== CONT TestMultipartCleanup782=== CONT TestServerTLSConfig783=== CONT TestService_NativeMTLS784=== CONT TestMetricsCommit785=== CONT TestMetricsInventory786=== CONT TestNARDeduplicationMetadataUploadBug787=== CONT TestCreatePendingClosureRejectsOversizedNAR788=== CONT TestCacheConfigHandlerMaxNarSize789=== CONT TestEnsureAbortUploadsRule7902026/11/09 12:01:21 INFO Received uploads request method=POST path=/api/pending_closures791--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)792--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)793=== CONT TestSweepRechecksPendingAfterLocking794=== CONT TestGenerateLandingPage795=== CONT TestService_healthCheckHandler796=== CONT TestGracefulShutdownDrainsInflight797=== CONT TestGCTaskStore_Fail798--- PASS: TestGCTaskStore_Fail (0.00s)799=== CONT TestGetExistingObjectsLocksRows800=== CONT TestGCTaskStore_PhaseUpdates801--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)802=== CONT TestGCTaskStore_CompletedAllowsNewTask803=== CONT TestGCTaskStore_GetReturnsLatest804=== CONT TestGCTaskStore_GetEmpty805=== CONT TestGCTaskStore_ConflictDifferentParams806=== CONT TestGCTaskStore_DeduplicateSameParams807=== CONT TestGCTaskStore_StartNew808=== CONT TestGCEndsOnShutdown809=== CONT TestCommitRacingPendingCleanupKeepsObjects810=== RUN TestServerTLSConfig/no_client_CA811=== CONT TestPushWaitsForSweepHoldingRow812=== CONT TestService_readinessHandler813=== CONT TestRegisterCompletedObjectNeedsPendingRow8142026/11/09 12:01:21 INFO Starting HTTP server address=127.0.0.1:45665815=== PAUSE TestServerTLSConfig/no_client_CA816=== CONT TestGCSweepDeliversEachKeyOnce817=== RUN TestServerTLSConfig/missing_CA_file818=== PAUSE TestServerTLSConfig/missing_CA_file819--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)8202026/11/09 12:01:21 INFO Shutdown signal received, draining in-flight requests timeout=10s821--- PASS: TestGCTaskStore_GetEmpty (0.00s)822=== CONT TestFailedS3DeleteKeepsTombstone823=== CONT TestForceGCDuringPushOffersSweptObject824=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection825=== CONT TestSweepSkipsRowsLockedByPush826=== RUN TestGCEndsOnShutdown/before_the_run827=== CONT TestTombstonedObjectOfferedWithoutWaiting828=== CONT TestReadRedirectUsesPublicS3URL829=== RUN TestServerTLSConfig/not_a_PEM_file830--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)831--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)832--- PASS: TestGCTaskStore_StartNew (0.00s)833--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)834--- PASS: TestGenerateLandingPage (0.00s)835=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows836=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows837=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check838=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check839=== PAUSE TestServerTLSConfig/not_a_PEM_file840=== PAUSE TestGCEndsOnShutdown/before_the_run841=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete842=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete843=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark844=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark845=== CONT TestGCSweepSkipsPendingObjects846=== CONT TestDeduplicatedObjectsRecordedAsPending847=== CONT TestPushDedupSurvivesConcurrentGC848--- PASS: TestGracefulShutdownDrainsInflight (0.07s)849=== CONT TestGCMetrics8502026/11/09 12:01:22 INFO Received uploads request method=POST path=/api/pending_closures8512026/11/09 12:01:22 INFO Received push request method=POST path=/api/pushes852--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.41s)853=== CONT TestCompleteMultipartUnregistered8542026/11/09 12:01:22 INFO Received complete push request method=POST path=/api/pushes/1/complete8552026/11/09 12:01:22 WARN mTLS auth: subject not in bound subjects subject="CN=reader"8562026/11/09 12:01:22 WARN mTLS auth: subject not in bound subjects subject="CN=reader"857--- PASS: TestService_NativeMTLS (0.43s)858=== CONT TestGCBugBareHashReferences8592026/11/09 12:01:22 INFO Completed push id=1 objects=4 duration=9.289266ms8602026/11/09 12:01:22 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete8612026/11/09 12:01:22 INFO Completed upload id=2 objects=2 duration=1.350431ms862--- PASS: TestMetricsCommit (0.45s)863=== CONT TestGCAdvisoryLockBlocksConcurrentRun8642026/11/09 12:01:22 INFO Received uploads request method=POST path=/api/pending_closures8652026/11/09 12:01:22 INFO Aborted multipart uploads count=0 kept=0866--- PASS: TestMetricsInventory (0.53s)867=== CONT TestService_verifyS3ReuploadsStaleNarinfo868=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed869=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed870=== RUN TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed871=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed872=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost873=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost874=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed875=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed876=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed877=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed878=== CONT TestLeadEndsOnShutdown8792026/11/09 12:01:22 WARN Force mode enabled - objects will be deleted immediately without grace period8802026/11/09 12:01:22 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=08812026/11/09 12:01:22 INFO Vacuumed table table=pending_closures8822026/11/09 12:01:22 INFO Vacuumed table table=pending_objects8832026/11/09 12:01:22 INFO Vacuumed table table=multipart_uploads8842026/11/09 12:01:22 INFO Vacuumed table table=closures8852026/11/09 12:01:22 INFO Vacuumed table table=objects886--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.55s)887=== CONT TestLeadIncumbentAnnouncesAtOnce8882026/11/09 12:01:22 INFO Received cleanup request method=DELETE path=/api/pending_closures8892026/11/09 12:01:22 INFO Installed lifecycle rule aborting incomplete NAR uploads bucket=bucket11 days=28902026/11/09 12:01:22 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket7/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""8912026/11/09 12:01:22 INFO Aborted multipart uploads count=0 kept=1892--- PASS: TestEnsureAbortUploadsRule (0.57s)893=== CONT TestLeadElectsOneAndHandsOver8942026/11/09 12:01:22 INFO Received cleanup request method=DELETE path=/api/pending_closures8952026/11/09 12:01:22 INFO Aborted multipart uploads count=1 kept=0896=== NAME TestNARDeduplicationMetadataUploadBug897 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug730971962/001/store/6fqb84hfcv889hhk2849sidz8jnrrnf2-file1.txt898--- PASS: TestMultipartCleanup (0.59s)899=== CONT TestService_verifyS3Integrity900--- PASS: TestGetExistingObjectsLocksRows (0.62s)901=== CONT TestConnectWaitsForAPeerMigration902--- PASS: TestService_healthCheckHandler (0.64s)903=== CONT TestResolveDBConnectionString904=== RUN TestResolveDBConnectionString/flag_wins905=== PAUSE TestResolveDBConnectionString/flag_wins906=== RUN TestResolveDBConnectionString/file_when_flag_empty907=== PAUSE TestResolveDBConnectionString/file_when_flag_empty908=== RUN TestResolveDBConnectionString/missing_file_is_an_error909=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error910=== RUN TestResolveDBConnectionString/PGHOST_allows_empty911=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty912=== RUN TestResolveDBConnectionString/nothing_configured913=== PAUSE TestResolveDBConnectionString/nothing_configured914=== CONT TestService_createPendingClosureHandler9152026/11/09 12:01:22 INFO Received uploads request method=POST path=/api/pending_closures9162026/11/09 12:01:22 INFO Received push request method=POST path=/api/pushes9172026/11/09 12:01:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9182026/11/09 12:01:22 INFO Received uploads request method=POST path=/api/pending_closures9192026/11/09 12:01:22 INFO Uploading 6fqb84hfcv889hhk2849sidz8jnrrnf2-file1.txt (160B)9202026/11/09 12:01:22 WARN readiness check failed error="closed pool"921--- PASS: TestService_readinessHandler (0.69s)922=== CONT TestCompleteMultipartUploadRetriesTransientFailure9232026/11/09 12:01:22 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"9242026/11/09 12:01:22 WARN Failed to register uploaded object key=6fqb84hfcv889hhk2849sidz8jnrrnf2.ls error="server returned 404: 404 page not found\n"9252026/11/09 12:01:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9262026/11/09 12:01:22 INFO Signed narinfos id=1 count=19272026/11/09 12:01:22 INFO Uploading 1 narinfos9282026/11/09 12:01:22 INFO Received complete push request method=POST path=/api/pushes/1/complete9292026/11/09 12:01:22 WARN Failed to register uploaded object key=6fqb84hfcv889hhk2849sidz8jnrrnf2.narinfo error="server returned 404: 404 page not found\n"9302026/11/09 12:01:22 INFO Completed push id=1 objects=3 duration=7.257515ms9312026/11/09 12:01:22 INFO Upload complete. (84ms)932=== NAME TestNARDeduplicationMetadataUploadBug933 metadata_upload_test.go:54: Retrieved narinfo from S3:934 StorePath: /build/TestNARDeduplicationMetadataUploadBug730971962/001/store/6fqb84hfcv889hhk2849sidz8jnrrnf2-file1.txt935 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst936 Compression: zstd937 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf938 NarSize: 160939 References: 940 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf9412026/11/09 12:01:22 INFO Aborted multipart uploads count=0 kept=0942 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)943 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):944 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}9452026/11/09 12:01:22 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=09462026/11/09 12:01:22 INFO Vacuumed table table=pending_closures9472026/11/09 12:01:22 INFO Vacuumed table table=pending_objects9482026/11/09 12:01:22 INFO Vacuumed table table=multipart_uploads9492026/11/09 12:01:22 INFO Vacuumed table table=closures9502026/11/09 12:01:22 INFO Vacuumed table table=objects9512026/11/09 12:01:22 INFO Aborted multipart uploads count=0 kept=09522026/11/09 12:01:22 WARN Force mode enabled - objects will be deleted immediately without grace period9532026/11/09 12:01:22 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=09542026/11/09 12:01:22 INFO Aborted multipart uploads count=0 kept=09552026/11/09 12:01:22 INFO Vacuumed table table=pending_closures9562026/11/09 12:01:22 INFO Vacuumed table table=pending_objects9572026/11/09 12:01:22 INFO Vacuumed table table=multipart_uploads9582026/11/09 12:01:22 INFO Vacuumed table table=closures9592026/11/09 12:01:22 INFO Vacuumed table table=objects960--- PASS: TestPushDedupSurvivesConcurrentGC (0.75s)961=== CONT TestRetryableCompletionError962=== RUN TestRetryableCompletionError/invalid_part963=== PAUSE TestRetryableCompletionError/invalid_part964=== RUN TestRetryableCompletionError/throttled965=== PAUSE TestRetryableCompletionError/throttled9662026/11/09 12:01:22 WARN Force mode enabled - objects will be deleted immediately without grace period967=== RUN TestRetryableCompletionError/context_canceled968=== PAUSE TestRetryableCompletionError/context_canceled969=== RUN TestRetryableCompletionError/deadline_exceeded970=== PAUSE TestRetryableCompletionError/deadline_exceeded971=== RUN TestRetryableCompletionError/degraded_quorum972=== PAUSE TestRetryableCompletionError/degraded_quorum973=== RUN TestRetryableCompletionError/transport_failure974=== PAUSE TestRetryableCompletionError/transport_failure9752026/11/09 12:01:22 INFO Received uploads request method=POST path=/api/pending_closures976=== RUN TestRetryableCompletionError/access_denied977=== PAUSE TestRetryableCompletionError/access_denied978=== RUN TestRetryableCompletionError/nil979=== PAUSE TestRetryableCompletionError/nil980=== RUN TestRetryableCompletionError/bad_gateway981=== PAUSE TestRetryableCompletionError/bad_gateway982=== RUN TestRetryableCompletionError/no_such_upload983=== PAUSE TestRetryableCompletionError/no_such_upload984=== CONT TestService_cleanupPendingClosuresHandler985=== NAME TestNARDeduplicationMetadataUploadBug986 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug730971962/001/store/j1dcj5vvs822z5hhlpzfbhw7v3sb35n3-file2.txt9872026/11/09 12:01:22 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=09882026/11/09 12:01:22 INFO Vacuumed table table=pending_closures9892026/11/09 12:01:22 INFO Vacuumed table table=pending_objects9902026/11/09 12:01:22 INFO Vacuumed table table=multipart_uploads9912026/11/09 12:01:22 INFO Vacuumed table table=closures9922026/11/09 12:01:22 INFO Vacuumed table table=objects993--- PASS: TestSweepRechecksPendingAfterLocking (0.78s)994=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock995--- PASS: TestReadRedirectUsesPublicS3URL (0.78s)996=== CONT TestDeleteClosuresRacingPins997--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.80s)998=== CONT TestUploadHandlersRejectOversizedBody9992026/11/09 12:01:22 INFO Received push request method=POST path=/api/pushes10002026/11/09 12:01:22 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)10012026/11/09 12:01:22 INFO Received uploads request method=POST path=/api/pending_closures10022026/11/09 12:01:22 WARN Failed to register uploaded object key=j1dcj5vvs822z5hhlpzfbhw7v3sb35n3.ls error="server returned 404: 404 page not found\n"10032026/11/09 12:01:22 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign10042026/11/09 12:01:22 INFO Signed narinfos id=2 count=110052026/11/09 12:01:22 INFO Uploading 1 narinfos1006--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.90s)1007=== CONT TestClientFallsBackToClosures10082026/11/09 12:01:22 INFO Received complete push request method=POST path=/api/pushes/2/complete10092026/11/09 12:01:22 WARN Failed to register uploaded object key=j1dcj5vvs822z5hhlpzfbhw7v3sb35n3.narinfo error="server returned 404: 404 page not found\n"10102026/11/09 12:01:22 INFO Completed push id=2 objects=3 duration=1.831392ms10112026/11/09 12:01:22 INFO Upload complete. (118ms)1012=== NAME TestNARDeduplicationMetadataUploadBug1013 metadata_upload_test.go:76: Retrieved narinfo from S3:1014 StorePath: /build/TestNARDeduplicationMetadataUploadBug730971962/001/store/j1dcj5vvs822z5hhlpzfbhw7v3sb35n3-file2.txt1015 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1016 Compression: zstd1017 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1018 NarSize: 1601019 References: 1020 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1021 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1022 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1023 {"version":1,"root":{"type":"regular","size":44}}1024--- PASS: TestNARDeduplicationMetadataUploadBug (0.92s)1025=== CONT TestUploadHandlersRejectInvalidKeys1026=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1027=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1028=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1029=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1030=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1031=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1032=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1033=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1034=== CONT TestClientPushesUseOnePush10352026/11/09 12:01:22 INFO Aborted multipart uploads count=0 kept=010362026/11/09 12:01:22 WARN Force mode enabled - objects will be deleted immediately without grace period10372026/11/09 12:01:22 INFO Received uploads request method=POST path=/api/pending_closures10382026/11/09 12:01:22 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=010392026/11/09 12:01:22 INFO Vacuumed table table=pending_closures10402026/11/09 12:01:22 INFO Vacuumed table table=pending_objects10412026/11/09 12:01:22 INFO Vacuumed table table=multipart_uploads10422026/11/09 12:01:22 INFO Vacuumed table table=closures10432026/11/09 12:01:22 INFO Vacuumed table table=objects10442026/11/09 12:01:22 INFO Aborted multipart uploads count=0 kept=01045--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.96s)1046=== CONT TestPinProtectsFromGC10472026/11/09 12:01:22 WARN Force mode enabled - objects will be deleted immediately without grace period1048=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1049=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure10502026/11/09 12:01:22 INFO Received uploads request method=POST path=/api/pending_closures1051=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1052=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1053=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1054=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1055=== CONT TestClientSharedPathCommittedMidPush10562026/11/09 12:01:22 INFO Aborted multipart uploads count=0 kept=010572026/11/09 12:01:22 WARN Force mode enabled - objects will be deleted immediately without grace period10582026/11/09 12:01:22 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=010592026/11/09 12:01:22 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=010602026/11/09 12:01:22 INFO Vacuumed table table=pending_closures10612026/11/09 12:01:22 INFO Vacuumed table table=pending_closures10622026/11/09 12:01:22 INFO Vacuumed table table=pending_objects10632026/11/09 12:01:22 INFO Vacuumed table table=multipart_uploads10642026/11/09 12:01:22 INFO Vacuumed table table=closures10652026/11/09 12:01:22 INFO Vacuumed table table=pending_objects10662026/11/09 12:01:22 INFO Vacuumed table table=multipart_uploads10672026/11/09 12:01:22 INFO Vacuumed table table=closures10682026/11/09 12:01:22 INFO Vacuumed table table=objects1069--- PASS: TestSweepSkipsRowsLockedByPush (1.00s)1070=== CONT TestIsValidUploadKey1071=== RUN TestIsValidUploadKey/narinfo1072=== PAUSE TestIsValidUploadKey/narinfo1073=== RUN TestIsValidUploadKey/nar_zst1074=== PAUSE TestIsValidUploadKey/nar_zst1075=== RUN TestIsValidUploadKey/nar_xz1076=== PAUSE TestIsValidUploadKey/nar_xz1077=== RUN TestIsValidUploadKey/nar_plain1078=== PAUSE TestIsValidUploadKey/nar_plain1079=== RUN TestIsValidUploadKey/listing1080=== PAUSE TestIsValidUploadKey/listing1081=== RUN TestIsValidUploadKey/build_log1082=== PAUSE TestIsValidUploadKey/build_log1083=== RUN TestIsValidUploadKey/build_log_home-manager_file1084=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1085=== RUN TestIsValidUploadKey/build_log_plus_in_name1086=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1087=== RUN TestIsValidUploadKey/build_log_question_mark1088=== PAUSE TestIsValidUploadKey/build_log_question_mark1089=== RUN TestIsValidUploadKey/build_log_equals1090=== PAUSE TestIsValidUploadKey/build_log_equals1091=== RUN TestIsValidUploadKey/realisation1092=== PAUSE TestIsValidUploadKey/realisation1093=== RUN TestIsValidUploadKey/realisation_plus_in_output1094=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1095=== RUN TestIsValidUploadKey/nix-cache-info10962026/11/09 12:01:22 INFO Vacuumed table table=objects1097=== PAUSE TestIsValidUploadKey/nix-cache-info1098=== RUN TestIsValidUploadKey/index.html1099=== PAUSE TestIsValidUploadKey/index.html1100=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1101=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1102=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1103=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1104=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1105=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1106=== RUN TestIsValidUploadKey/traversal1107=== PAUSE TestIsValidUploadKey/traversal1108=== RUN TestIsValidUploadKey/traversal_nar1109=== PAUSE TestIsValidUploadKey/traversal_nar1110=== RUN TestIsValidUploadKey/absolute1111=== PAUSE TestIsValidUploadKey/absolute1112=== RUN TestIsValidUploadKey/empty_key1113=== PAUSE TestIsValidUploadKey/empty_key1114=== RUN TestIsValidUploadKey/unknown_type1115=== PAUSE TestIsValidUploadKey/unknown_type1116=== CONT TestClientWithDependencies1117--- PASS: TestGCSweepSkipsPendingObjects (1.01s)1118=== CONT TestPendingClosureWriteTimeout1119=== RUN TestPendingClosureWriteTimeout/empty1120=== PAUSE TestPendingClosureWriteTimeout/empty1121=== RUN TestPendingClosureWriteTimeout/400_objects1122=== PAUSE TestPendingClosureWriteTimeout/400_objects1123=== RUN TestPendingClosureWriteTimeout/670k_objects1124=== PAUSE TestPendingClosureWriteTimeout/670k_objects1125=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1126=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1127=== CONT TestClientMultipleUploads11282026/11/09 12:01:22 INFO Aborted multipart uploads count=0 kept=011292026/11/09 12:01:22 INFO Aborted multipart uploads count=0 kept=011302026/11/09 12:01:22 WARN Force mode enabled - objects will be deleted immediately without grace period11312026/11/09 12:01:22 WARN Force mode enabled - objects will be deleted immediately without grace period11322026/11/09 12:01:22 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=011332026/11/09 12:01:22 INFO Vacuumed table table=pending_closures11342026/11/09 12:01:22 INFO Vacuumed table table=pending_objects11352026/11/09 12:01:22 INFO Vacuumed table table=multipart_uploads11362026/11/09 12:01:22 INFO Vacuumed table table=closures11372026/11/09 12:01:22 INFO Vacuumed table table=objects1138--- PASS: TestGCMetrics (0.98s)1139=== CONT TestClientIntegration11402026/11/09 12:01:22 INFO Received uploads request method=POST path=/api/pending_closures11412026/11/09 12:01:22 INFO Aborted multipart uploads count=0 kept=01142--- PASS: TestTombstonedObjectOfferedWithoutWaiting (1.06s)1143=== CONT TestProxyWriteTimeout1144=== RUN TestProxyWriteTimeout/narinfo1145=== PAUSE TestProxyWriteTimeout/narinfo1146=== RUN TestProxyWriteTimeout/1_GiB_nar1147=== PAUSE TestProxyWriteTimeout/1_GiB_nar1148=== RUN TestProxyWriteTimeout/10_GiB_nar1149=== PAUSE TestProxyWriteTimeout/10_GiB_nar1150=== RUN TestProxyWriteTimeout/unknown_size1151=== PAUSE TestProxyWriteTimeout/unknown_size1152=== CONT TestClientErrorHandling1153=== RUN TestClientErrorHandling/InvalidStorePath1154=== PAUSE TestClientErrorHandling/InvalidStorePath1155=== RUN TestClientErrorHandling/InvalidAuthToken1156=== PAUSE TestClientErrorHandling/InvalidAuthToken1157=== RUN TestClientErrorHandling/ServerNotAvailable1158=== PAUSE TestClientErrorHandling/ServerNotAvailable1159=== CONT TestClientCADerivations11602026/11/09 12:01:22 WARN Force mode enabled - objects will be deleted immediately without grace period11612026/11/09 12:01:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11622026/11/09 12:01:22 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1163--- PASS: TestCompleteMultipartUnregistered (0.67s)1164=== CONT TestCacheStatsHandler11652026/11/09 12:01:22 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."11662026/11/09 12:01:22 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."11672026/11/09 12:01:22 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=011682026/11/09 12:01:22 INFO Vacuumed table table=pending_closures11692026/11/09 12:01:22 INFO Vacuumed table table=pending_objects1170--- PASS: TestFailedS3DeleteKeepsTombstone (1.09s)1171=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle11722026/11/09 12:01:22 INFO Vacuumed table table=multipart_uploads11732026/11/09 12:01:22 INFO Vacuumed table table=closures11742026/11/09 12:01:22 INFO Vacuumed table table=objects1175--- PASS: TestGCSweepDeliversEachKeyOnce (1.10s)1176=== CONT TestCacheConfigHandler1177=== RUN TestCacheConfigHandler/full_config,_no_issuer1178=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1179=== RUN TestCacheConfigHandler/no_cache_url_configured1180=== PAUSE TestCacheConfigHandler/no_cache_url_configured1181=== RUN TestCacheConfigHandler/no_signing_keys1182=== PAUSE TestCacheConfigHandler/no_signing_keys1183=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1184=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1185=== CONT TestService_ReadScope_PublicByDefault11862026/11/09 12:01:22 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=nixbld database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1187--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.67s)1188=== CONT TestService_RequireScope_OIDC1189--- PASS: TestPushWaitsForSweepHoldingRow (1.19s)1190=== CONT TestSkippedUploadsHandler11912026/11/09 12:01:22 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001192--- PASS: TestSkippedUploadsHandler (0.00s)1193=== CONT TestService_AuthMiddleware_OIDC11942026/11/09 12:01:22 INFO lead: acquired remote=192.0.2.1:123411952026/11/09 12:01:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32941/oidc11962026/11/09 12:01:22 INFO lead: acquired remote=192.0.2.1:123411972026/11/09 12:01:22 INFO lead: released remote=192.0.2.1:12341198--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.68s)1199=== CONT TestService_ReadAuthMiddleware12002026/11/09 12:01:22 INFO lead: acquired remote=192.0.2.1:123412012026/11/09 12:01:22 INFO Received uploads request method=POST path=/api/pending_closures12022026/11/09 12:01:22 INFO Received uploads request method=POST path=/api/pending_closures12032026/11/09 12:01:22 INFO Received uploads request method=POST path=/api/pending_closures12042026/11/09 12:01:22 INFO Received uploads request method=POST path=/api/pending_closures12052026/11/09 12:01:23 INFO Received uploads request method=POST path=/api/pending_closures12062026/11/09 12:01:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33749/oidc12072026/11/09 12:01:23 INFO Received cleanup request method=DELETE path=/api/pending_closures12082026/11/09 12:01:23 INFO Aborted multipart uploads count=0 kept=012092026/11/09 12:01:23 INFO Received uploads request method=POST path=/api/pending_closures12102026/11/09 12:01:23 INFO Received cleanup request method=DELETE path=/api/pending_closures12112026/11/09 12:01:23 INFO Aborted multipart uploads count=1 kept=012122026/11/09 12:01:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12132026-11-09 12:01:23.050 UTC [830] ERROR: Closure does not exist: id=112142026-11-09 12:01:23.050 UTC [830] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE12152026-11-09 12:01:23.050 UTC [830] STATEMENT: -- name: CommitPendingClosure :one1216 SELECT commit_pending_closure($1::bigint)::bigint1217 1218--- PASS: TestService_cleanupPendingClosuresHandler (0.61s)1219=== CONT TestParseSize1220--- PASS: TestParseSize (0.00s)1221=== CONT TestService_AuthMiddleware_MTLSBoundSubjects12222026/11/09 12:01:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1223--- PASS: TestGCBugBareHashReferences (0.98s)1224=== CONT TestService_Rustfstest12252026/11/09 12:01:23 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccc0100000000000000000000.nar.zst upload_id=YjZmZmY5MmItZmM0NC00MjRiLWE2OGUtNDI0OTA1OTA5ODgwLmU0NTE5MjM2LTE4NzktNDRhMC05YmI0LTcwYjc2YWNkYzg5NngxNzk0MjI1NjgzMDE2ODE1Nzcy parts=21226--- PASS: TestCompleteMultipartUploadRetriesTransientFailure (0.80s)1227=== CONT TestService_AuthMiddleware_MTLSProxyHeader1228=== NAME TestPinProtectsFromGC1229 client_integration_test.go:778: Pinned store path: /build/TestPinProtectsFromGC1658890263/001/store/31gb6q185jp911s32z396ldfsp6rqsd4-pinned-file.txt1230 client_integration_test.go:779: Unpinned store path: /build/TestPinProtectsFromGC1658890263/001/store/4azmfa7a9n8xnmjnmw5lbv7bwsi1w4ki-unpinned-file.txt1231=== NAME TestClientMultipleUploads1232 client_integration_test.go:405: Created store path 0: /build/TestClientMultipleUploads817290038/001/store/1igbwkdxg6v4wsrhqchgzad287zqfvyx-test-file-0.txt1233--- PASS: TestCacheStatsHandler (0.53s)1234=== CONT TestPresignedUploadRegisteredBeforeCommit1235--- PASS: TestService_ReadScope_PublicByDefault (0.51s)1236=== CONT TestService_AuthMiddleware1237=== NAME TestClientIntegration1238 client_integration_test.go:291: Created store path: /build/TestClientIntegration17016472/002/store/kd46x3vr8ix7is363vnh5wm8s4sqzkwz-test-file.txt12392026/11/09 12:01:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12402026/11/09 12:01:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1241=== NAME TestClientWithDependencies1242 client_integration_test.go:660: Built derivation: /build/TestClientWithDependencies1924211134/001/store/8m7736p48kbz71gcwlja3vd70lm5147c-test-script12432026/11/09 12:01:23 INFO Received uploads request method=POST path=/api/pending_closures1244=== NAME TestClientMultipleUploads1245 client_integration_test.go:405: Created store path 1: /build/TestClientMultipleUploads817290038/001/store/wv6l6jnh1a1m0z0a510pq418r5n0a0df-test-file-1.txt12462026/11/09 12:01:23 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YjZmZmY5MmItZmM0NC00MjRiLWE2OGUtNDI0OTA1OTA5ODgwLjBkNjk0MDg3LTZlMDgtNGU0Yi1hYzAwLWI3MGYyODZjOGZlY3gxNzk0MjI1NjgyOTcyNjU1NzUz parts=1012472026/11/09 12:01:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12482026/11/09 12:01:23 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YjZmZmY5MmItZmM0NC00MjRiLWE2OGUtNDI0OTA1OTA5ODgwLmMzNjhjNjcxLWQxMTItNDQwNi04YjZmLTU5MTY0MzY3MGM4OXgxNzk0MjI1NjgyOTk5NDcxNjUx parts=1012492026/11/09 12:01:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12502026/11/09 12:01:23 INFO Received push request method=POST path=/api/pushes12512026/11/09 12:01:23 INFO Completed upload id=1 objects=2 duration=3.817993ms12522026/11/09 12:01:23 INFO Completed upload id=1 objects=2 duration=3.603002ms12532026/11/09 12:01:23 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000012542026/11/09 12:01:23 INFO Received uploads request method=POST path=/api/pending_closures12552026/11/09 12:01:23 INFO Received uploads request method=POST path=/api/pending_closures12562026/11/09 12:01:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12572026/11/09 12:01:23 INFO Uploading 31gb6q185jp911s32z396ldfsp6rqsd4-pinned-file.txt (128B)12582026/11/09 12:01:23 INFO Starting cleanup of old closures method=DELETE path=/api/closures12592026/11/09 12:01:23 INFO Received uploads request method=POST path=/api/pending_closures12602026/11/09 12:01:23 INFO Received uploads request method=POST path=/api/pending_closures12612026/11/09 12:01:23 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo12622026/11/09 12:01:23 WARN Found objects in DB but missing from S3, will re-upload count=112632026/11/09 12:01:23 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"1264--- PASS: TestService_verifyS3Integrity (1.07s)1265=== CONT TestCompletedNarNotReofferedAcrossClosures12662026/11/09 12:01:23 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12672026/11/09 12:01:23 INFO Received uploads request method=POST path=/api/pending_closures12682026/11/09 12:01:23 INFO Signed narinfos id=1 count=112692026/11/09 12:01:23 WARN Failed to register uploaded object key=31gb6q185jp911s32z396ldfsp6rqsd4.ls error="server returned 404: 404 page not found\n"12702026/11/09 12:01:23 INFO Uploading 1 narinfos12712026/11/09 12:01:23 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12722026/11/09 12:01:23 INFO Uploading lbiib28005dfhcp3920vzg47p3ir0kis-shared-dep (136B)12732026/11/09 12:01:23 INFO Uploading jsk6b4pzhyc3150h5i32ww09qrzrhim6-a (216B)12742026/11/09 12:01:23 INFO Aborted multipart uploads count=0 kept=01275=== RUN TestService_RequireScope_OIDC/builder_may_write1276=== PAUSE TestService_RequireScope_OIDC/builder_may_write1277=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1278=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1279=== RUN TestService_RequireScope_OIDC/ops_may_admin1280=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1281=== RUN TestService_RequireScope_OIDC/ops_may_not_write1282=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1283=== RUN TestService_RequireScope_OIDC/reader_may_not_write12842026/11/09 12:01:23 INFO Received complete push request method=POST path=/api/pushes/1/complete1285=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1286=== RUN TestService_RequireScope_OIDC/static_token_may_admin1287=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1288=== RUN TestService_RequireScope_OIDC/static_token_may_write1289=== PAUSE TestService_RequireScope_OIDC/static_token_may_write12902026/11/09 12:01:23 WARN Failed to register uploaded object key=31gb6q185jp911s32z396ldfsp6rqsd4.narinfo error="server returned 404: 404 page not found\n"1291=== RUN TestService_RequireScope_OIDC/reader_may_read1292=== PAUSE TestService_RequireScope_OIDC/reader_may_read1293=== NAME TestClientWithDependencies12942026/11/09 12:01:23 INFO Received push request method=POST path=/api/pushes1295 client_integration_test.go:662: Found 1 dependencies (including self)1296=== RUN TestService_RequireScope_OIDC/writer_implies_read1297=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1298=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1299=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1300=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1301=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc13022026/11/09 12:01:23 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1303=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1304=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1305=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1306=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1307=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1308=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1309=== CONT TestCompleteMultipartUpload_ErrorButObjectExists13102026/11/09 12:01:23 WARN Failed to register uploaded object key=brih1gbf2iswpjmyk2rmhy5irlv9nlvc.ls error="server returned 404: 404 page not found\n"13112026/11/09 12:01:23 WARN Failed to register uploaded object key=lbiib28005dfhcp3920vzg47p3ir0kis.ls error="server returned 404: 404 page not found\n"13122026/11/09 12:01:23 WARN Failed to register uploaded object key=nar/0y55cnsmaigs0p5nv53m6ch2vznkps0l04hxbqq2rrvfp4ii58xd.nar.zst error="server returned 404: 404 page not found\n"13132026/11/09 12:01:23 WARN Failed to register uploaded object key=jsk6b4pzhyc3150h5i32ww09qrzrhim6.ls error="server returned 404: 404 page not found\n"13142026/11/09 12:01:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13152026/11/09 12:01:23 INFO Signed narinfos id=1 count=213162026/11/09 12:01:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13172026/11/09 12:01:23 INFO Signed narinfos id=2 count=213182026/11/09 12:01:23 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13192026/11/09 12:01:23 INFO Uploading 4 narinfos13202026/11/09 12:01:23 INFO Uploading 52xf5x6bc5dgs9av07h83mk2gpicly1f-a (216B)13212026/11/09 12:01:23 INFO Uploading 70sn0nq8k91ad8mwjl7qmppx41zh2wzy-shared-dep (136B)13222026/11/09 12:01:23 INFO Completed push id=1 objects=3 duration=6.304744ms13232026/11/09 12:01:23 INFO Upload complete. (72ms)1324--- PASS: TestService_ReadAuthMiddleware (0.45s)1325=== CONT TestReadProxyNarinfoAlreadyDecompressed1326=== NAME TestClientMultipleUploads1327 client_integration_test.go:405: Created store path 2: /build/TestClientMultipleUploads817290038/001/store/pmv0814r185pz4kyp0gm6ycyxqh84g41-test-file-2.txt1328--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.90s)1329=== CONT TestSharedNarBothUploadsComplete13302026/11/09 12:01:23 WARN Failed to register uploaded object key=brih1gbf2iswpjmyk2rmhy5irlv9nlvc.narinfo error="server returned 404: 404 page not found\n"13312026/11/09 12:01:23 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=013322026/11/09 12:01:23 WARN Failed to register uploaded object key=ywkzidk2wavwjk7hl7p1kvklwlnygiy4.ls error="server returned 404: 404 page not found\n"13332026/11/09 12:01:23 WARN Failed to register uploaded object key=lbiib28005dfhcp3920vzg47p3ir0kis.narinfo error="server returned 404: 404 page not found\n"13342026/11/09 12:01:23 WARN Failed to register uploaded object key=jsk6b4pzhyc3150h5i32ww09qrzrhim6.narinfo error="server returned 404: 404 page not found\n"13352026/11/09 12:01:23 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13362026/11/09 12:01:23 WARN Failed to register uploaded object key=52xf5x6bc5dgs9av07h83mk2gpicly1f.ls error="server returned 404: 404 page not found\n"13372026/11/09 12:01:23 INFO Received push request method=POST path=/api/pushes13382026/11/09 12:01:23 WARN Failed to register uploaded object key=70sn0nq8k91ad8mwjl7qmppx41zh2wzy.ls error="server returned 404: 404 page not found\n"13392026/11/09 12:01:23 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13402026/11/09 12:01:23 WARN Failed to register uploaded object key=nar/1hb5cg7il3q7ws5alh92kgbvmj7613n4lc4g8rw85bqbpk145cm0.nar.zst error="server returned 404: 404 page not found\n"13412026/11/09 12:01:23 INFO Signed narinfos id=1 count=313422026/11/09 12:01:23 INFO Uploading 3 narinfos13432026/11/09 12:01:23 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13442026/11/09 12:01:23 WARN Failed to register uploaded object key=lbiib28005dfhcp3920vzg47p3ir0kis.narinfo error="server returned 404: 404 page not found\n"13452026/11/09 12:01:23 INFO Vacuumed table table=pending_closures13462026/11/09 12:01:23 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)13472026/11/09 12:01:23 INFO Uploading qmsgy2iqrym3gcx2vkrrhk7hdb01jh4f-shared-dep (136B)13482026/11/09 12:01:23 INFO Uploading nq11fm1mw591n81cb635xcrklf9b8rwp-top (224B)13492026/11/09 12:01:23 WARN Failed to register uploaded object key=ywkzidk2wavwjk7hl7p1kvklwlnygiy4.narinfo error="server returned 404: 404 page not found\n"13502026/11/09 12:01:23 WARN Failed to register uploaded object key=52xf5x6bc5dgs9av07h83mk2gpicly1f.narinfo error="server returned 404: 404 page not found\n"13512026/11/09 12:01:23 INFO Received complete push request method=POST path=/api/pushes/1/complete13522026/11/09 12:01:23 WARN Failed to register uploaded object key=70sn0nq8k91ad8mwjl7qmppx41zh2wzy.narinfo error="server returned 404: 404 page not found\n"13532026/11/09 12:01:23 INFO Vacuumed table table=pending_objects13542026/11/09 12:01:23 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13552026/11/09 12:01:23 WARN Failed to register uploaded object key=qmsgy2iqrym3gcx2vkrrhk7hdb01jh4f.ls error="server returned 404: 404 page not found\n"1356=== NAME TestClientCADerivations13572026/11/09 12:01:23 INFO Completed upload id=2 objects=6 duration=8.048845ms1358 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1036264312/001/store/pldww60lnl2bbsnflpw4l1dgysx3k5bn-ca-test13592026/11/09 12:01:23 WARN Failed to register uploaded object key=nq11fm1mw591n81cb635xcrklf9b8rwp.ls error="server returned 404: 404 page not found\n"13602026/11/09 12:01:23 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13612026/11/09 12:01:23 WARN Failed to register uploaded object key=nar/1agwdz2pn2ki8gfhgpjgr27vanvbic9qg6yq5rz0drmhmrcikkl1.nar.zst error="server returned 404: 404 page not found\n"13622026/11/09 12:01:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13632026/11/09 12:01:23 INFO Vacuumed table table=multipart_uploads13642026/11/09 12:01:23 INFO Signed narinfos id=1 count=213652026/11/09 12:01:23 INFO Uploading 2 narinfos13662026/11/09 12:01:23 INFO Completed push id=1 objects=8 duration=6.932055ms13672026/11/09 12:01:23 INFO Upload complete. (73ms)13682026/11/09 12:01:23 INFO Completed upload id=1 objects=6 duration=1.494371ms13692026/11/09 12:01:23 INFO Upload complete. (85ms)1370=== NAME TestClientPushesUseOnePush1371 client_pushes_test.go:97: Retrieved narinfo from S3:1372 StorePath: /build/TestClientPushesUseOnePush2231228108/001/store/70sn0nq8k91ad8mwjl7qmppx41zh2wzy-shared-dep1373 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1374 Compression: zstd1375 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821376 NarSize: 1361377 References: 1378 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1379=== NAME TestClientFallsBackToClosures1380 client_pushes_test.go:112: Retrieved narinfo from S3:1381 StorePath: /build/TestClientFallsBackToClosures1386538817/001/store/lbiib28005dfhcp3920vzg47p3ir0kis-shared-dep1382 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1383 Compression: zstd1384 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821385 NarSize: 1361386 References: 1387 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n13882026/11/09 12:01:23 INFO Vacuumed table table=closures1389=== NAME TestClientPushesUseOnePush1390 client_pushes_test.go:97: Retrieved narinfo from S3:1391 StorePath: /build/TestClientPushesUseOnePush2231228108/001/store/52xf5x6bc5dgs9av07h83mk2gpicly1f-a1392 URL: nar/1hb5cg7il3q7ws5alh92kgbvmj7613n4lc4g8rw85bqbpk145cm0.nar.zst1393 Compression: zstd1394 NarHash: sha256:1hb5cg7il3q7ws5alh92kgbvmj7613n4lc4g8rw85bqbpk145cm01395 NarSize: 21613962026/11/09 12:01:23 WARN Failed to register uploaded object key=nq11fm1mw591n81cb635xcrklf9b8rwp.narinfo error="server returned 404: 404 page not found\n"1397 References: /build/TestClientPushesUseOnePush2231228108/001/store/70sn0nq8k91ad8mwjl7qmppx41zh2wzy-shared-dep13982026/11/09 12:01:23 INFO Received complete push request method=POST path=/api/pushes/1/complete1399 CA: text:sha256:1n9058q772vy5y4d6l1820scrrfk4392f099gvi1awhj5804j7nq14002026/11/09 12:01:23 WARN Failed to register uploaded object key=qmsgy2iqrym3gcx2vkrrhk7hdb01jh4f.narinfo error="server returned 404: 404 page not found\n"1401=== NAME TestClientFallsBackToClosures1402 client_pushes_test.go:112: Retrieved narinfo from S3:1403 StorePath: /build/TestClientFallsBackToClosures1386538817/001/store/jsk6b4pzhyc3150h5i32ww09qrzrhim6-a1404 URL: nar/0y55cnsmaigs0p5nv53m6ch2vznkps0l04hxbqq2rrvfp4ii58xd.nar.zst1405 Compression: zstd1406 NarHash: sha256:0y55cnsmaigs0p5nv53m6ch2vznkps0l04hxbqq2rrvfp4ii58xd1407 NarSize: 2161408 References: /build/TestClientFallsBackToClosures1386538817/001/store/lbiib28005dfhcp3920vzg47p3ir0kis-shared-dep1409 CA: text:sha256:1n5k1fwy5vc7b8gf06vi7qpw66kw89rs5arq1pqxrxkg6wglim8i14102026/11/09 12:01:23 INFO Vacuumed table table=objects1411=== NAME TestClientPushesUseOnePush1412 client_pushes_test.go:97: Retrieved narinfo from S3:1413 StorePath: /build/TestClientPushesUseOnePush2231228108/001/store/ywkzidk2wavwjk7hl7p1kvklwlnygiy4-b1414 URL: nar/1hb5cg7il3q7ws5alh92kgbvmj7613n4lc4g8rw85bqbpk145cm0.nar.zst1415 Compression: zstd1416 NarHash: sha256:1hb5cg7il3q7ws5alh92kgbvmj7613n4lc4g8rw85bqbpk145cm01417 NarSize: 2161418 References: /build/TestClientPushesUseOnePush2231228108/001/store/70sn0nq8k91ad8mwjl7qmppx41zh2wzy-shared-dep1419 CA: text:sha256:1n9058q772vy5y4d6l1820scrrfk4392f099gvi1awhj5804j7nq1420=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1421=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1422=== NAME TestClientFallsBackToClosures1423 client_pushes_test.go:112: Retrieved narinfo from S3:1424 StorePath: /build/TestClientFallsBackToClosures1386538817/001/store/brih1gbf2iswpjmyk2rmhy5irlv9nlvc-b1425 URL: nar/0y55cnsmaigs0p5nv53m6ch2vznkps0l04hxbqq2rrvfp4ii58xd.nar.zst1426 Compression: zstd1427 NarHash: sha256:0y55cnsmaigs0p5nv53m6ch2vznkps0l04hxbqq2rrvfp4ii58xd1428 NarSize: 2161429 References: /build/TestClientFallsBackToClosures1386538817/001/store/lbiib28005dfhcp3920vzg47p3ir0kis-shared-dep1430 CA: text:sha256:1n5k1fwy5vc7b8gf06vi7qpw66kw89rs5arq1pqxrxkg6wglim8i1431=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1432=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1433=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1434=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1435=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1436=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1437=== CONT TestReadProxyRangeRequest14382026/11/09 12:01:23 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001439--- PASS: TestService_createPendingClosureHandler (1.06s)1440=== CONT TestPush_SignsNarinfosOfItsPendingObjects1441--- PASS: TestClientPushesUseOnePush (0.79s)1442=== CONT TestReadRedirectKeepsNarinfoProxied14432026/11/09 12:01:23 INFO Completed push id=1 objects=6 duration=7.819695ms14442026/11/09 12:01:23 INFO Upload complete. (74ms)1445--- PASS: TestClientFallsBackToClosures (0.80s)1446=== CONT TestPush_RejectsBadRequests1447=== NAME TestClientSharedPathCommittedMidPush1448 client_integration_test.go:727: Retrieved narinfo from S3:1449 StorePath: /build/TestClientSharedPathCommittedMidPush3061376114/001/store/qmsgy2iqrym3gcx2vkrrhk7hdb01jh4f-shared-dep1450 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1451 Compression: zstd1452 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821453 NarSize: 1361454 References: 1455 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1456 client_integration_test.go:727: Retrieved narinfo from S3:1457 StorePath: /build/TestClientSharedPathCommittedMidPush3061376114/001/store/nq11fm1mw591n81cb635xcrklf9b8rwp-top1458 URL: nar/1agwdz2pn2ki8gfhgpjgr27vanvbic9qg6yq5rz0drmhmrcikkl1.nar.zst1459 Compression: zstd1460 NarHash: sha256:1agwdz2pn2ki8gfhgpjgr27vanvbic9qg6yq5rz0drmhmrcikkl11461 NarSize: 2241462 References: /build/TestClientSharedPathCommittedMidPush3061376114/001/store/qmsgy2iqrym3gcx2vkrrhk7hdb01jh4f-shared-dep14632026/11/09 12:01:23 INFO Received push request method=POST path=/api/pushes1464 CA: text:sha256:0jv0zww2pqrgbqdy1vfinbl2rzzjqjf0mgw4sjh4p50fjyzrxqsk14652026/11/09 12:01:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1466--- PASS: TestClientSharedPathCommittedMidPush (0.74s)1467=== CONT TestReadRedirectNar14682026/11/09 12:01:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14692026/11/09 12:01:23 INFO Uploading kd46x3vr8ix7is363vnh5wm8s4sqzkwz-test-file.txt (152B)14702026/11/09 12:01:23 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"14712026/11/09 12:01:23 WARN mTLS auth: bound subjects configured but subject DN unavailable14722026/11/09 12:01:23 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1473--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.36s)1474=== CONT TestReadProxyDisabled14752026/11/09 12:01:23 WARN Failed to register uploaded object key=kd46x3vr8ix7is363vnh5wm8s4sqzkwz.ls error="server returned 404: 404 page not found\n"14762026/11/09 12:01:23 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14772026/11/09 12:01:23 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"14782026/11/09 12:01:23 INFO Signed narinfos id=1 count=114792026/11/09 12:01:23 INFO Uploading 1 narinfos1480=== NAME TestClientCADerivations1481 client_ca_test.go:139: Found 1 dependencies (including self)14822026/11/09 12:01:23 INFO Received complete push request method=POST path=/api/pushes/1/complete14832026/11/09 12:01:23 WARN Failed to register uploaded object key=kd46x3vr8ix7is363vnh5wm8s4sqzkwz.narinfo error="server returned 404: 404 page not found\n"14842026/11/09 12:01:23 INFO Completed push id=1 objects=3 duration=7.043715ms14852026/11/09 12:01:23 INFO Upload complete. (80ms)1486--- PASS: TestService_Rustfstest (0.34s)1487=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit14882026/11/09 12:01:23 INFO Received push request method=POST path=/api/pushes14892026/11/09 12:01:23 INFO Received push request method=POST path=/api/pushes14902026/11/09 12:01:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14912026/11/09 12:01:23 INFO Uploading 4azmfa7a9n8xnmjnmw5lbv7bwsi1w4ki-unpinned-file.txt (128B)14922026/11/09 12:01:23 WARN Failed to register uploaded object key=4azmfa7a9n8xnmjnmw5lbv7bwsi1w4ki.ls error="server returned 404: 404 page not found\n"14932026/11/09 12:01:23 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14942026/11/09 12:01:23 INFO Signed narinfos id=2 count=114952026/11/09 12:01:23 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"14962026/11/09 12:01:23 INFO Uploading 1 narinfos14972026/11/09 12:01:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14982026/11/09 12:01:23 INFO Uploading 8m7736p48kbz71gcwlja3vd70lm5147c-test-script (136B)14992026/11/09 12:01:23 INFO Received complete push request method=POST path=/api/pushes/2/complete15002026/11/09 12:01:23 WARN Failed to register uploaded object key=4azmfa7a9n8xnmjnmw5lbv7bwsi1w4ki.narinfo error="server returned 404: 404 page not found\n"1501--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.28s)1502=== CONT TestReadProxyRootRedirectsToIndexHTML15032026/11/09 12:01:23 WARN Failed to register uploaded object key=8m7736p48kbz71gcwlja3vd70lm5147c.ls error="server returned 404: 404 page not found\n"15042026/11/09 12:01:23 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15052026/11/09 12:01:23 WARN Failed to register uploaded object key=log/ham0s2igj83z1zgwyddr5acm9h0g9vm1-test-script.drv error="server returned 404: 404 page not found\n"15062026/11/09 12:01:23 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15072026/11/09 12:01:23 INFO Signed narinfos id=1 count=115082026/11/09 12:01:23 INFO Uploading 1 narinfos15092026/11/09 12:01:23 INFO Completed push id=2 objects=3 duration=5.313623ms15102026/11/09 12:01:23 INFO Upload complete. (63ms)15112026/11/09 12:01:23 INFO Received complete push request method=POST path=/api/pushes/1/complete15122026/11/09 12:01:23 WARN Failed to register uploaded object key=8m7736p48kbz71gcwlja3vd70lm5147c.narinfo error="server returned 404: 404 page not found\n"15132026/11/09 12:01:23 INFO Received push request method=POST path=/api/pushes15142026/11/09 12:01:23 INFO Completed push id=1 objects=4 duration=23.572525ms15152026/11/09 12:01:23 INFO All 1 paths already cached15162026/11/09 12:01:23 INFO Upload complete. (90ms)1517=== NAME TestClientIntegration1518 client_integration_test.go:317: Retrieved narinfo from S3:1519 StorePath: /build/TestClientIntegration17016472/002/store/kd46x3vr8ix7is363vnh5wm8s4sqzkwz-test-file.txt1520 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1521 Compression: zstd1522 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11523 NarSize: 1521524 References: 1525 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11526=== NAME TestClientWithDependencies1527 client_integration_test.go:664: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1924211134/001/store) requires matching store prefix1528=== NAME TestClientIntegration1529 client_integration_test.go:318: Retrieved .ls file from S3 (compressed size: 77 bytes)1530 client_integration_test.go:318: Decompressed .ls content (64 bytes):1531 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1532--- PASS: TestClientWithDependencies (0.80s)1533=== CONT TestReadProxy40415342026/11/09 12:01:23 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15352026/11/09 12:01:23 INFO Uploading pmv0814r185pz4kyp0gm6ycyxqh84g41-test-file-2.txt (160B)15362026/11/09 12:01:23 INFO Uploading wv6l6jnh1a1m0z0a510pq418r5n0a0df-test-file-1.txt (160B)15372026/11/09 12:01:23 INFO Uploading 1igbwkdxg6v4wsrhqchgzad287zqfvyx-test-file-0.txt (160B)15382026/11/09 12:01:23 WARN Failed to register uploaded object key=wv6l6jnh1a1m0z0a510pq418r5n0a0df.ls error="server returned 404: 404 page not found\n"15392026/11/09 12:01:23 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15402026/11/09 12:01:23 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15412026/11/09 12:01:23 WARN Failed to register uploaded object key=pmv0814r185pz4kyp0gm6ycyxqh84g41.ls error="server returned 404: 404 page not found\n"15422026/11/09 12:01:23 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15432026/11/09 12:01:23 WARN Failed to register uploaded object key=1igbwkdxg6v4wsrhqchgzad287zqfvyx.ls error="server returned 404: 404 page not found\n"15442026/11/09 12:01:23 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15452026/11/09 12:01:23 INFO Signed narinfos id=1 count=315462026/11/09 12:01:23 INFO Uploading 3 narinfos15472026/11/09 12:01:23 WARN Failed to register uploaded object key=wv6l6jnh1a1m0z0a510pq418r5n0a0df.narinfo error="server returned 404: 404 page not found\n"15482026/11/09 12:01:23 WARN Failed to register uploaded object key=pmv0814r185pz4kyp0gm6ycyxqh84g41.narinfo error="server returned 404: 404 page not found\n"15492026/11/09 12:01:23 INFO Received complete push request method=POST path=/api/pushes/1/complete15502026/11/09 12:01:23 WARN Failed to register uploaded object key=1igbwkdxg6v4wsrhqchgzad287zqfvyx.narinfo error="server returned 404: 404 page not found\n"15512026/11/09 12:01:23 INFO Starting cleanup of old closures method=DELETE path=/api/closures15522026/11/09 12:01:23 INFO Garbage collection started15532026/11/09 12:01:23 INFO Completed push id=1 objects=9 duration=8.771066ms15542026/11/09 12:01:23 INFO Upload complete. (85ms)1555=== NAME TestClientMultipleUploads1556 client_integration_test.go:416: Uploaded 3 paths in 151.795028ms1557--- PASS: TestClientMultipleUploads (0.82s)1558=== CONT TestPush_RootsAreLockedInByteOrder15592026/11/09 12:01:23 INFO Aborted multipart uploads count=0 kept=015602026/11/09 12:01:23 INFO Received push request method=POST path=/api/pushes15612026/11/09 12:01:23 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1562--- PASS: TestService_AuthMiddleware (0.24s)1563=== CONT TestReadProxyNarStreaming15642026/11/09 12:01:23 WARN Force mode enabled - objects will be deleted immediately without grace period15652026/11/09 12:01:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15662026/11/09 12:01:23 INFO Uploading pldww60lnl2bbsnflpw4l1dgysx3k5bn-ca-test (144B)15672026/11/09 12:01:23 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"15682026/11/09 12:01:23 WARN Failed to register uploaded object key=pldww60lnl2bbsnflpw4l1dgysx3k5bn.ls error="server returned 404: 404 page not found\n"15692026/11/09 12:01:23 WARN Failed to register uploaded object key=log/c8r10bcn3vp26rfvjk66w4zkakydnc5z-ca-test.drv error="server returned 404: 404 page not found\n"15702026/11/09 12:01:23 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15712026/11/09 12:01:23 INFO Signed narinfos id=1 count=115722026/11/09 12:01:23 INFO Uploading 1 narinfos15732026/11/09 12:01:23 INFO Received complete push request method=POST path=/api/pushes/1/complete15742026/11/09 12:01:23 WARN Failed to register uploaded object key=pldww60lnl2bbsnflpw4l1dgysx3k5bn.narinfo error="server returned 404: 404 page not found\n"15752026/11/09 12:01:23 INFO Received uploads request method=POST path=/api/pending_closures15762026/11/09 12:01:23 INFO Completed push id=1 objects=4 duration=11.520888ms15772026/11/09 12:01:23 INFO Upload complete. (114ms)1578=== NAME TestClientCADerivations1579 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1036264312/001/store/pldww60lnl2bbsnflpw4l1dgysx3k5bn-ca-test1580 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1581 Compression: zstd1582 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1583 NarSize: 1441584 References: 1585 Deriver: /build/TestClientCADerivations1036264312/001/store/c8r10bcn3vp26rfvjk66w4zkakydnc5z-ca-test.drv1586 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1587 client_ca_test.go:185: Checking for realisation files in S3...1588 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1589 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache15902026/11/09 12:01:23 INFO Received push request method=POST path=/api/pushes15912026/11/09 12:01:23 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=015922026/11/09 12:01:23 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst15932026/11/09 12:01:23 INFO Received uploads request method=POST path=/api/pending_closures15942026/11/09 12:01:23 INFO Object in database but missing from S3 key=kd46x3vr8ix7is363vnh5wm8s4sqzkwz.ls15952026/11/09 12:01:23 WARN Found objects in DB but missing from S3, will re-upload count=115962026/11/09 12:01:23 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1597--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.31s)1598=== CONT TestPush_CompleteWaitsForCleanupOfThePush15992026/11/09 12:01:23 INFO Vacuumed table table=pending_closures16002026/11/09 12:01:23 INFO Received complete push request method=POST path=/api/pushes/2/complete16012026/11/09 12:01:23 WARN Failed to register uploaded object key=kd46x3vr8ix7is363vnh5wm8s4sqzkwz.ls error="server returned 404: 404 page not found\n"16022026/11/09 12:01:23 INFO Vacuumed table table=pending_objects16032026/11/09 12:01:23 INFO Vacuumed table table=multipart_uploads16042026/11/09 12:01:23 INFO Completed push id=2 objects=3 duration=2.769852ms16052026/11/09 12:01:23 INFO Upload complete. (64ms)1606=== NAME TestClientIntegration1607 client_integration_test.go:335: Retrieved .ls file from S3 (compressed size: 62 bytes)1608 client_integration_test.go:335: Decompressed .ls content (49 bytes):1609 {"version":1,"root":{"type":"regular","size":39}}16102026/11/09 12:01:23 INFO Vacuumed table table=closures16112026/11/09 12:01:23 INFO Vacuumed table table=objects16122026/11/09 12:01:23 INFO Received uploads request method=POST path=/api/pending_closures16132026/11/09 12:01:23 INFO Received uploads request method=POST path=/api/pending_closures1614--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.32s)1615=== CONT TestReadProxyContentNegotiation16162026/11/09 12:01:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16172026/11/09 12:01:23 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YjZmZmY5MmItZmM0NC00MjRiLWE2OGUtNDI0OTA1OTA5ODgwLjdhNGQyMDg3LTY1NzEtNDhkOS04YTY2LTMzMjgwMzFjMTU2ZngxNzk0MjI1NjgzNjczNDE5MzQ216182026/11/09 12:01:23 INFO Received uploads request method=POST path=/api/pending_closures16192026/11/09 12:01:23 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YjZmZmY5MmItZmM0NC00MjRiLWE2OGUtNDI0OTA1OTA5ODgwLjdhNGQyMDg3LTY1NzEtNDhkOS04YTY2LTMzMjgwMzFjMTU2ZngxNzk0MjI1NjgzNjczNDE5MzQ2 parts=116202026/11/09 12:01:23 INFO Received push request method=POST path=/api/pushes1621--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.36s)1622=== CONT TestPush_RepeatedRootCommitsOnce16232026/11/09 12:01:23 INFO Received uploads request method=POST path=/api/pending_closures16242026/11/09 12:01:23 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16252026/11/09 12:01:23 INFO Received complete push request method=POST path=/api/pushes/3/complete16262026/11/09 12:01:23 WARN Failed to register uploaded object key=kd46x3vr8ix7is363vnh5wm8s4sqzkwz.ls error="server returned 404: 404 page not found\n"16272026/11/09 12:01:23 INFO Completed push id=3 objects=3 duration=1.881611ms16282026/11/09 12:01:23 INFO Upload complete. (59ms)1629=== NAME TestClientIntegration1630 client_integration_test.go:352: Retrieved .ls file from S3 (compressed size: 62 bytes)1631 client_integration_test.go:352: Decompressed .ls content (49 bytes):1632 {"version":1,"root":{"type":"regular","size":39}}1633 client_integration_test.go:363: Testing garbage collection...1634--- PASS: TestReadRedirectKeepsNarinfoProxied (0.35s)1635=== CONT TestReadProxyOutlastsServerWriteTimeout16362026/11/09 12:01:23 INFO Received push request method=POST path=/api/pushes16372026/11/09 12:01:23 INFO Starting cleanup of old closures method=DELETE path=/api/closures16382026/11/09 12:01:23 INFO Garbage collection started16392026/11/09 12:01:23 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16402026/11/09 12:01:23 INFO Signed narinfos id=1 count=116412026/11/09 12:01:23 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16422026/11/09 12:01:23 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16432026/11/09 12:01:23 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"16442026/11/09 12:01:23 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16452026/11/09 12:01:23 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"16462026/11/09 12:01:23 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16472026/11/09 12:01:23 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=116482026/11/09 12:01:23 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16492026/11/09 12:01:23 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1650--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.38s)1651=== CONT TestReadProxyConditionalGet1652--- PASS: TestReadRedirectNar (0.38s)1653=== CONT TestPush_CompleteCommitsEveryRoot16542026/11/09 12:01:23 INFO Aborted multipart uploads count=0 kept=016552026/11/09 12:01:23 WARN Force mode enabled - objects will be deleted immediately without grace period1656--- PASS: TestReadProxyRangeRequest (0.41s)1657=== CONT TestCreatePin_ReservedPins1658--- PASS: TestReadProxyDisabled (0.40s)1659=== CONT TestReadProxyNarinfo16602026/11/09 12:01:23 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=01661=== RUN TestPush_RejectsBadRequests/bad_root1662=== PAUSE TestPush_RejectsBadRequests/bad_root1663=== RUN TestPush_RejectsBadRequests/root_not_in_objects1664=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1665=== RUN TestPush_RejectsBadRequests/no_roots1666=== PAUSE TestPush_RejectsBadRequests/no_roots1667=== RUN TestPush_RejectsBadRequests/no_objects1668=== PAUSE TestPush_RejectsBadRequests/no_objects1669=== CONT TestPush_OverlappingRootsStoreOneRowPerKey16702026/11/09 12:01:23 INFO Vacuumed table table=pending_closures16712026/11/09 12:01:23 INFO Vacuumed table table=pending_objects16722026/11/09 12:01:23 INFO Vacuumed table table=multipart_uploads16732026/11/09 12:01:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36089/oidc16742026/11/09 12:01:23 INFO Vacuumed table table=closures16752026/11/09 12:01:23 INFO Vacuumed table table=objects16762026/11/09 12:01:23 INFO Received push request method=POST path=/api/pushes1677--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.42s)1678=== CONT TestIsValidCachePath1679=== RUN TestIsValidCachePath/narinfo1680=== PAUSE TestIsValidCachePath/narinfo1681=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1682=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1683=== RUN TestIsValidCachePath/nar_zst1684=== PAUSE TestIsValidCachePath/nar_zst1685=== RUN TestIsValidCachePath/nar_xz16862026/11/09 12:01:23 INFO Received complete push request method=POST path=/api/pushes/1/complete1687=== PAUSE TestIsValidCachePath/nar_xz1688=== RUN TestIsValidCachePath/nar_bz21689=== PAUSE TestIsValidCachePath/nar_bz21690=== RUN TestIsValidCachePath/nar_uncompressed1691=== PAUSE TestIsValidCachePath/nar_uncompressed1692=== RUN TestIsValidCachePath/ls1693=== PAUSE TestIsValidCachePath/ls1694=== RUN TestIsValidCachePath/log1695=== PAUSE TestIsValidCachePath/log1696=== RUN TestIsValidCachePath/realisation1697=== PAUSE TestIsValidCachePath/realisation1698=== RUN TestIsValidCachePath/nix-cache-info1699=== PAUSE TestIsValidCachePath/nix-cache-info1700=== RUN TestIsValidCachePath/index.html1701=== PAUSE TestIsValidCachePath/index.html1702=== RUN TestIsValidCachePath/traversal_parent1703=== PAUSE TestIsValidCachePath/traversal_parent1704=== RUN TestIsValidCachePath/traversal_in_middle1705=== PAUSE TestIsValidCachePath/traversal_in_middle1706=== RUN TestIsValidCachePath/invalid_char_e1707=== PAUSE TestIsValidCachePath/invalid_char_e1708=== RUN TestIsValidCachePath/invalid_char_u1709=== PAUSE TestIsValidCachePath/invalid_char_u1710=== RUN TestIsValidCachePath/random_path1711=== PAUSE TestIsValidCachePath/random_path1712=== RUN TestIsValidCachePath/empty1713=== PAUSE TestIsValidCachePath/empty1714=== RUN TestIsValidCachePath/leading_slash1715=== PAUSE TestIsValidCachePath/leading_slash1716=== RUN TestIsValidCachePath/wrong_extension1717=== PAUSE TestIsValidCachePath/wrong_extension1718=== RUN TestIsValidCachePath/short_hash1719=== PAUSE TestIsValidCachePath/short_hash1720=== CONT TestParseSingleRange1721=== RUN TestParseSingleRange/none1722=== PAUSE TestParseSingleRange/none1723=== RUN TestParseSingleRange/unknown_unit1724=== PAUSE TestParseSingleRange/unknown_unit1725=== RUN TestParseSingleRange/multi-range_ignored1726=== PAUSE TestParseSingleRange/multi-range_ignored1727=== RUN TestParseSingleRange/malformed_no_dash1728=== PAUSE TestParseSingleRange/malformed_no_dash1729=== RUN TestParseSingleRange/malformed_both_empty1730=== PAUSE TestParseSingleRange/malformed_both_empty1731=== RUN TestParseSingleRange/malformed_end_before_start1732=== PAUSE TestParseSingleRange/malformed_end_before_start1733=== RUN TestParseSingleRange/closed1734=== PAUSE TestParseSingleRange/closed1735=== RUN TestParseSingleRange/open-ended1736=== PAUSE TestParseSingleRange/open-ended1737=== RUN TestParseSingleRange/end_clamped_to_size1738=== PAUSE TestParseSingleRange/end_clamped_to_size1739=== RUN TestParseSingleRange/suffix1740=== PAUSE TestParseSingleRange/suffix1741=== RUN TestParseSingleRange/suffix_exceeds_size1742=== PAUSE TestParseSingleRange/suffix_exceeds_size1743=== RUN TestParseSingleRange/single_byte1744=== PAUSE TestParseSingleRange/single_byte1745=== RUN TestParseSingleRange/start_past_EOF1746=== PAUSE TestParseSingleRange/start_past_EOF1747=== RUN TestParseSingleRange/start_far_past_EOF1748=== PAUSE TestParseSingleRange/start_far_past_EOF1749=== CONT TestPresentNotReportedWhileGCDeletesClosure1750=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1751=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1752=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1753=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1754=== CONT TestPresentRefreshesOnlyStaleClosures17552026/11/09 12:01:23 INFO Completed push id=1 objects=4 duration=7.952935ms17562026/11/09 12:01:23 INFO Received push request method=POST path=/api/pushes1757=== NAME TestClientCADerivations1758 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1759 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1760 error: binary cache 's3://bucket47?endpoint=http://localhost:42599®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1036264312/001/store'1761 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11762--- PASS: TestClientCADerivations (1.14s)1763=== CONT TestReadProxyHead1764--- PASS: TestReadProxyNarStreaming (0.37s)1765=== CONT TestPresentReportsOnlyClosureRoots17662026/11/09 12:01:23 INFO Received push request method=POST path=/api/pushes1767--- PASS: TestReadProxy404 (0.45s)1768=== CONT TestObjectStatsUpdatedOncePerCommit17692026/11/09 12:01:23 INFO Aborted multipart uploads count=0 kept=017702026/11/09 12:01:23 INFO lead: released remote=192.0.2.1:12341771--- PASS: TestLeadEndsOnShutdown (1.73s)1772=== CONT TestOrphanedObjectsGCStressTest17732026/11/09 12:01:23 WARN Force mode enabled - objects will be deleted immediately without grace period17742026/11/09 12:01:23 INFO Received push request method=POST path=/api/pushes17752026/11/09 12:01:23 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=017762026/11/09 12:01:23 INFO Vacuumed table table=pending_closures17772026/11/09 12:01:23 INFO Vacuumed table table=pending_objects17782026/11/09 12:01:23 INFO Vacuumed table table=multipart_uploads17792026/11/09 12:01:23 INFO Vacuumed table table=closures17802026/11/09 12:01:23 INFO Vacuumed table table=objects17812026/11/09 12:01:23 INFO Received complete push request method=POST path=/api/pushes/2/complete17822026-11-09 12:01:23.991 UTC [2042] ERROR: could not obtain lock on row in relation "closures"17832026-11-09 12:01:23.991 UTC [2042] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT17842026-11-09 12:01:23.992 UTC [2042] ERROR: could not obtain lock on row in relation "closures"17852026-11-09 12:01:23.992 UTC [2042] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT17862026-11-09 12:01:23.992 UTC [2042] ERROR: could not obtain lock on row in relation "closures"17872026-11-09 12:01:23.992 UTC [2042] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT17882026-11-09 12:01:23.993 UTC [2042] ERROR: could not obtain lock on row in relation "closures"17892026-11-09 12:01:23.993 UTC [2042] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT17902026-11-09 12:01:23.993 UTC [2042] ERROR: could not obtain lock on row in relation "closures"17912026-11-09 12:01:23.993 UTC [2042] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT17922026/11/09 12:01:23 INFO Completed push id=2 objects=4 duration=4.925573ms1793--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.56s)1794=== CONT TestOrphanedObjectsGC1795--- PASS: TestPush_RootsAreLockedInByteOrder (0.47s)1796=== CONT TestPendingCleanupUsesOneCutoff17972026/11/09 12:01:24 INFO Received push request method=POST path=/api/pushes17982026/11/09 12:01:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17992026/11/09 12:01:24 INFO Received complete push request method=POST path=/api/pushes/1/complete18002026/11/09 12:01:24 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YjZmZmY5MmItZmM0NC00MjRiLWE2OGUtNDI0OTA1OTA5ODgwLjYwZjAwNDUyLWM2OTEtNGNmNC1iZmZhLTBkODc5ZWJjNDE4M3gxNzk0MjI1NjgzNjUwOTYwODAy parts=1218012026/11/09 12:01:24 INFO Received uploads request method=POST path=/api/pending_closures1802--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.70s)1803=== CONT TestReadProxyInvalidPath1804--- PASS: TestReadProxyContentNegotiation (0.35s)1805=== CONT TestObjectStatsTrigger18062026/11/09 12:01:24 INFO Completed push id=1 objects=4 duration=12.518478ms1807--- PASS: TestPush_RepeatedRootCommitsOnce (0.34s)1808=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1809--- PASS: TestReadProxyConditionalGet (0.28s)1810=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows18112026/11/09 12:01:24 INFO Received push request method=POST path=/api/pushes18122026/11/09 12:01:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18132026/11/09 12:01:24 INFO Received complete push request method=POST path=/api/pushes/1/complete18142026/11/09 12:01:24 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YjZmZmY5MmItZmM0NC00MjRiLWE2OGUtNDI0OTA1OTA5ODgwLjdiN2RiYTZmLTVjYjUtNDJmMS05YjgxLTE4MDM3YjcxMjgwNXgxNzk0MjI1NjgzNzExNzIyNjMx parts=1218152026/11/09 12:01:24 INFO Received push request method=POST path=/api/pushes18162026/11/09 12:01:24 INFO Completed push id=1 objects=6 duration=11.740748ms1817--- PASS: TestPush_CompleteCommitsEveryRoot (0.34s)1818=== CONT TestServerTLSConfig/no_client_CA1819=== CONT TestServerTLSConfig/not_a_PEM_file1820=== CONT TestServerTLSConfig/missing_CA_file1821--- PASS: TestServerTLSConfig (0.01s)1822 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1823 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1824 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1825=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1826--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.30s)1827=== CONT TestGCEndsOnShutdown/before_the_run18282026/11/09 12:01:24 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18292026/11/09 12:01:24 WARN Refused reserved pin name=worker-x86_64-linux18302026/11/09 12:01:24 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18312026/11/09 12:01:24 INFO Received create pin request method=POST path=/api/pins/my-app18322026/11/09 12:01:24 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18332026/11/09 12:01:24 INFO lead: released remote=192.0.2.1:12341834--- PASS: TestCreatePin_ReservedPins (0.34s)1835=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1836--- PASS: TestPresentRefreshesOnlyStaleClosures (0.30s)1837=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1838--- PASS: TestReadProxyHead (0.29s)1839=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed18402026/11/09 12:01:24 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1841--- PASS: TestReadProxyNarinfo (0.38s)1842=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed18432026/11/09 12:01:24 INFO lead: acquired remote=192.0.2.1:12341844--- PASS: TestPresentReportsOnlyClosureRoots (0.29s)1845=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed18462026/11/09 12:01:24 INFO Received uploads request method=POST path=/api/pending_closures18472026-11-09 12:01:24.276 UTC [2047] ERROR: Push does not exist: id=118482026-11-09 12:01:24.276 UTC [2047] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE18492026-11-09 12:01:24.276 UTC [2047] STATEMENT: SELECT commit_push($1)1850--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.67s)1851=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost18522026/11/09 12:01:24 INFO Received uploads request method=POST path=/api/pending_closures18532026/11/09 12:01:24 INFO Received cleanup request method=DELETE path=/api/pending_closures1854--- PASS: TestObjectStatsUpdatedOncePerCommit (0.36s)1855=== CONT TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed1856--- PASS: TestObjectStatsTrigger (0.28s)1857=== CONT TestResolveDBConnectionString/flag_wins1858=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1859=== CONT TestResolveDBConnectionString/nothing_configured1860=== CONT TestResolveDBConnectionString/missing_file_is_an_error1861=== CONT TestResolveDBConnectionString/file_when_flag_empty1862=== CONT TestRetryableCompletionError/invalid_part1863=== CONT TestRetryableCompletionError/transport_failure1864=== CONT TestRetryableCompletionError/no_such_upload1865=== CONT TestRetryableCompletionError/bad_gateway1866=== CONT TestRetryableCompletionError/nil1867=== CONT TestRetryableCompletionError/access_denied1868=== CONT TestRetryableCompletionError/deadline_exceeded1869--- PASS: TestResolveDBConnectionString (0.00s)1870 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1871 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1872 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1873 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1874 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1875=== CONT TestRetryableCompletionError/degraded_quorum1876=== CONT TestRetryableCompletionError/context_canceled1877=== CONT TestRetryableCompletionError/throttled1878--- PASS: TestRetryableCompletionError (0.00s)1879 --- PASS: TestRetryableCompletionError/invalid_part (0.00s)1880 --- PASS: TestRetryableCompletionError/transport_failure (0.00s)1881 --- PASS: TestRetryableCompletionError/no_such_upload (0.00s)1882 --- PASS: TestRetryableCompletionError/bad_gateway (0.00s)1883 --- PASS: TestRetryableCompletionError/nil (0.00s)1884 --- PASS: TestRetryableCompletionError/access_denied (0.00s)1885 --- PASS: TestRetryableCompletionError/deadline_exceeded (0.00s)1886 --- PASS: TestRetryableCompletionError/degraded_quorum (0.00s)1887 --- PASS: TestRetryableCompletionError/context_canceled (0.00s)1888 --- PASS: TestRetryableCompletionError/throttled (0.00s)1889=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18902026/11/09 12:01:24 INFO Received uploads request method=POST path=/1891=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18922026/11/09 12:01:24 INFO Received complete multipart upload request method=POST path=/1893=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18942026/11/09 12:01:24 INFO Received request for more parts method=POST path=/1895=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18962026/11/09 12:01:24 INFO Received uploads request method=POST path=/1897--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1898 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1899 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1900 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1901 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1902=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19032026/11/09 12:01:24 INFO Received uploads request method=POST path=/19042026/11/09 12:01:24 INFO Received uploads request method=POST path=/api/pending_closures1905--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.30s)1906=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts19072026/11/09 12:01:24 INFO Received request for more parts method=POST path=/1908--- PASS: TestReadProxyInvalidPath (0.31s)1909=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19102026/11/09 12:01:24 INFO Received complete multipart upload request method=POST path=/19112026/11/09 12:01:24 INFO Received uploads request method=POST path=/api/pending_closures1912=== CONT TestIsValidUploadKey/narinfo1913=== CONT TestIsValidUploadKey/realisation_plus_in_output1914=== CONT TestIsValidUploadKey/unknown_type1915=== CONT TestIsValidUploadKey/empty_key1916=== CONT TestIsValidUploadKey/absolute1917=== CONT TestIsValidUploadKey/traversal_nar1918=== CONT TestIsValidUploadKey/traversal1919=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1920=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1921=== CONT TestIsValidUploadKey/build_log_home-manager_file1922=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1923=== CONT TestIsValidUploadKey/realisation1924=== CONT TestIsValidUploadKey/index.html1925=== CONT TestIsValidUploadKey/build_log_equals1926=== CONT TestIsValidUploadKey/nix-cache-info1927=== CONT TestIsValidUploadKey/build_log_question_mark1928=== CONT TestIsValidUploadKey/build_log_plus_in_name1929=== CONT TestIsValidUploadKey/nar_plain1930=== CONT TestIsValidUploadKey/listing1931=== CONT TestIsValidUploadKey/build_log1932=== CONT TestIsValidUploadKey/nar_zst1933=== CONT TestIsValidUploadKey/nar_xz1934=== CONT TestPendingClosureWriteTimeout/empty1935--- PASS: TestIsValidUploadKey (0.00s)1936 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1937 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1938 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1939 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1940 --- PASS: TestIsValidUploadKey/absolute (0.00s)1941 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1942 --- PASS: TestIsValidUploadKey/traversal (0.00s)1943 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1944 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1945 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1946 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1947 --- PASS: TestIsValidUploadKey/realisation (0.00s)1948 --- PASS: TestIsValidUploadKey/index.html (0.00s)1949 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1950 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1951 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1952 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1953 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1954 --- PASS: TestIsValidUploadKey/listing (0.00s)1955 --- PASS: TestIsValidUploadKey/build_log (0.00s)1956 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1957 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1958=== CONT TestPendingClosureWriteTimeout/670k_objects1959=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1960=== CONT TestPendingClosureWriteTimeout/400_objects1961=== CONT TestProxyWriteTimeout/narinfo1962=== CONT TestProxyWriteTimeout/10_GiB_nar1963=== CONT TestProxyWriteTimeout/unknown_size1964=== CONT TestProxyWriteTimeout/1_GiB_nar1965--- PASS: TestProxyWriteTimeout (0.00s)1966 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1967 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1968 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1969 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1970=== CONT TestClientErrorHandling/InvalidStorePath19712026/11/09 12:01:24 INFO Aborted multipart uploads count=0 kept=019722026/11/09 12:01:24 WARN Force mode enabled - objects will be deleted immediately without grace period19732026/11/09 12:01:24 INFO Received uploads request method=POST path=/api/pending_closures19742026/11/09 12:01:24 INFO Aborted multipart uploads count=0 kept=01975=== CONT TestClientErrorHandling/ServerNotAvailable19762026/11/09 12:01:24 WARN Force mode enabled - objects will be deleted immediately without grace period19772026/11/09 12:01:24 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=019782026/11/09 12:01:24 INFO Vacuumed table table=pending_closures19792026/11/09 12:01:24 INFO Vacuumed table table=pending_objects19802026/11/09 12:01:24 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=019812026/11/09 12:01:24 INFO Vacuumed table table=multipart_uploads19822026/11/09 12:01:24 INFO Vacuumed table table=closures19832026/11/09 12:01:24 INFO Vacuumed table table=pending_closures19842026/11/09 12:01:24 INFO Vacuumed table table=objects19852026/11/09 12:01:24 INFO Vacuumed table table=pending_objects19862026/11/09 12:01:24 INFO Vacuumed table table=multipart_uploads19872026/11/09 12:01:24 INFO Vacuumed table table=closures19882026/11/09 12:01:24 INFO Vacuumed table table=objects1989=== CONT TestClientErrorHandling/InvalidAuthToken1990--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1991 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.33s)1992 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.40s)1993=== CONT TestCacheConfigHandler/full_config,_no_issuer1994=== CONT TestCacheConfigHandler/no_signing_keys1995=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1996=== CONT TestCacheConfigHandler/no_cache_url_configured1997--- PASS: TestCacheConfigHandler (0.00s)1998 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1999 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2000 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2001 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2002=== CONT TestService_RequireScope_OIDC/builder_may_write2003=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2004=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2005=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2006=== CONT TestService_RequireScope_OIDC/writer_implies_read2007=== CONT TestService_RequireScope_OIDC/reader_may_read2008=== CONT TestService_RequireScope_OIDC/static_token_may_write2009=== CONT TestService_RequireScope_OIDC/static_token_may_admin2010=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read20112026/11/09 12:01:24 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]2012=== CONT TestService_RequireScope_OIDC/reader_may_not_write2013=== CONT TestService_RequireScope_OIDC/ops_may_not_write2014=== CONT TestService_RequireScope_OIDC/ops_may_admin2015=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2016=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2017=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2018--- PASS: TestService_RequireScope_OIDC (0.55s)2019 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2020 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2021 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2022 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2023 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2024 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2025 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2026 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2027 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2028 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2029 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2030 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2031 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2032 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2033=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20342026/11/09 12:01:24 INFO Aborted multipart uploads count=0 kept=020352026/11/09 12:01:24 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]2036=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20372026/11/09 12:01:24 WARN Authentication failed token_preview=eyJhbGciOi...ps7Y4hlQ1A token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2038=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2039=== CONT TestPush_RejectsBadRequests/bad_root20402026/11/09 12:01:24 INFO Received push request method=POST path=/api/pushes2041=== CONT TestPush_RejectsBadRequests/no_roots20422026/11/09 12:01:24 INFO Received push request method=POST path=/api/pushes2043=== CONT TestPush_RejectsBadRequests/no_objects20442026/11/09 12:01:24 INFO Received push request method=POST path=/api/pushes2045=== CONT TestPush_RejectsBadRequests/root_not_in_objects20462026/11/09 12:01:24 INFO Received push request method=POST path=/api/pushes2047=== CONT TestIsValidCachePath/narinfo2048=== CONT TestIsValidCachePath/index.html2049--- PASS: TestPush_RejectsBadRequests (0.44s)2050 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2051 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2052 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2053 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2054=== CONT TestIsValidCachePath/short_hash2055=== CONT TestIsValidCachePath/wrong_extension2056=== CONT TestIsValidCachePath/leading_slash2057=== CONT TestIsValidCachePath/empty2058=== CONT TestIsValidCachePath/random_path2059=== CONT TestIsValidCachePath/nar_uncompressed2060=== CONT TestIsValidCachePath/invalid_char_u2061--- PASS: TestService_AuthMiddleware_OIDC (0.50s)2062 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2063 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2064 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2065 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2066=== CONT TestIsValidCachePath/nix-cache-info2067=== CONT TestIsValidCachePath/invalid_char_e2068=== CONT TestIsValidCachePath/realisation2069=== CONT TestIsValidCachePath/traversal_in_middle2070=== CONT TestIsValidCachePath/log2071=== CONT TestIsValidCachePath/ls2072=== CONT TestIsValidCachePath/nar_xz2073=== CONT TestIsValidCachePath/traversal_parent2074=== CONT TestIsValidCachePath/nar_zst2075=== CONT TestIsValidCachePath/nar_bz22076=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2077=== CONT TestParseSingleRange/none2078=== CONT TestParseSingleRange/open-ended2079=== CONT TestParseSingleRange/start_far_past_EOF2080=== CONT TestParseSingleRange/start_past_EOF2081=== CONT TestParseSingleRange/single_byte2082=== CONT TestParseSingleRange/suffix_exceeds_size20832026/11/09 12:01:24 WARN Force mode enabled - objects will be deleted immediately without grace period2084=== CONT TestParseSingleRange/suffix2085=== CONT TestParseSingleRange/end_clamped_to_size2086=== CONT TestParseSingleRange/malformed_both_empty2087=== CONT TestParseSingleRange/closed2088=== CONT TestParseSingleRange/malformed_end_before_start2089=== CONT TestParseSingleRange/multi-range_ignored2090=== CONT TestParseSingleRange/unknown_unit2091=== CONT TestParseSingleRange/malformed_no_dash2092=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale2093--- PASS: TestIsValidCachePath (0.00s)2094 --- PASS: TestIsValidCachePath/narinfo (0.00s)2095 --- PASS: TestIsValidCachePath/index.html (0.00s)2096 --- PASS: TestIsValidCachePath/short_hash (0.00s)2097 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2098 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2099 --- PASS: TestIsValidCachePath/empty (0.00s)2100 --- PASS: TestIsValidCachePath/random_path (0.00s)2101 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2102 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2103 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2104 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2105 --- PASS: TestIsValidCachePath/realisation (0.00s)2106 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2107 --- PASS: TestIsValidCachePath/log (0.00s)2108 --- PASS: TestIsValidCachePath/ls (0.00s)2109 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2110 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2111 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2112 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2113 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2114--- PASS: TestParseSingleRange (0.00s)2115 --- PASS: TestParseSingleRange/none (0.00s)2116 --- PASS: TestParseSingleRange/open-ended (0.00s)2117 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2118 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2119 --- PASS: TestParseSingleRange/single_byte (0.00s)2120 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2121 --- PASS: TestParseSingleRange/suffix (0.00s)2122 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2123 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2124 --- PASS: TestParseSingleRange/closed (0.00s)2125 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2126 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2127 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2128 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)21292026/11/09 12:01:24 INFO Aborted multipart uploads count=0 kept=021302026/11/09 12:01:24 INFO Received uploads request method=POST path=/api/pending_closures21312026/11/09 12:01:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21322026/11/09 12:01:24 WARN Force mode enabled - objects will be deleted immediately without grace period2133=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh21342026/11/09 12:01:24 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:42599/bucket97/?delete=\": context canceled"2135--- PASS: TestGCEndsOnShutdown (0.00s)2136 --- PASS: TestGCEndsOnShutdown/before_the_run (0.29s)2137 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.34s)2138 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.31s)21392026/11/09 12:01:24 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YjZmZmY5MmItZmM0NC00MjRiLWE2OGUtNDI0OTA1OTA5ODgwLmNkZDBkNjVkLWMyYzktNGY4Zi1hY2U4LTA5MDE3Y2RmMmExOHgxNzk0MjI1NjgzNzE4NjY1ODc2 parts=122140--- PASS: TestSharedNarBothUploadsComplete (1.13s)21412026/11/09 12:01:24 INFO Received uploads request method=POST path=/api/pending_closures2142--- PASS: TestDeleteClosuresRacingPins (2.03s)21432026/11/09 12:01:24 INFO Received uploads request method=POST path=/api/pending_closures21442026/11/09 12:01:24 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/present21452026/11/09 12:01:24 INFO Received uploads request method=POST path=/api/pending_closures21462026/11/09 12:01:24 INFO Received uploads request method=POST path=/api/pending_closures21472026/11/09 12:01:24 WARN Request failed, retrying attempt=2 backoff=188.893622ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21482026/11/09 12:01:24 INFO Received uploads request method=POST path=/api/pending_closures2149=== NAME TestOrphanedObjectsGC2150 orphaned_objects_gc_test.go:287: GC Test Summary:2151 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A2152 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B2153 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)2154 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)2155 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects2156--- PASS: TestOrphanedObjectsGC (0.83s)21572026/11/09 12:01:24 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21582026/11/09 12:01:24 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21592026/11/09 12:01:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21602026/11/09 12:01:24 WARN Request failed, retrying attempt=3 backoff=382.459283ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21612026/11/09 12:01:24 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst upload_id=YjZmZmY5MmItZmM0NC00MjRiLWE2OGUtNDI0OTA1OTA5ODgwLjViOTBkNzk4LTg4MDktNDkxNi1hMDdhLWQ2ZDU1ZTI3MTZjNngxNzk0MjI1Njg0NTA1MDM3MDA0 parts=1021622026/11/09 12:01:24 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21632026/11/09 12:01:24 INFO Completed upload id=1 objects=3 duration=1.643131ms21642026/11/09 12:01:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21652026/11/09 12:01:24 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst upload_id=YjZmZmY5MmItZmM0NC00MjRiLWE2OGUtNDI0OTA1OTA5ODgwLjY2YTc2MDAxLWQ5NDAtNGM3NC05NzYzLWRjZTkxYjIwMjBjYXgxNzk0MjI1Njg0NDg0OTEyMjYx parts=1021662026/11/09 12:01:24 INFO Received uploads request method=POST path=/api/pending_closures21672026/11/09 12:01:24 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21682026/11/09 12:01:25 INFO Completed upload id=1 objects=3 duration=1.861142ms21692026/11/09 12:01:25 INFO Received uploads request method=POST path=/api/pending_closures21702026/11/09 12:01:25 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst21712026/11/09 12:01:25 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0001.narinfo21722026/11/09 12:01:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21732026/11/09 12:01:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21742026/11/09 12:01:25 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000200000000000000000000.nar.zst upload_id=YjZmZmY5MmItZmM0NC00MjRiLWE2OGUtNDI0OTA1OTA5ODgwLjk5M2VlNjQzLTk3ZjktNGNhOS1iYTA3LTRkZDJmOWQwNGIwZHgxNzk0MjI1Njg0NTY1OTAwNDcz parts=1021752026/11/09 12:01:25 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst upload_id=YjZmZmY5MmItZmM0NC00MjRiLWE2OGUtNDI0OTA1OTA5ODgwLjcyZmNmMjY2LTBkY2YtNGRjYS05Yjk3LTAzYTI3ZGRkYWVkNHgxNzk0MjI1Njg0NTM2ODUwMjE0 parts=1021762026/11/09 12:01:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21772026/11/09 12:01:25 INFO Completed upload id=1 objects=3 duration=1.766901ms21782026/11/09 12:01:25 INFO Received uploads request method=POST path=/api/pending_closures21792026/11/09 12:01:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21802026/11/09 12:01:25 INFO Completed upload id=1 objects=3 duration=1.861301ms21812026/11/09 12:01:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21822026/11/09 12:01:25 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst upload_id=YjZmZmY5MmItZmM0NC00MjRiLWE2OGUtNDI0OTA1OTA5ODgwLjgwM2U3MTg2LTc5NTYtNDgyZS05N2YzLWViMTIxMmEwNjJmZHgxNzk0MjI1Njg0NTQ3Mzk0NTYx parts=1021832026/11/09 12:01:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21842026/11/09 12:01:25 INFO Completed upload id=1 objects=3 duration=1.859781ms21852026/11/09 12:01:25 INFO Received uploads request method=POST path=/api/pending_closures21862026/11/09 12:01:25 INFO Received uploads request method=POST path=/api/pending_closures21872026/11/09 12:01:25 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst21882026/11/09 12:01:25 WARN Found objects in DB but missing from S3, will re-upload count=12189--- PASS: TestUploadHandlersRejectOversizedBody (0.16s)2190 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)2191 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.04s)2192 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.79s)21932026/11/09 12:01:25 INFO lead: released remote=192.0.2.1:12342194--- PASS: TestLeadElectsOneAndHandsOver (2.99s)21952026/11/09 12:01:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21962026/11/09 12:01:25 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100400000000000000000000.nar.zst upload_id=YjZmZmY5MmItZmM0NC00MjRiLWE2OGUtNDI0OTA1OTA5ODgwLjQxOGU2MTA0LTc3NGQtNGI5OC05MTQwLTAwMjdhNTQ3Mjg2ZHgxNzk0MjI1Njg1MDAzODgzNzU2 parts=1021972026/11/09 12:01:25 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21982026/11/09 12:01:25 INFO Completed upload id=2 objects=3 duration=789.901µs21992026/11/09 12:01:25 INFO Received uploads request method=POST path=/api/pending_closures22002026/11/09 12:01:25 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst22012026/11/09 12:01:25 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0004.narinfo22022026/11/09 12:01:25 WARN Request failed, retrying attempt=4 backoff=835.633791ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2203--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2204 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.87s)2205 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.87s)22062026/11/09 12:01:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22072026/11/09 12:01:25 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100300000000000000000000.nar.zst upload_id=YjZmZmY5MmItZmM0NC00MjRiLWE2OGUtNDI0OTA1OTA5ODgwLjY3MDRiZDlmLTkxODMtNDYwZC1iYTI0LTczZTdhYmYxMTIwYngxNzk0MjI1Njg1MDYwNDkxMDEz parts=1022082026/11/09 12:01:25 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22092026/11/09 12:01:25 INFO Completed upload id=2 objects=3 duration=906.901µs22102026/11/09 12:01:25 INFO Received uploads request method=POST path=/api/pending_closures22112026/11/09 12:01:25 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst22122026/11/09 12:01:25 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0003.narinfo2213--- PASS: TestService_verifyS3ReuploadsStaleNarinfo (0.00s)2214 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed (0.82s)2215 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed (0.73s)2216 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed (0.85s)2217 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed (1.14s)2218 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost (1.13s)22192026/11/09 12:01:25 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=022202026/11/09 12:01:25 INFO Received create pin request method=POST path=/api/pins/myapp22212026/11/09 12:01:25 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1658890263/001/store/31gb6q185jp911s32z396ldfsp6rqsd4-pinned-file.txt narinfo_key=31gb6q185jp911s32z396ldfsp6rqsd4.narinfo22222026/11/09 12:01:25 INFO Starting cleanup of old closures method=DELETE path=/api/closures22232026/11/09 12:01:25 INFO Garbage collection started22242026/11/09 12:01:25 INFO Aborted multipart uploads count=0 kept=022252026/11/09 12:01:25 WARN Force mode enabled - objects will be deleted immediately without grace period22262026/11/09 12:01:25 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=022272026/11/09 12:01:25 INFO Vacuumed table table=pending_closures22282026/11/09 12:01:25 INFO Vacuumed table table=pending_objects22292026/11/09 12:01:25 INFO Vacuumed table table=multipart_uploads22302026/11/09 12:01:25 INFO Vacuumed table table=closures22312026/11/09 12:01:25 INFO Vacuumed table table=objects2232--- PASS: TestPendingClosureWriteTimeout (0.00s)2233 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2234 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2235 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2236 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.18s)2237=== NAME TestOrphanedObjectsGCStressTest2238 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2239 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion22402026/11/09 12:01:25 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02241=== NAME TestClientIntegration2242 client_integration_test.go:370: Objects in database after GC:2243 client_integration_test.go:370: Successfully deleted all objects with GC --force2244--- PASS: TestClientIntegration (3.04s)22452026/11/09 12:01:26 WARN Rate limiter enabled after throttle name=s3-test rate=522462026/11/09 12:01:26 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2247=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2248 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102249 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002250--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (3.36s)22512026/11/09 12:01:26 WARN Request failed, retrying attempt=5 backoff=1.73694308s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2252=== NAME TestOrphanedObjectsGCStressTest2253 orphaned_objects_gc_test.go:503: Stress test completed successfully:2254 orphaned_objects_gc_test.go:504: - Active objects preserved: 202255 orphaned_objects_gc_test.go:505: - Objects deleted: 2102256 orphaned_objects_gc_test.go:506: - Total GC'd: 2102257--- PASS: TestOrphanedObjectsGCStressTest (2.53s)2258--- PASS: TestConnectWaitsForAPeerMigration (5.16s)2259=== NAME TestPinProtectsFromGC2260 client_integration_test.go:887: Pin successfully protected closure from garbage collection2261--- PASS: TestPinProtectsFromGC (4.88s)22622026/11/09 12:01:27 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-config22632026/11/09 12:01:28 WARN Request failed, retrying attempt=2 backoff=208.137799ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2264--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.50s)22652026/11/09 12:01:28 WARN Request failed, retrying attempt=3 backoff=365.725706ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22662026/11/09 12:01:28 WARN Request failed, retrying attempt=4 backoff=727.132134ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22672026/11/09 12:01:29 WARN Request failed, retrying attempt=5 backoff=1.593914393s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22682026/11/09 12:01:30 INFO Aborted multipart uploads count=1 kept=022692026/11/09 12:01:30 INFO Received cleanup request method=DELETE path=/api/pending_closures22702026/11/09 12:01:30 INFO Aborted multipart uploads count=1 kept=02271--- PASS: TestPendingCleanupUsesOneCutoff (6.30s)22722026/11/09 12:01:30 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"22732026/11/09 12:01:30 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-config22742026/11/09 12:01:31 WARN Request failed, retrying attempt=2 backoff=191.574207ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22752026/11/09 12:01:31 WARN Request failed, retrying attempt=3 backoff=439.474042ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22762026/11/09 12:01:31 WARN Request failed, retrying attempt=4 backoff=789.36752ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22772026/11/09 12:01:32 WARN Request failed, retrying attempt=5 backoff=1.493419826s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22782026/11/09 12:01:33 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_closures22792026/11/09 12:01:34 WARN Request failed, retrying attempt=2 backoff=197.705622ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22802026/11/09 12:01:34 WARN Request failed, retrying attempt=3 backoff=398.358129ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22812026/11/09 12:01:34 WARN Request failed, retrying attempt=4 backoff=839.042436ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22822026/11/09 12:01:35 WARN Request failed, retrying attempt=5 backoff=1.697422679s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2283--- PASS: TestClientErrorHandling (0.00s)2284 --- PASS: TestClientErrorHandling/InvalidStorePath (0.44s)2285 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.49s)2286 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.80s)2287PASS2288{"timestamp":"2026-11-09T12:01:37.226405056Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:48092","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(400)"}2289{"timestamp":"2026-11-09T12:01:37.226862256Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:48066","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(395)"}2290{"timestamp":"2026-11-09T12:01:37.226938496Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:48104","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(387)"}2291{"timestamp":"2026-11-09T12:01:37.226921746Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:48082","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(398)"}2292{"timestamp":"2026-11-09T12:01:37.226942876Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:47174","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(393)"}22932026-11-09 12:01:37.625 UTC [129] LOG: received smart shutdown request22942026-11-09 12:01:37.632 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 122952026-11-09 12:01:37.639 UTC [134] LOG: shutting down22962026-11-09 12:01:37.640 UTC [134] LOG: checkpoint starting: shutdown immediate22972026-11-09 12:01:39.306 UTC [134] LOG: checkpoint complete: wrote 11174 buffers (68.2%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.440 s, sync=1.166 s, total=1.666 s; sync files=36398, longest=0.002 s, average=0.001 s; distance=526050 kB, estimate=526050 kB; lsn=0/2191E838, redo lsn=0/2191E83822982026-11-09 12:01:39.400 UTC [129] LOG: database system is shut down2299Running OIDC tests...2300=== RUN TestAudienceForIssuer2301=== PAUSE TestAudienceForIssuer2302=== RUN TestGlobMatch2303=== PAUSE TestGlobMatch2304=== RUN TestValidateToken_ValidToken2305=== PAUSE TestValidateToken_ValidToken2306=== RUN TestValidateToken_WrongAudience2307=== PAUSE TestValidateToken_WrongAudience2308=== RUN TestValidateToken_Expired2309=== PAUSE TestValidateToken_Expired2310=== RUN TestValidateToken_BoundClaimsMismatch2311=== PAUSE TestValidateToken_BoundClaimsMismatch2312=== RUN TestValidateToken_BoundSubjectMismatch2313=== PAUSE TestValidateToken_BoundSubjectMismatch2314=== RUN TestValidateToken_MultipleProviders2315=== PAUSE TestValidateToken_MultipleProviders2316=== RUN TestValidateToken_NoMatchingProvider2317=== PAUSE TestValidateToken_NoMatchingProvider2318=== RUN TestValidateToken_KubernetesServiceAccount2319=== PAUSE TestValidateToken_KubernetesServiceAccount2320=== RUN TestNewValidator_KubernetesRequiresCA2321=== PAUSE TestNewValidator_KubernetesRequiresCA2322=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2323=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2324=== RUN TestPins_ReservedForMatchingRule2325=== PAUSE TestPins_ReservedForMatchingRule2326=== RUN TestPins_TopLevelShorthand2327=== PAUSE TestPins_TopLevelShorthand2328=== RUN TestPins_ConfigValidation2329=== PAUSE TestPins_ConfigValidation2330=== RUN TestScopes_LegacyProviderDefaultsToWrite2331=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2332=== RUN TestScopes_Rules2333=== PAUSE TestScopes_Rules2334=== RUN TestScopes_ConfigValidation2335=== PAUSE TestScopes_ConfigValidation2336=== CONT TestAudienceForIssuer2337=== CONT TestValidateToken_BoundClaimsMismatch2338--- PASS: TestAudienceForIssuer (0.00s)2339=== CONT TestValidateToken_Expired2340=== CONT TestValidateToken_WrongAudience2341=== CONT TestValidateToken_ValidToken2342=== CONT TestValidateToken_KubernetesServiceAccount2343=== CONT TestPins_TopLevelShorthand2344=== CONT TestGlobMatch2345=== RUN TestGlobMatch/foo_foo2346=== PAUSE TestGlobMatch/foo_foo2347=== CONT TestPins_ReservedForMatchingRule2348=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2349=== CONT TestScopes_Rules2350=== CONT TestNewValidator_KubernetesRequiresCA2351=== CONT TestScopes_ConfigValidation2352=== CONT TestValidateToken_MultipleProviders2353=== CONT TestScopes_LegacyProviderDefaultsToWrite2354=== CONT TestValidateToken_NoMatchingProvider2355=== CONT TestValidateToken_BoundSubjectMismatch2356--- PASS: TestScopes_ConfigValidation (0.00s)2357=== CONT TestPins_ConfigValidation2358=== RUN TestGlobMatch/foo_bar2359=== PAUSE TestGlobMatch/foo_bar2360=== RUN TestGlobMatch/*_2361=== PAUSE TestGlobMatch/*_2362=== RUN TestGlobMatch/*_anything2363=== PAUSE TestGlobMatch/*_anything2364=== RUN TestGlobMatch/foo*_foo2365=== PAUSE TestGlobMatch/foo*_foo2366=== RUN TestGlobMatch/foo*_foobar2367=== PAUSE TestGlobMatch/foo*_foobar2368=== RUN TestGlobMatch/foo*_bar2369=== PAUSE TestGlobMatch/foo*_bar2370=== RUN TestGlobMatch/*bar_bar2371=== PAUSE TestGlobMatch/*bar_bar2372=== RUN TestGlobMatch/*bar_foobar2373=== PAUSE TestGlobMatch/*bar_foobar2374=== RUN TestGlobMatch/*bar_foo2375=== PAUSE TestGlobMatch/*bar_foo2376=== RUN TestGlobMatch/foo*bar_foobar2377=== PAUSE TestGlobMatch/foo*bar_foobar2378=== RUN TestGlobMatch/foo*bar_foo123bar2379=== PAUSE TestGlobMatch/foo*bar_foo123bar2380=== RUN TestGlobMatch/foo*bar_foobarbaz2381=== PAUSE TestGlobMatch/foo*bar_foobarbaz2382=== RUN TestGlobMatch/*/*_foo/bar2383=== PAUSE TestGlobMatch/*/*_foo/bar2384=== RUN TestGlobMatch/*/*_foo2385=== PAUSE TestGlobMatch/*/*_foo2386=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2387=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2388=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02389=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02390=== RUN TestGlobMatch/refs/*/main_refs/heads/main2391=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2392=== RUN TestGlobMatch/fo?_foo2393=== PAUSE TestGlobMatch/fo?_foo2394=== RUN TestGlobMatch/fo?_fo2395=== PAUSE TestGlobMatch/fo?_fo2396=== RUN TestGlobMatch/fo?_fooo2397=== PAUSE TestGlobMatch/fo?_fooo2398=== RUN TestGlobMatch/?oo_foo2399=== PAUSE TestGlobMatch/?oo_foo2400=== RUN TestGlobMatch/?oo_boo2401=== PAUSE TestGlobMatch/?oo_boo2402=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2403=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2404=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2405=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2406=== CONT TestGlobMatch/foo_foo2407=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2408=== CONT TestGlobMatch/?oo_foo2409=== CONT TestGlobMatch/fo?_fooo2410=== CONT TestGlobMatch/?oo_boo2411=== CONT TestGlobMatch/foo*_bar2412=== CONT TestGlobMatch/foo*bar_foo123bar2413=== CONT TestGlobMatch/fo?_fo2414=== CONT TestGlobMatch/foo*bar_foobar2415=== CONT TestGlobMatch/*bar_foo2416=== CONT TestGlobMatch/foo_bar2417=== CONT TestGlobMatch/*_2418=== CONT TestGlobMatch/*bar_foobar2419=== CONT TestGlobMatch/foo*_foobar2420--- PASS: TestPins_ConfigValidation (0.00s)2421=== CONT TestGlobMatch/foo*bar_foobarbaz2422=== CONT TestGlobMatch/foo*_foo2423=== CONT TestGlobMatch/refs/*/main_refs/heads/main2424=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02425=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2426=== CONT TestGlobMatch/*/*_foo2427=== CONT TestGlobMatch/fo?_foo2428=== CONT TestGlobMatch/*/*_foo/bar2429=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2430=== CONT TestGlobMatch/*_anything2431=== CONT TestGlobMatch/*bar_bar2432--- PASS: TestGlobMatch (0.01s)2433 --- PASS: TestGlobMatch/foo_foo (0.00s)2434 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2435 --- PASS: TestGlobMatch/?oo_foo (0.00s)2436 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2437 --- PASS: TestGlobMatch/?oo_boo (0.00s)2438 --- PASS: TestGlobMatch/foo*_bar (0.00s)2439 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2440 --- PASS: TestGlobMatch/fo?_fo (0.00s)2441 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2442 --- PASS: TestGlobMatch/*bar_foo (0.00s)2443 --- PASS: TestGlobMatch/foo_bar (0.00s)2444 --- PASS: TestGlobMatch/*_ (0.00s)2445 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2446 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2447 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2448 --- PASS: TestGlobMatch/foo*_foo (0.00s)2449 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2450 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2451 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2452 --- PASS: TestGlobMatch/*/*_foo (0.00s)2453 --- PASS: TestGlobMatch/fo?_foo (0.00s)2454 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2455 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2456 --- PASS: TestGlobMatch/*_anything (0.00s)2457 --- PASS: TestGlobMatch/*bar_bar (0.00s)24582026/11/09 12:01:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39591/oidc24592026/11/09 12:01:42 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:4323124602026/11/09 12:01:42 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232461--- PASS: TestValidateToken_ValidToken (0.04s)24622026/11/09 12:01:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34689/oidc2463--- PASS: TestValidateToken_KubernetesServiceAccount (0.04s)2464--- PASS: TestValidateToken_WrongAudience (0.05s)2465--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.04s)24662026/11/09 12:01:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42493/oidc2467--- PASS: TestValidateToken_BoundSubjectMismatch (0.04s)24682026/11/09 12:01:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33119/oidc2469--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.07s)24702026/11/09 12:01:42 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:38591/oidc2471--- PASS: TestValidateToken_NoMatchingProvider (0.07s)24722026/11/09 12:01:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38263/oidc2473--- PASS: TestValidateToken_BoundClaimsMismatch (0.09s)24742026/11/09 12:01:42 http: TLS handshake error from 127.0.0.1:46914: remote error: tls: bad certificate2475--- PASS: TestNewValidator_KubernetesRequiresCA (0.08s)24762026/11/09 12:01:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36595/oidc24772026/11/09 12:01:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45977/oidc2478--- PASS: TestPins_TopLevelShorthand (0.10s)2479--- PASS: TestScopes_Rules (0.10s)24802026/11/09 12:01:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41669/oidc2481--- PASS: TestValidateToken_Expired (0.11s)24822026/11/09 12:01:42 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:36589/oidc24832026/11/09 12:01:42 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:42313/oidc2484--- PASS: TestValidateToken_MultipleProviders (0.15s)24852026/11/09 12:01:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40219/oidc2486--- PASS: TestPins_ReservedForMatchingRule (0.17s)2487PASS2488Running hook tests...2489=== RUN TestSendPathsEmpty2490=== PAUSE TestSendPathsEmpty2491=== RUN TestQueueEnqueueAndFetch2492=== PAUSE TestQueueEnqueueAndFetch2493=== RUN TestQueueDeduplication2494=== PAUSE TestQueueDeduplication2495=== RUN TestQueueRemove2496=== PAUSE TestQueueRemove2497=== RUN TestQueueFetchBatchLimit2498=== PAUSE TestQueueFetchBatchLimit2499=== RUN TestQueueRetryMovesToBack2500=== PAUSE TestQueueRetryMovesToBack2501=== RUN TestQueueFetchRemoveLifecycle2502=== PAUSE TestQueueFetchRemoveLifecycle2503=== RUN TestQueueConcurrentWriters2504=== PAUSE TestQueueConcurrentWriters2505=== RUN TestQueueRemoveLargeClosure2506=== PAUSE TestQueueRemoveLargeClosure2507=== RUN TestServerClientIntegration2508--- PASS: TestServerClientIntegration (0.00s)2509=== RUN TestServerQueueError25102026/11/09 12:01:42 ERROR Failed to queue paths error="permission denied" count=12511--- PASS: TestServerQueueError (0.00s)2512=== RUN TestGetListenerSocketActivation2513 server_test.go:218: === RUN TestGetListenerSocketActivation2514 --- PASS: TestGetListenerSocketActivation (0.00s)2515 PASS2516 2517--- PASS: TestGetListenerSocketActivation (0.01s)2518=== RUN TestServerStalledClientDoesNotBlockShutdown2519=== PAUSE TestServerStalledClientDoesNotBlockShutdown2520=== RUN TestServerBacksOffOnAcceptErrors2521=== PAUSE TestServerBacksOffOnAcceptErrors2522=== RUN TestDrainIsolatesPoisonPath2523=== PAUSE TestDrainIsolatesPoisonPath2524=== RUN TestRunNotBlockedByPoisonHead2525=== PAUSE TestRunNotBlockedByPoisonHead2526=== RUN TestDrainGivesUpWhenServerDown2527=== PAUSE TestDrainGivesUpWhenServerDown2528=== RUN TestFailedPathPrunedByLaterClosure2529=== PAUSE TestFailedPathPrunedByLaterClosure2530=== RUN TestWorkerUploadsAndRemoves2531=== PAUSE TestWorkerUploadsAndRemoves2532=== RUN TestWorkerSkipsGCdPaths2533=== PAUSE TestWorkerSkipsGCdPaths2534=== RUN TestWorkerPrunesClosureDeps2535=== PAUSE TestWorkerPrunesClosureDeps2536=== RUN TestDrainTimeout2537=== PAUSE TestDrainTimeout2538=== RUN TestWorkerRemoveFailureIsNotProgress2539=== PAUSE TestWorkerRemoveFailureIsNotProgress2540=== RUN TestWorkerKeepsPathItCannotStat2541=== PAUSE TestWorkerKeepsPathItCannotStat2542=== CONT TestSendPathsEmpty2543=== CONT TestRunNotBlockedByPoisonHead2544=== CONT TestDrainIsolatesPoisonPath2545=== CONT TestWorkerUploadsAndRemoves2546=== CONT TestFailedPathPrunedByLaterClosure2547=== CONT TestDrainGivesUpWhenServerDown2548=== CONT TestWorkerSkipsGCdPaths2549=== CONT TestWorkerKeepsPathItCannotStat2550=== CONT TestWorkerRemoveFailureIsNotProgress2551--- PASS: TestSendPathsEmpty (0.00s)2552=== CONT TestDrainTimeout2553=== CONT TestServerBacksOffOnAcceptErrors2554=== CONT TestServerStalledClientDoesNotBlockShutdown25552026/11/09 12:01:42 ERROR Accept failed error="too many open files"2556=== CONT TestQueueFetchBatchLimit2557=== CONT TestWorkerPrunesClosureDeps2558=== CONT TestQueueRemove2559=== CONT TestQueueDeduplication2560=== CONT TestQueueRetryMovesToBack2561=== CONT TestQueueEnqueueAndFetch2562=== CONT TestQueueConcurrentWriters2563=== CONT TestQueueFetchRemoveLifecycle2564=== CONT TestQueueRemoveLargeClosure25652026/11/09 12:01:42 ERROR Accept failed error="too many open files"25662026/11/09 12:01:42 ERROR Accept failed error="too many open files"25672026/11/09 12:01:42 INFO Upload queue status pending=225682026/11/09 12:01:42 INFO Upload queue status pending=225692026/11/09 12:01:42 INFO Uploading batch count=125702026/11/09 12:01:42 INFO Uploading batch count=425712026/11/09 12:01:42 INFO Uploading batch count=225722026/11/09 12:01:42 ERROR Upload failed error="upload failed" count=125732026/11/09 12:01:42 INFO Uploading batch count=225742026/11/09 12:01:42 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3974782056/002/nonexistent25752026/11/09 12:01:42 INFO Upload queue status pending=225762026/11/09 12:01:42 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat4101703641/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat4101703641/002/locked/aaa: permission denied"25772026/11/09 12:01:42 INFO Upload queue status pending=325782026/11/09 12:01:42 INFO Uploading batch count=225792026/11/09 12:01:42 ERROR Upload failed error="upload failed" count=225802026/11/09 12:01:42 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3128051291/002/a25812026/11/09 12:01:42 ERROR Upload failed error="upload failed" count=425822026/11/09 12:01:42 INFO Uploading batch count=125832026/11/09 12:01:42 INFO Uploading batch count=125842026/11/09 12:01:42 ERROR Upload failed error="upload failed" count=125852026/11/09 12:01:42 INFO Uploading batch count=12586--- PASS: TestQueueDeduplication (0.04s)25872026/11/09 12:01:42 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat4101703641/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat4101703641/002/locked/aaa: permission denied"2588--- PASS: TestQueueFetchBatchLimit (0.04s)25892026/11/09 12:01:42 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3128051291/002/b25902026/11/09 12:01:42 INFO Uploading batch count=125912026/11/09 12:01:42 ERROR Accept failed error="too many open files"25922026/11/09 12:01:42 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat4101703641/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat4101703641/002/locked/aaa: permission denied"25932026/11/09 12:01:42 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2010982553/002/bbb2594--- PASS: TestQueueRetryMovesToBack (0.04s)2595--- PASS: TestQueueRemove (0.04s)2596--- PASS: TestQueueFetchRemoveLifecycle (0.04s)25972026/11/09 12:01:42 ERROR Drain finished with paths left in queue remaining=125982026/11/09 12:01:42 INFO Uploading batch count=125992026/11/09 12:01:42 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress3775752792/002/nonexistent26002026/11/09 12:01:42 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=126012026/11/09 12:01:42 INFO Uploading batch count=226022026/11/09 12:01:42 ERROR Upload failed error="upload failed" count=226032026/11/09 12:01:42 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3128051291/002/c26042026/11/09 12:01:42 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress3775752792/002/nonexistent2605--- PASS: TestQueueEnqueueAndFetch (0.04s)26062026/11/09 12:01:42 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=126072026/11/09 12:01:42 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress3775752792/002/nonexistent26082026/11/09 12:01:42 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3128051291/002/d26092026/11/09 12:01:42 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=126102026/11/09 12:01:42 ERROR Drain finished with paths left in queue remaining=126112026/11/09 12:01:42 INFO Uploading batch count=126122026/11/09 12:01:42 ERROR Upload failed error="upload failed" count=126132026/11/09 12:01:42 INFO Uploading batch count=22614--- PASS: TestWorkerKeepsPathItCannotStat (0.04s)26152026/11/09 12:01:42 ERROR Upload failed error="upload failed" count=226162026/11/09 12:01:42 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3128051291/002/e2617--- PASS: TestFailedPathPrunedByLaterClosure (0.05s)26182026/11/09 12:01:42 INFO Uploading batch count=126192026/11/09 12:01:42 ERROR Upload failed error="upload failed" count=12620--- PASS: TestWorkerRemoveFailureIsNotProgress (0.05s)26212026/11/09 12:01:42 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3128051291/002/f26222026/11/09 12:01:42 INFO Uploading batch count=126232026/11/09 12:01:42 ERROR Upload failed error="upload failed" count=126242026/11/09 12:01:42 ERROR Drain finished with paths left in queue remaining=126252026/11/09 12:01:42 ERROR Drain finished with paths left in queue remaining=102626--- PASS: TestDrainIsolatesPoisonPath (0.05s)2627--- PASS: TestDrainGivesUpWhenServerDown (0.05s)2628--- PASS: TestWorkerSkipsGCdPaths (0.06s)2629--- PASS: TestWorkerUploadsAndRemoves (0.06s)2630--- PASS: TestWorkerPrunesClosureDeps (0.06s)26312026/11/09 12:01:42 ERROR Accept failed error="too many open files"2632--- PASS: TestQueueRemoveLargeClosure (0.09s)26332026/11/09 12:01:42 ERROR Accept failed error="too many open files"26342026/11/09 12:01:42 ERROR Failed to decode request error="read unix /build/hook1896399295/test.sock->@: i/o timeout"26352026/11/09 12:01:42 ERROR Failed to write response error="write unix /build/hook1896399295/test.sock->@: i/o timeout"2636--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)26372026/11/09 12:01:42 ERROR Upload failed error="context deadline exceeded" count=226382026/11/09 12:01:42 ERROR Drain finished with paths left in queue remaining=42639--- PASS: TestQueueConcurrentWriters (0.23s)2640--- PASS: TestDrainTimeout (0.24s)26412026/11/09 12:01:42 ERROR Accept failed error="too many open files"26422026/11/09 12:01:43 ERROR Accept failed error="too many open files"2643--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)26442026/11/09 12:01:43 INFO Uploading batch count=126452026/11/09 12:01:43 INFO Uploading batch count=126462026/11/09 12:01:43 INFO Uploading batch count=126472026/11/09 12:01:43 ERROR Upload failed error="upload failed" count=126482026/11/09 12:01:43 INFO Uploading batch count=126492026/11/09 12:01:43 ERROR Upload failed error="upload failed" count=126502026/11/09 12:01:43 INFO Uploading batch count=126512026/11/09 12:01:43 ERROR Upload failed error="upload failed" count=126522026/11/09 12:01:43 INFO Uploading batch count=126532026/11/09 12:01:43 ERROR Upload failed error="upload failed" count=126542026/11/09 12:01:43 ERROR Drain finished with paths left in queue remaining=12655--- PASS: TestRunNotBlockedByPoisonHead (1.06s)2656PASS2657Running signing tests...2658=== RUN TestExternalSigner2659=== PAUSE TestExternalSigner2660=== RUN TestExternalSignerWrongPublicKey2661=== PAUSE TestExternalSignerWrongPublicKey2662=== RUN TestExternalSignerErrors2663=== PAUSE TestExternalSignerErrors2664=== RUN TestExternalSignerRestartsAfterCrash2665=== PAUSE TestExternalSignerRestartsAfterCrash2666=== RUN TestExternalSignerProgramErrorKeepsProcess2667=== PAUSE TestExternalSignerProgramErrorKeepsProcess2668=== RUN TestExternalSignerClose2669=== PAUSE TestExternalSignerClose2670=== RUN TestExternalSignerRejectsInvalidPublicKey2671=== PAUSE TestExternalSignerRejectsInvalidPublicKey2672=== RUN TestExternalSignerCancellation2673=== PAUSE TestExternalSignerCancellation2674=== RUN TestGenerateFingerprint2675=== PAUSE TestGenerateFingerprint2676=== RUN TestParseSigningKey2677=== PAUSE TestParseSigningKey2678=== RUN TestSign2679=== PAUSE TestSign2680=== RUN TestSignBatch2681=== PAUSE TestSignBatch2682=== RUN TestNilKeyPublicKey2683=== PAUSE TestNilKeyPublicKey2684=== RUN TestSignErrors2685=== PAUSE TestSignErrors2686=== CONT TestExternalSigner2687=== CONT TestGenerateFingerprint2688=== CONT TestSignBatch2689=== CONT TestSignErrors2690=== CONT TestNilKeyPublicKey2691=== CONT TestExternalSignerProgramErrorKeepsProcess2692=== CONT TestExternalSignerRejectsInvalidPublicKey2693=== CONT TestExternalSignerClose2694=== CONT TestExternalSignerErrors2695=== RUN TestExternalSignerErrors/exit_at_startup2696=== PAUSE TestExternalSignerErrors/exit_at_startup2697=== RUN TestExternalSignerErrors/invalid_JSON2698=== PAUSE TestExternalSignerErrors/invalid_JSON2699=== RUN TestExternalSignerErrors/wrong_shape2700=== PAUSE TestExternalSignerErrors/wrong_shape2701=== RUN TestExternalSignerErrors/null2702=== PAUSE TestExternalSignerErrors/null2703=== CONT TestExternalSignerRestartsAfterCrash2704=== CONT TestSign2705=== CONT TestExternalSignerWrongPublicKey2706=== CONT TestExternalSignerCancellation2707=== CONT TestParseSigningKey2708=== RUN TestGenerateFingerprint/basic_with_references2709--- PASS: TestNilKeyPublicKey (0.00s)2710=== RUN TestExternalSignerRejectsInvalidPublicKey/#002711=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002712=== RUN TestSignErrors/nil_key2713=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2714=== PAUSE TestSignErrors/nil_key2715=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2716=== RUN TestSignErrors/nil_narinfo2717=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2718=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2719=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2720=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2721=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2722=== PAUSE TestSignErrors/nil_narinfo2723=== RUN TestParseSigningKey/valid_32-byte_key2724=== PAUSE TestParseSigningKey/valid_32-byte_key2725=== PAUSE TestGenerateFingerprint/basic_with_references2726=== RUN TestExternalSignerErrors/null_signatures2727=== PAUSE TestExternalSignerErrors/null_signatures2728--- PASS: TestSignBatch (0.00s)2729=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2730=== CONT TestExternalSignerRejectsInvalidPublicKey/#002731=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2732=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2733=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2734=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2735=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2736=== RUN TestParseSigningKey/no_colon2737=== PAUSE TestParseSigningKey/no_colon2738=== RUN TestParseSigningKey/empty_name2739=== PAUSE TestParseSigningKey/empty_name2740=== RUN TestParseSigningKey/invalid_base642741=== PAUSE TestParseSigningKey/invalid_base642742=== RUN TestGenerateFingerprint/no_references2743=== PAUSE TestGenerateFingerprint/no_references2744=== RUN TestExternalSignerErrors/wrong_signatures_shape2745=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2746--- PASS: TestSign (0.00s)2747=== RUN TestSignErrors/invalid_narinfo2748=== PAUSE TestSignErrors/invalid_narinfo2749=== RUN TestSignErrors/canceled2750=== PAUSE TestSignErrors/canceled2751=== CONT TestSignErrors/nil_key2752=== CONT TestSignErrors/canceled2753=== CONT TestSignErrors/invalid_narinfo2754=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2755=== CONT TestSignErrors/nil_narinfo2756=== RUN TestParseSigningKey/wrong_length2757=== PAUSE TestParseSigningKey/wrong_length2758=== CONT TestParseSigningKey/valid_32-byte_key2759=== CONT TestParseSigningKey/no_colon2760=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2761=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2762=== CONT TestParseSigningKey/empty_name2763--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2764 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2765 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2766 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2767 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2768 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2769=== CONT TestParseSigningKey/invalid_base642770=== CONT TestParseSigningKey/wrong_length2771=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2772=== RUN TestExternalSignerErrors/unrequested_key2773=== PAUSE TestExternalSignerErrors/unrequested_key2774=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2775--- PASS: TestSignErrors (0.00s)2776 --- PASS: TestSignErrors/nil_key (0.00s)2777 --- PASS: TestSignErrors/canceled (0.00s)2778 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2779 --- PASS: TestSignErrors/nil_narinfo (0.00s)2780=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2781=== RUN TestGenerateFingerprint/invalid_nar_hash_length2782=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2783--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2784--- PASS: TestExternalSignerClose (0.00s)2785=== RUN TestExternalSignerErrors/missing_signature_name2786--- PASS: TestParseSigningKey (0.00s)2787 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2788 --- PASS: TestParseSigningKey/no_colon (0.00s)2789 --- PASS: TestParseSigningKey/empty_name (0.00s)2790 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2791 --- PASS: TestParseSigningKey/wrong_length (0.00s)2792 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2793=== RUN TestGenerateFingerprint/invalid_store_path_prefix2794=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2795=== PAUSE TestExternalSignerErrors/missing_signature_name2796=== RUN TestExternalSignerErrors/too_few_signatures2797=== RUN TestGenerateFingerprint/invalid_reference_prefix2798=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2799=== CONT TestGenerateFingerprint/basic_with_references2800=== CONT TestGenerateFingerprint/no_references2801--- PASS: TestExternalSignerWrongPublicKey (0.01s)2802=== PAUSE TestExternalSignerErrors/too_few_signatures2803=== RUN TestExternalSignerErrors/wrong_signature_name2804=== PAUSE TestExternalSignerErrors/wrong_signature_name2805=== RUN TestExternalSignerErrors/wrong_signature_length2806=== PAUSE TestExternalSignerErrors/wrong_signature_length2807=== RUN TestExternalSignerErrors/missing_signatures2808=== PAUSE TestExternalSignerErrors/missing_signatures2809=== RUN TestExternalSignerErrors/exit_on_request2810=== PAUSE TestExternalSignerErrors/exit_on_request2811=== RUN TestExternalSignerErrors/wrong_id2812=== PAUSE TestExternalSignerErrors/wrong_id2813=== CONT TestGenerateFingerprint/invalid_reference_prefix2814=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2815=== CONT TestGenerateFingerprint/invalid_nar_hash_length2816=== CONT TestGenerateFingerprint/invalid_store_path_prefix2817=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2818--- PASS: TestGenerateFingerprint (0.01s)2819 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2820 --- PASS: TestGenerateFingerprint/no_references (0.00s)2821 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2822 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2823 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2824 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2825 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2826=== RUN TestExternalSignerErrors/invalid_signature_base642827=== PAUSE TestExternalSignerErrors/invalid_signature_base642828=== RUN TestExternalSignerErrors/program_error2829=== PAUSE TestExternalSignerErrors/program_error2830=== CONT TestExternalSignerErrors/exit_at_startup2831=== CONT TestExternalSignerErrors/unrequested_key2832=== CONT TestExternalSignerErrors/wrong_signature_length2833=== CONT TestExternalSignerErrors/program_error2834=== CONT TestExternalSignerErrors/invalid_signature_base642835=== CONT TestExternalSignerErrors/missing_signatures2836=== CONT TestExternalSignerErrors/exit_on_request2837=== CONT TestExternalSignerErrors/wrong_signatures_shape2838=== CONT TestExternalSignerErrors/wrong_id2839=== CONT TestExternalSignerErrors/wrong_signature_name2840=== CONT TestExternalSignerErrors/too_few_signatures2841=== CONT TestExternalSignerErrors/missing_signature_name2842=== CONT TestExternalSignerErrors/null2843=== CONT TestExternalSignerErrors/null_signatures2844=== CONT TestExternalSignerErrors/wrong_shape2845=== CONT TestExternalSignerErrors/invalid_JSON2846--- PASS: TestExternalSigner (0.01s)2847--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2848--- PASS: TestExternalSignerErrors (0.01s)2849 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2850 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2851 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2852 --- PASS: TestExternalSignerErrors/program_error (0.01s)2853 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2854 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2855 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2856 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2857 --- PASS: TestExternalSignerErrors/null (0.01s)2858 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2859 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2860 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2861 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2862 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2863 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2864 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2865--- PASS: TestExternalSignerCancellation (0.02s)2866PASS2867Running OpenBao signer tests...2868=== RUN TestSign2869=== PAUSE TestSign2870=== RUN TestSignErrors2871=== PAUSE TestSignErrors2872=== RUN TestServe2873=== PAUSE TestServe2874=== RUN TestServeRejectsGarbage2875=== PAUSE TestServeRejectsGarbage2876=== CONT TestSign2877=== CONT TestSignErrors2878=== CONT TestServeRejectsGarbage2879=== RUN TestSignErrors/no_prefix2880=== CONT TestServe2881=== PAUSE TestSignErrors/no_prefix2882=== RUN TestSignErrors/invalid_base642883=== PAUSE TestSignErrors/invalid_base642884=== RUN TestSignErrors/http_error2885=== PAUSE TestSignErrors/http_error2886=== RUN TestSignErrors/invalid_json2887=== PAUSE TestSignErrors/invalid_json2888=== CONT TestSignErrors/no_prefix2889=== CONT TestSignErrors/http_error2890--- PASS: TestServeRejectsGarbage (0.00s)2891=== CONT TestSignErrors/invalid_json2892--- PASS: TestServe (0.00s)2893=== CONT TestSignErrors/invalid_base642894--- PASS: TestSign (0.01s)2895--- PASS: TestSignErrors (0.00s)2896 --- PASS: TestSignErrors/no_prefix (0.00s)2897 --- PASS: TestSignErrors/invalid_base64 (0.00s)2898 --- PASS: TestSignErrors/http_error (0.00s)2899 --- PASS: TestSignErrors/invalid_json (0.00s)2900PASS