niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #485
· 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 TestEncodeNixBase32WithRealHash115--- PASS: TestEncodeNixBase32WithRealHash (0.00s)116=== CONT TestFileTokenMissing117=== CONT TestRetryTimeoutOutlastsMaxRetries118=== CONT TestScriptTokenEmptyCommand119--- PASS: TestScriptTokenEmptyCommand (0.00s)120=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun121=== CONT TestScriptTokenScriptFails122--- PASS: TestFileTokenMissing (0.00s)123=== CONT TestScriptTokenEmptyToken124=== CONT TestScriptTokenBadJSON125=== CONT TestClientSignaturesByStorePath126=== CONT TestStreamPushReportsSkippedPaths127=== CONT TestStreamPushReportsSignatures128=== CONT TestUploadMultipart_PartsInParallel129=== CONT TestStreamPushRequestLine130=== CONT TestCaseHackSuffix131=== CONT TestStreamPushGivesUpOnDeadServer1322026/11/11 22:53:20 ERROR Upload failed error=boom count=1133=== CONT TestEncodeNixBase321342026/11/11 22:53:20 ERROR Upload failed error=boom count=1135=== CONT TestSetClientTLSErrors1362026/11/11 22:53:20 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:387191372026/11/11 22:53:20 ERROR Upload failed error="connection refused" count=20138=== CONT TestStreamPushIsolatesFailures1392026/11/11 22:53:20 ERROR Server seems unavailable, giving up on batch untried=17140=== CONT TestDumpPathWriterError1412026/11/11 22:53:20 ERROR Upload failed error="bad path" count=3142=== CONT TestStreamPushBatchesUnderLoad143=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false144=== CONT TestDumpPathSingleFile1452026/11/11 22:53:20 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:38719146=== CONT TestStreamPushReportsEveryPath1472026/11/11 22:53:20 INFO Garbage collection started148=== CONT TestRegisterUploadedObjectReusesConnections149=== CONT TestDumpPathMatchesNix150=== CONT TestShellSplitErrors151=== CONT TestPartSizeForNAR152=== CONT TestShellSplit153=== CONT TestUploadMultipart_ReturnsAfterDroppedBody154=== CONT TestDoWithRetry_FinalResponseBodyReadable155--- PASS: TestScriptTokenScriptFails (0.00s)156=== CONT TestFilterOversizedClosures157=== CONT TestScriptTokenCachesUntilRefresh158=== CONT TestScriptTokenNoExpiryRerunsEveryCall159=== CONT TestFileTokenEmpty160=== RUN TestEncodeNixBase32/test_string_hash161=== CONT TestSetClientTLSDoesNotMutateDefaultTransport162=== RUN TestSetClientTLSErrors/missing_cert_file163=== CONT TestFileTokenReadsAndCaches164=== CONT TestSetClientTLS165=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry166=== CONT TestRateLimiterFeedback167=== RUN TestRateLimiterFeedback/429_enables_limiter168=== PAUSE TestRateLimiterFeedback/429_enables_limiter169=== RUN TestRateLimiterFeedback/503_enables_limiter170=== PAUSE TestRateLimiterFeedback/503_enables_limiter171=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter172=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter173=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter174=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter1752026/11/11 22:53:20 WARN Rate limiter enabled after throttle name=server-test rate=5176=== RUN TestFilterOversizedClosures/no_limit_keeps_everything177=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything178=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped179=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped180=== RUN TestFilterOversizedClosures/all_closures_skipped181=== PAUSE TestFilterOversizedClosures/all_closures_skipped1822026/11/11 22:53:20 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:387191832026/11/11 22:53:20 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:44077184=== PAUSE TestEncodeNixBase32/test_string_hash1852026/11/11 22:53:20 WARN Rate limiter backed off name=server-test rate=5186=== RUN TestEncodeNixBase32/empty_input187=== PAUSE TestEncodeNixBase32/empty_input188=== CONT TestPathInfoCACompatibility189=== RUN TestPathInfoCACompatibility/null_ca_field190=== PAUSE TestPathInfoCACompatibility/null_ca_field191=== CONT TestParsePathInfoJSON192=== RUN TestParsePathInfoJSON/Nix_format193=== PAUSE TestParsePathInfoJSON/Nix_format194=== RUN TestParsePathInfoJSON/Lix_format195=== PAUSE TestParsePathInfoJSON/Lix_format196=== RUN TestParsePathInfoJSON/empty_input197=== PAUSE TestParsePathInfoJSON/empty_input198=== RUN TestParsePathInfoJSON/whitespace_only199=== PAUSE TestParsePathInfoJSON/whitespace_only200=== RUN TestParsePathInfoJSON/invalid_JSON201=== PAUSE TestParsePathInfoJSON/invalid_JSON202=== RUN TestPathInfoCACompatibility/old_string_format_-_text203=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text204=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive205=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive206=== RUN TestPathInfoCACompatibility/new_structured_format_-_text207=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text208=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method209=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method210=== CONT TestParsePathInfoJSONMultiplePaths211=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths212=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths213=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths214=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths215=== CONT TestStaticToken216=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer217=== RUN TestSetClientTLS/rejects_connection_without_client_cert218=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert219=== CONT TestGetStorePathHash220=== RUN TestGetStorePathHash/valid_store_path221=== PAUSE TestGetStorePathHash/valid_store_path222=== CONT TestPathInfoHashCompatibility223=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)224=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)225=== CONT TestRegisterUploadedObject_OutlivesPush2262026/11/11 22:53:20 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:38719227=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess228=== CONT TestConvertHashToNix322292026/11/11 22:53:20 WARN Rate limiter enabled after throttle name=server-test rate=5230=== RUN TestConvertHashToNix32/SRI_format_to_Nix32231=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32232=== RUN TestConvertHashToNix32/already_Nix32_format233=== PAUSE TestConvertHashToNix32/already_Nix32_format234=== RUN TestConvertHashToNix32/invalid_format235=== PAUSE TestConvertHashToNix32/invalid_format236=== RUN TestGetStorePathHash/basename_without_hyphen_should_error2372026/11/11 22:53:20 WARN Rate limiter enabled after throttle name=s3-test rate=5238=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error2392026/11/11 22:53:20 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:46839240=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error241=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error242=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error243=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error244=== CONT TestDoWithRetry_BodyReplayedViaGetBody245=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA246=== CONT TestFilterOversizedClosures/no_limit_keeps_everything247=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter248=== PAUSE TestSetClientTLSErrors/missing_cert_file249=== RUN TestSetClientTLSErrors/missing_key_file250=== PAUSE TestSetClientTLSErrors/missing_key_file251=== RUN TestSetClientTLSErrors/missing_ca_file252=== PAUSE TestSetClientTLSErrors/missing_ca_file253=== RUN TestSetClientTLSErrors/invalid_ca_file254=== PAUSE TestSetClientTLSErrors/invalid_ca_file255=== CONT TestRateLimiterFeedback/429_enables_limiter2562026/11/11 22:53:20 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:38719257=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA258=== RUN TestSetClientTLS/preserves_debug_logging_transport2592026/11/11 22:53:20 WARN Rate limiter enabled after throttle name=server-test rate=5260=== PAUSE TestSetClientTLS/preserves_debug_logging_transport2612026/11/11 22:53:20 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:35887262=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false263=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true264=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true265=== CONT TestParsePathInfoJSON/Nix_format266=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica267=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon268=== CONT TestStreamPushStopsWhenCanceled269=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths2702026/11/11 22:53:20 WARN Rate limiter backed off name=server-test rate=52712026/11/11 22:53:20 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:35887272=== CONT TestPathInfoCACompatibility/null_ca_field273=== CONT TestParsePathInfoJSON/whitespace_only274=== CONT TestParsePathInfoJSON/empty_input275=== CONT TestParsePathInfoJSON/Lix_format276=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method2772026/11/11 22:53:20 WARN Rate limiter enabled after throttle name=server-test rate=5278=== CONT TestPathInfoCACompatibility/new_structured_format_-_text2792026/11/11 22:53:20 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:34703280=== CONT TestPathInfoCACompatibility/old_string_format_-_text281=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon282=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI2832026/11/11 22:53:20 WARN Rate limiter backed off name=server-test rate=5284=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter285=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive286=== CONT TestParsePathInfoJSON/invalid_JSON287--- PASS: TestClientSignaturesByStorePath (0.00s)288--- PASS: TestStreamPushReportsSkippedPaths (0.00s)289=== CONT TestEncodeNixBase32/empty_input290=== CONT TestEncodeNixBase32/test_string_hash291=== CONT TestResolveStorePath292=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths293=== CONT TestRateLimiterFeedback/503_enables_limiter294=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI295=== RUN TestPartSizeForNAR/zero_stays_at_minimum296--- PASS: TestScriptTokenBadJSON (0.00s)297--- PASS: TestScriptTokenEmptyToken (0.00s)298--- PASS: TestStreamPushReportsSignatures (0.00s)299--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)300--- PASS: TestStreamPushIsolatesFailures (0.04s)301--- PASS: TestDoServerRequestAttachesToken (0.04s)302--- PASS: TestStreamPushReportsEveryPath (0.00s)303--- PASS: TestShellSplitErrors (0.00s)304--- PASS: TestShellSplit (0.00s)305--- PASS: TestFileTokenReadsAndCaches (0.00s)306--- PASS: TestFileTokenEmpty (0.00s)307--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.00s)308--- PASS: TestStaticToken (0.00s)309--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)310--- PASS: TestUploadMultipart_ReturnsAfterDroppedBody (0.00s)311--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.05s)312--- PASS: TestRegisterUploadedObject_OutlivesPush (0.00s)313--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.00s)314--- PASS: TestStreamPushStopsWhenCanceled (0.00s)315--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)316--- PASS: TestParsePathInfoJSON (0.00s)317 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)318 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)319 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)320 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)321 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)322=== CONT TestFilterOversizedClosures/all_closures_skipped323=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum324--- PASS: TestPathInfoCACompatibility (0.00s)325 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)326 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)327 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)328 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)329 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.01s)3302026/11/11 22:53:20 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50331=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error3322026/11/11 22:53:20 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:38719333=== CONT TestConvertHashToNix32/SRI_format_to_Nix323342026/11/11 22:53:20 WARN Rate limiter enabled after throttle name=server-test rate=5335=== CONT TestSetClientTLSErrors/invalid_ca_file3362026/11/11 22:53:20 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:352913372026/11/11 22:53:20 INFO Garbage collection started338=== CONT TestSetClientTLSErrors/missing_key_file3392026/11/11 22:53:20 WARN Rate limiter backed off name=server-test rate=5340=== CONT TestSetClientTLS/rejects_connection_without_client_cert341=== CONT TestSetClientTLS/preserves_debug_logging_transport3422026/11/11 22:53:20 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:38719343=== CONT TestConvertHashToNix32/invalid_format344=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA3452026/11/11 22:53:20 INFO Garbage collection progress phase=running_on_another_replica failed_uploads_deleted=0 old_closures_deleted=0 objects_marked=0 objects_deleted=0 objects_failed=0346=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false347=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512348=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512349=== RUN TestPartSizeForNAR/small_stays_at_minimum350=== CONT TestConvertHashToNix32/already_Nix32_format351=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error352=== CONT TestGetStorePathHash/valid_store_path353--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)354=== CONT TestGetStorePathHash/basename_without_hyphen_should_error355=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped356=== CONT TestSetClientTLSErrors/missing_cert_file357=== CONT TestSetClientTLSErrors/missing_ca_file358=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true359=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)3602026/11/11 22:53:20 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000361--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)362 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)363 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)364--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)365=== PAUSE TestPartSizeForNAR/small_stays_at_minimum366=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum367=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum368=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI369=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha5123702026/11/11 22:53:20 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:38719371=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon372--- PASS: TestResolveStorePath (0.00s)3732026/11/11 22:53:20 WARN Garbage collection finished on another replica. Its statistics are not available here374=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts375=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts376=== RUN TestPartSizeForNAR/1_TiB377=== PAUSE TestPartSizeForNAR/1_TiB378=== RUN TestPartSizeForNAR/5_TiB_S3_max_object379--- PASS: TestRateLimiterFeedback (0.00s)380 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)381 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)382 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.01s)383 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)384--- PASS: TestConvertHashToNix32 (0.00s)385 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)386 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)387 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)388=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object389--- PASS: TestFilterOversizedClosures (0.00s)390 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)391 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)392 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)393=== RUN TestPartSizeForNAR/capped_at_5_GiB394=== PAUSE TestPartSizeForNAR/capped_at_5_GiB395=== CONT TestPartSizeForNAR/zero_stays_at_minimum396=== CONT TestPartSizeForNAR/capped_at_5_GiB397--- PASS: TestGetStorePathHash (0.00s)398 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)399 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)400 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)401 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)402=== CONT TestPartSizeForNAR/5_TiB_S3_max_object403=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum404=== CONT TestPartSizeForNAR/small_stays_at_minimum405=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts406=== CONT TestPartSizeForNAR/1_TiB407--- PASS: TestEncodeNixBase32 (0.04s)408 --- PASS: TestEncodeNixBase32/empty_input (0.00s)409 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)410--- PASS: TestStreamPushBatchesUnderLoad (0.01s)411 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)412 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)4132026/11/11 22:53:20 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:38719414--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.02s)415--- PASS: TestPartSizeForNAR (0.02s)416 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)417 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)418 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)419 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)420 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)421 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)422 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)423--- PASS: TestPathInfoHashCompatibility (0.02s)424 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)425 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)426 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)427 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)428--- PASS: TestSetClientTLSErrors (0.04s)429 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)430 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)431 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)432 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)4332026/11/11 22:53:20 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:38719434--- PASS: TestStreamPushRequestLine (0.06s)4352026/11/11 22:53:20 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:387194362026/11/11 22:53:20 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:387194372026/11/11 22:53:20 http: TLS handshake error from 127.0.0.1:56140: remote error: tls: bad certificate4382026/11/11 22:53:20 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:38719439--- PASS: TestSetClientTLS (0.01s)440 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)441 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)442 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)4432026/11/11 22:53:20 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:38719444--- PASS: TestCaseHackSuffix (0.07s)4452026/11/11 22:53:20 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:387194462026/11/11 22:53:20 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:38719447--- PASS: TestDumpPathSingleFile (0.03s)4482026/11/11 22:53:20 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:387194492026/11/11 22:53:20 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:38719450--- PASS: TestDumpPathWriterError (0.04s)4512026/11/11 22:53:20 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:38719452--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.08s)453--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)454--- PASS: TestDumpPathMatchesNix (0.08s)4552026/11/11 22:53:20 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:33451/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:33451/api/uploads/complete4562026/11/11 22:53:20 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4572026/11/11 22:53:20 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:33451/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:33451/api/uploads/complete4582026/11/11 22:53:20 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4592026/11/11 22:53:20 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:33451/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:33451/api/uploads/complete4602026/11/11 22:53:20 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"461--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (0.10s)462--- PASS: TestUploadMultipart_PartsInParallel (0.67s)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/postgres3984247283/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/postgres3984247283/data -l logfile start492493/build/postgres3984247283:5432 - no response4942026-11-11 22:53:22.143 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4952026-11-11 22:53:22.144 UTC [129] LOG: listening on Unix socket "/build/postgres3984247283/.s.PGSQL.5432"4962026-11-11 22:53:22.149 UTC [136] LOG: database system was shut down at 2026-11-11 22:53:21 UTC4972026-11-11 22:53:22.153 UTC [129] LOG: database system is ready to accept connections498/build/postgres3984247283:5432 - accepting connections499{"timestamp":"2026-11-11T22:53:22.44838988Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"b549340b-0e07-47a3-89d2-807a611a2e30","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(392)"}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 TestResolveDBConnectionString543=== PAUSE TestResolveDBConnectionString544=== RUN TestConnectWaitsForAPeerMigration545=== PAUSE TestConnectWaitsForAPeerMigration546=== RUN TestLeadElectsOneAndHandsOver547=== PAUSE TestLeadElectsOneAndHandsOver548=== RUN TestLeadIncumbentWinsAfterRestart5492026/11/11 22:53:22 INFO lead: acquired remote=192.0.2.1:1234 generation=15502026/11/11 22:53:23 INFO lead: released remote=192.0.2.1:1234 generation=15512026/11/11 22:53:23 INFO lead: acquired remote=192.0.2.1:1234 generation=25522026/11/11 22:53:24 INFO lead: released remote=192.0.2.1:1234 generation=2553--- PASS: TestLeadIncumbentWinsAfterRestart (1.89s)554=== RUN TestLeadUnannouncedStandbyYieldsToIncumbent555=== PAUSE TestLeadUnannouncedStandbyYieldsToIncumbent556=== RUN TestLeadIncumbentAnnouncesAtOnce557=== PAUSE TestLeadIncumbentAnnouncesAtOnce558=== RUN TestLeadGenerationGrowsWithEveryGrant559=== PAUSE TestLeadGenerationGrowsWithEveryGrant560=== RUN TestLeadEndsOnShutdown561=== PAUSE TestLeadEndsOnShutdown562=== RUN TestLeadEndsWhenItsConnectionHangs5632026/11/11 22:53:24 INFO lead: acquired remote=192.0.2.1:1234 generation=15642026-11-11 22:53:25.954 UTC [577] FATAL: terminating connection due to administrator command5652026/11/11 22:53:26 INFO lead: acquired remote=192.0.2.1:1234 generation=25662026/11/11 22:53:27 WARN lead: lock connection lost error="timeout: context deadline exceeded"5672026/11/11 22:53:27 INFO lead: released remote=192.0.2.1:1234 generation=15682026/11/11 22:53:27 INFO lead: released remote=192.0.2.1:1234 generation=2569--- PASS: TestLeadEndsWhenItsConnectionHangs (3.11s)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/11 22:53:27 INFO Starting HTTP server address=proxy.sock6722026/11/11 22:53:27 INFO Starting HTTP server address=127.0.0.1:380996732026/11/11 22:53:27 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6742026/11/11 22:53:27 INFO Shutdown signal received, draining in-flight requests timeout=10s675--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.10s)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/11 22:53:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7442026/11/11 22:53:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7452026/11/11 22:53:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7462026/11/11 22:53:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7472026/11/11 22:53:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7482026/11/11 22:53:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7492026/11/11 22:53:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7502026/11/11 22:53:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7512026/11/11 22:53:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7522026/11/11 22:53:27 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 TestIsValidUploadKey780=== RUN TestIsValidUploadKey/narinfo781=== PAUSE TestIsValidUploadKey/narinfo782=== RUN TestIsValidUploadKey/nar_zst783=== PAUSE TestIsValidUploadKey/nar_zst784=== RUN TestIsValidUploadKey/nar_xz785=== PAUSE TestIsValidUploadKey/nar_xz786=== RUN TestIsValidUploadKey/nar_plain787=== PAUSE TestIsValidUploadKey/nar_plain788=== RUN TestIsValidUploadKey/listing789=== PAUSE TestIsValidUploadKey/listing790=== RUN TestIsValidUploadKey/build_log791=== PAUSE TestIsValidUploadKey/build_log792=== RUN TestIsValidUploadKey/build_log_home-manager_file793=== PAUSE TestIsValidUploadKey/build_log_home-manager_file794=== RUN TestIsValidUploadKey/build_log_plus_in_name795=== PAUSE TestIsValidUploadKey/build_log_plus_in_name796--- PASS: TestAbortSucceeded (0.00s)797=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT798=== CONT TestCompleteMultipartUnregistered799=== CONT TestService_verifyS3ReuploadsStaleNarinfo800=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed801=== CONT TestService_verifyS3Integrity802=== CONT TestService_createPendingClosureHandler803=== CONT TestService_cleanupPendingClosuresHandler804=== CONT TestUploadHandlersRejectOversizedBody805=== CONT TestUploadHandlersRejectInvalidKeys806=== CONT TestIsValidCachePath807=== CONT TestParseSingleRange808=== CONT TestPresentNotReportedWhileGCDeletesClosure809=== CONT TestPresentRefreshesOnlyStaleClosures810=== CONT TestPresentReportsOnlyClosureRoots811=== CONT TestCreatePin_ReservedPins812=== CONT TestOrphanedObjectsGCStressTest813=== CONT TestOrphanedObjectsGC814=== CONT TestObjectStatsUpdatedOncePerCommit815=== CONT TestObjectStatsTrigger816=== CONT TestPendingCleanupUsesOneCutoff817=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded818=== CONT TestMultipartCleanup819=== CONT TestServerTLSConfig820=== CONT TestService_NativeMTLS821=== RUN TestIsValidUploadKey/build_log_question_mark822=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed823=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info824=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale825=== RUN TestIsValidCachePath/narinfo826=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info827=== RUN TestParseSingleRange/none828=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale829=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh830=== RUN TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed831=== PAUSE TestParseSingleRange/none832=== RUN TestParseSingleRange/unknown_unit833=== RUN TestServerTLSConfig/no_client_CA834=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal835=== PAUSE TestIsValidUploadKey/build_log_question_mark836=== PAUSE TestIsValidCachePath/narinfo837=== RUN TestIsValidUploadKey/build_log_equals838=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars839=== PAUSE TestIsValidUploadKey/build_log_equals840=== RUN TestIsValidUploadKey/realisation841=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed842=== PAUSE TestParseSingleRange/unknown_unit843=== PAUSE TestServerTLSConfig/no_client_CA844=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh845=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal846=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key847=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost848=== RUN TestParseSingleRange/multi-range_ignored849=== RUN TestServerTLSConfig/missing_CA_file850=== CONT TestMetricsCommit851=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars852=== RUN TestIsValidCachePath/nar_zst853=== PAUSE TestIsValidCachePath/nar_zst854=== RUN TestIsValidCachePath/nar_xz855=== PAUSE TestIsValidUploadKey/realisation856=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key8572026/11/11 22:53:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40953/oidc858=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost859=== PAUSE TestServerTLSConfig/missing_CA_file860=== RUN TestServerTLSConfig/not_a_PEM_file861=== PAUSE TestParseSingleRange/multi-range_ignored862=== PAUSE TestIsValidCachePath/nar_xz863=== RUN TestIsValidCachePath/nar_bz2864=== PAUSE TestIsValidCachePath/nar_bz2865=== RUN TestIsValidCachePath/nar_uncompressed866=== PAUSE TestIsValidCachePath/nar_uncompressed867=== RUN TestIsValidCachePath/ls868=== RUN TestIsValidUploadKey/realisation_plus_in_output869=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key870=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key871=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed872=== RUN TestParseSingleRange/malformed_no_dash873=== PAUSE TestParseSingleRange/malformed_no_dash874=== RUN TestParseSingleRange/malformed_both_empty875=== PAUSE TestParseSingleRange/malformed_both_empty876=== RUN TestParseSingleRange/malformed_end_before_start877=== PAUSE TestParseSingleRange/malformed_end_before_start878=== RUN TestParseSingleRange/closed879=== PAUSE TestParseSingleRange/closed880=== PAUSE TestIsValidCachePath/ls881=== PAUSE TestIsValidUploadKey/realisation_plus_in_output882=== RUN TestIsValidUploadKey/nix-cache-info883=== PAUSE TestServerTLSConfig/not_a_PEM_file884=== CONT TestMetricsInventory885=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed886=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed887=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed888=== RUN TestParseSingleRange/open-ended889=== PAUSE TestParseSingleRange/open-ended890=== RUN TestParseSingleRange/end_clamped_to_size891=== PAUSE TestParseSingleRange/end_clamped_to_size892=== RUN TestParseSingleRange/suffix893=== RUN TestIsValidCachePath/log894=== PAUSE TestIsValidCachePath/log895=== PAUSE TestIsValidUploadKey/nix-cache-info896=== RUN TestIsValidUploadKey/index.html897=== PAUSE TestIsValidUploadKey/index.html898=== RUN TestIsValidUploadKey/narinfo_key,_nar_type899=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type900=== CONT TestNARDeduplicationMetadataUploadBug901=== CONT TestCreatePendingClosureRejectsOversizedNAR902=== PAUSE TestParseSingleRange/suffix9032026/11/11 22:53:27 INFO Received uploads request method=POST path=/api/pending_closures904=== RUN TestParseSingleRange/suffix_exceeds_size905=== PAUSE TestParseSingleRange/suffix_exceeds_size906=== RUN TestParseSingleRange/single_byte907=== PAUSE TestParseSingleRange/single_byte908=== RUN TestParseSingleRange/start_past_EOF909=== PAUSE TestParseSingleRange/start_past_EOF910=== RUN TestParseSingleRange/start_far_past_EOF911=== PAUSE TestParseSingleRange/start_far_past_EOF912=== RUN TestIsValidCachePath/realisation913=== RUN TestIsValidUploadKey/nar_key,_narinfo_type914=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type915=== RUN TestIsValidUploadKey/listing_key,_narinfo_type916=== PAUSE TestIsValidCachePath/realisation917=== CONT TestCacheConfigHandlerMaxNarSize918=== CONT TestEnsureAbortUploadsRule919--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)920--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)921=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type922=== RUN TestIsValidUploadKey/traversal923=== PAUSE TestIsValidUploadKey/traversal924=== RUN TestIsValidCachePath/nix-cache-info925=== CONT TestGenerateLandingPage926=== RUN TestIsValidUploadKey/traversal_nar927=== PAUSE TestIsValidUploadKey/traversal_nar928=== RUN TestIsValidUploadKey/absolute929=== PAUSE TestIsValidUploadKey/absolute930=== RUN TestIsValidUploadKey/empty_key931=== PAUSE TestIsValidUploadKey/empty_key932=== RUN TestIsValidUploadKey/unknown_type933=== PAUSE TestIsValidUploadKey/unknown_type934=== PAUSE TestIsValidCachePath/nix-cache-info935=== RUN TestIsValidCachePath/index.html936=== PAUSE TestIsValidCachePath/index.html937=== RUN TestIsValidCachePath/traversal_parent938=== PAUSE TestIsValidCachePath/traversal_parent939=== RUN TestIsValidCachePath/traversal_in_middle940=== PAUSE TestIsValidCachePath/traversal_in_middle941=== RUN TestIsValidCachePath/invalid_char_e942=== PAUSE TestIsValidCachePath/invalid_char_e943=== RUN TestIsValidCachePath/invalid_char_u944=== PAUSE TestIsValidCachePath/invalid_char_u945=== RUN TestIsValidCachePath/random_path946=== PAUSE TestIsValidCachePath/random_path947=== RUN TestIsValidCachePath/empty948=== PAUSE TestIsValidCachePath/empty949=== RUN TestIsValidCachePath/leading_slash950=== PAUSE TestIsValidCachePath/leading_slash951=== RUN TestIsValidCachePath/wrong_extension952=== CONT TestService_readinessHandler953=== PAUSE TestIsValidCachePath/wrong_extension954=== RUN TestIsValidCachePath/short_hash955=== PAUSE TestIsValidCachePath/short_hash956=== CONT TestService_healthCheckHandler957--- PASS: TestGenerateLandingPage (0.00s)958=== CONT TestGracefulShutdownDrainsInflight9592026/11/11 22:53:27 INFO Starting HTTP server address=127.0.0.1:396819602026/11/11 22:53:27 INFO Shutdown signal received, draining in-flight requests timeout=10s961=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts962=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts963=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure964=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure965=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart966=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart967=== CONT TestGCTaskStore_Fail968--- PASS: TestGCTaskStore_Fail (0.00s)969=== CONT TestGCTaskStore_PhaseUpdates970--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)971=== CONT TestGCTaskStore_CompletedAllowsNewTask972--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)973=== CONT TestGCTaskStore_GetReturnsLatest974--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)975=== CONT TestGCTaskStore_GetEmpty976--- PASS: TestGCTaskStore_GetEmpty (0.00s)977=== CONT TestGCTaskStore_ConflictDifferentParams978--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)979=== CONT TestGCTaskStore_DeduplicateSameParams980--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)981=== CONT TestGCTaskStore_StartNew982--- PASS: TestGCTaskStore_StartNew (0.00s)983=== CONT TestGCEndsOnShutdown984=== RUN TestGCEndsOnShutdown/before_the_run985=== PAUSE TestGCEndsOnShutdown/before_the_run986=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete987=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete988=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark989=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark990=== CONT TestCommitRacingPendingCleanupKeepsObjects991--- PASS: TestGracefulShutdownDrainsInflight (0.07s)992=== CONT TestPushWaitsForSweepHoldingRow9932026/11/11 22:53:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9942026/11/11 22:53:28 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst995--- PASS: TestCompleteMultipartUnregistered (0.36s)996=== CONT TestSweepRechecksPendingAfterLocking9972026/11/11 22:53:28 INFO Received uploads request method=POST path=/api/pending_closures9982026/11/11 22:53:28 INFO Received uploads request method=POST path=/api/pending_closures9992026/11/11 22:53:28 INFO Received uploads request method=POST path=/api/pending_closures10002026/11/11 22:53:28 INFO Received uploads request method=POST path=/api/pending_closures1001--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.41s)1002=== CONT TestGetExistingObjectsLocksRows10032026/11/11 22:53:28 INFO Received uploads request method=POST path=/api/pending_closures10042026/11/11 22:53:28 INFO Received uploads request method=POST path=/api/pending_closures1005--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.45s)1006=== CONT TestRegisterCompletedObjectNeedsPendingRow1007--- PASS: TestObjectStatsUpdatedOncePerCommit (0.51s)1008=== CONT TestSweepSkipsRowsLockedByPush10092026/11/11 22:53:28 INFO Received cleanup request method=DELETE path=/api/pending_closures10102026/11/11 22:53:28 INFO Aborted multipart uploads count=0 kept=010112026/11/11 22:53:28 INFO Received uploads request method=POST path=/api/pending_closures10122026/11/11 22:53:28 INFO Received cleanup request method=DELETE path=/api/pending_closures10132026/11/11 22:53:28 INFO Aborted multipart uploads count=1 kept=010142026/11/11 22:53:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10152026-11-11 22:53:28.434 UTC [664] ERROR: Closure does not exist: id=110162026-11-11 22:53:28.434 UTC [664] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE10172026-11-11 22:53:28.434 UTC [664] STATEMENT: -- name: CommitPendingClosure :one1018 SELECT commit_pending_closure($1::bigint)::bigint1019 1020--- PASS: TestService_cleanupPendingClosuresHandler (0.54s)1021=== CONT TestFailedS3DeleteKeepsTombstone10222026/11/11 22:53:28 INFO Received uploads request method=POST path=/api/pending_closures10232026/11/11 22:53:28 INFO Received uploads request method=POST path=/api/pending_closures10242026/11/11 22:53:28 INFO Received uploads request method=POST path=/api/pending_closures10252026/11/11 22:53:28 INFO Received cleanup request method=DELETE path=/api/pending_closures10262026/11/11 22:53:28 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10272026/11/11 22:53:28 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1028--- PASS: TestService_NativeMTLS (0.62s)1029=== CONT TestForceGCDuringPushOffersSweptObject1030=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1031=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1032=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1033=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1034=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1035--- PASS: TestPresentReportsOnlyClosureRoots (0.66s)1036=== CONT TestGCSweepDeliversEachKeyOnce10372026/11/11 22:53:28 INFO Received cleanup request method=DELETE path=/api/pending_closures10382026/11/11 22:53:28 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket13/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""10392026/11/11 22:53:28 INFO Aborted multipart uploads count=0 kept=110402026/11/11 22:53:28 INFO Received cleanup request method=DELETE path=/api/pending_closures10412026/11/11 22:53:28 INFO Aborted multipart uploads count=1 kept=01042--- PASS: TestMetricsInventory (0.60s)1043=== CONT TestTombstonedObjectOfferedWithoutWaiting1044--- PASS: TestMultipartCleanup (0.70s)1045=== CONT TestGCSweepSkipsPendingObjects10462026/11/11 22:53:28 INFO Installed lifecycle rule aborting incomplete NAR uploads bucket=bucket18 days=21047--- PASS: TestEnsureAbortUploadsRule (0.61s)1048=== CONT TestDeduplicatedObjectsRecordedAsPending10492026/11/11 22:53:28 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10502026/11/11 22:53:28 WARN Refused reserved pin name=worker-x86_64-linux10512026/11/11 22:53:28 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10522026/11/11 22:53:28 INFO Received create pin request method=POST path=/api/pins/my-app10532026/11/11 22:53:28 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1054--- PASS: TestCreatePin_ReservedPins (0.74s)1055=== CONT TestPushDedupSurvivesConcurrentGC1056--- PASS: TestObjectStatsTrigger (0.78s)1057=== CONT TestGCMetrics10582026/11/11 22:53:28 INFO Received push request method=POST path=/api/pushes10592026/11/11 22:53:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1060=== NAME TestNARDeduplicationMetadataUploadBug1061 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3920864162/001/store/9rr9p9jm17a5xbigdc65kgdqm39d87yj-file1.txt10622026/11/11 22:53:28 INFO Received complete push request method=POST path=/api/pushes/1/complete10632026/11/11 22:53:28 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZjE4N2NiZjQtZGJlMi00NWM0LWE3NGMtODMxMmUyZmRjZjdmLmViNjE5ZWJiLTc2MmEtNGIxOS04Yzk1LTI1ZjM4NTU4YzNhOXgxNzk0NDM3NjA4Mjc1Mzc5MTQ2 parts=1010642026/11/11 22:53:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1065--- PASS: TestService_healthCheckHandler (0.74s)1066=== CONT TestGCBugBareHashReferences10672026/11/11 22:53:28 INFO Completed push id=1 objects=4 duration=8.069863ms10682026/11/11 22:53:28 INFO Completed upload id=1 objects=2 duration=4.908356ms10692026/11/11 22:53:28 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010702026/11/11 22:53:28 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10712026/11/11 22:53:28 INFO Received uploads request method=POST path=/api/pending_closures10722026/11/11 22:53:28 INFO Completed upload id=2 objects=2 duration=1.787108ms10732026/11/11 22:53:28 INFO Starting cleanup of old closures method=DELETE path=/api/closures1074--- PASS: TestMetricsCommit (0.76s)1075=== CONT TestGCAdvisoryLockBlocksConcurrentRun10762026/11/11 22:53:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10772026/11/11 22:53:28 INFO Aborted multipart uploads count=0 kept=010782026/11/11 22:53:28 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=010792026/11/11 22:53:28 INFO Vacuumed table table=pending_closures10802026/11/11 22:53:28 INFO Vacuumed table table=pending_objects10812026/11/11 22:53:28 INFO Vacuumed table table=multipart_uploads10822026/11/11 22:53:28 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZjE4N2NiZjQtZGJlMi00NWM0LWE3NGMtODMxMmUyZmRjZjdmLjRkMTJhNmY5LTk2NjItNGYyOS05MTU0LTAyZjljMjcyNzY1MHgxNzk0NDM3NjA4MzIxOTAxNjE1 parts=1010832026/11/11 22:53:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10842026/11/11 22:53:28 INFO Vacuumed table table=closures10852026/11/11 22:53:28 INFO Vacuumed table table=objects10862026/11/11 22:53:28 INFO Received uploads request method=POST path=/api/pending_closures10872026/11/11 22:53:28 INFO Completed upload id=1 objects=2 duration=5.229065ms10882026/11/11 22:53:28 INFO Received uploads request method=POST path=/api/pending_closures10892026/11/11 22:53:28 INFO Received uploads request method=POST path=/api/pending_closures10902026/11/11 22:53:28 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10912026/11/11 22:53:28 WARN Found objects in DB but missing from S3, will re-upload count=11092--- PASS: TestService_verifyS3Integrity (0.90s)1093=== CONT TestLeadEndsOnShutdown1094=== NAME TestOrphanedObjectsGC1095 orphaned_objects_gc_test.go:287: GC Test Summary:1096 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1097 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1098 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1099 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1100 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects11012026/11/11 22:53:28 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001102--- PASS: TestOrphanedObjectsGC (0.90s)1103=== CONT TestPush_CompleteCommitsEveryRoot1104--- PASS: TestService_createPendingClosureHandler (0.90s)1105=== CONT TestLeadGenerationGrowsWithEveryGrant11062026/11/11 22:53:28 INFO Received push request method=POST path=/api/pushes1107--- PASS: TestPresentRefreshesOnlyStaleClosures (0.92s)1108=== CONT TestLeadIncumbentAnnouncesAtOnce11092026/11/11 22:53:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11102026/11/11 22:53:28 INFO Uploading 9rr9p9jm17a5xbigdc65kgdqm39d87yj-file1.txt (160B)11112026/11/11 22:53:28 WARN readiness check failed error="closed pool"1112--- PASS: TestService_readinessHandler (0.82s)1113=== CONT TestPendingClosureWriteTimeout1114=== RUN TestPendingClosureWriteTimeout/empty1115=== PAUSE TestPendingClosureWriteTimeout/empty1116=== RUN TestPendingClosureWriteTimeout/400_objects1117=== PAUSE TestPendingClosureWriteTimeout/400_objects1118=== RUN TestPendingClosureWriteTimeout/670k_objects1119=== PAUSE TestPendingClosureWriteTimeout/670k_objects1120=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1121=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1122=== CONT TestLeadUnannouncedStandbyYieldsToIncumbent11232026/11/11 22:53:28 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11242026/11/11 22:53:28 WARN Failed to register uploaded object key=9rr9p9jm17a5xbigdc65kgdqm39d87yj.ls error="server returned 404: 404 page not found\n"11252026/11/11 22:53:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11262026/11/11 22:53:28 INFO Signed narinfos id=1 count=111272026/11/11 22:53:28 INFO Uploading 1 narinfos11282026/11/11 22:53:28 INFO Received complete push request method=POST path=/api/pushes/1/complete11292026/11/11 22:53:28 WARN Failed to register uploaded object key=9rr9p9jm17a5xbigdc65kgdqm39d87yj.narinfo error="server returned 404: 404 page not found\n"11302026/11/11 22:53:28 INFO Completed push id=1 objects=3 duration=10.55249ms11312026/11/11 22:53:28 INFO Upload complete. (69ms)1132=== NAME TestNARDeduplicationMetadataUploadBug1133 metadata_upload_test.go:54: Retrieved narinfo from S3:1134 StorePath: /build/TestNARDeduplicationMetadataUploadBug3920864162/001/store/9rr9p9jm17a5xbigdc65kgdqm39d87yj-file1.txt1135 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1136 Compression: zstd1137 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1138 NarSize: 1601139 References: 1140 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1141 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1142 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1143 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1144 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3920864162/001/store/s6l50m83k8nl9n82vwzas2akr48p6gld-file2.txt11452026/11/11 22:53:28 INFO Aborted multipart uploads count=0 kept=011462026/11/11 22:53:28 WARN Force mode enabled - objects will be deleted immediately without grace period11472026/11/11 22:53:28 INFO Aborted multipart uploads count=0 kept=011482026/11/11 22:53:28 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=011492026/11/11 22:53:28 WARN Force mode enabled - objects will be deleted immediately without grace period11502026/11/11 22:53:28 INFO Vacuumed table table=pending_closures11512026/11/11 22:53:28 INFO Vacuumed table table=pending_objects11522026/11/11 22:53:28 INFO Vacuumed table table=multipart_uploads11532026/11/11 22:53:28 INFO Vacuumed table table=closures11542026/11/11 22:53:28 INFO Vacuumed table table=objects11552026/11/11 22:53:28 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=011562026/11/11 22:53:28 INFO Vacuumed table table=pending_closures1157--- PASS: TestGetExistingObjectsLocksRows (0.60s)1158=== CONT TestProxyWriteTimeout1159=== RUN TestProxyWriteTimeout/narinfo1160=== PAUSE TestProxyWriteTimeout/narinfo1161=== RUN TestProxyWriteTimeout/1_GiB_nar11622026/11/11 22:53:28 INFO Vacuumed table table=pending_objects1163=== PAUSE TestProxyWriteTimeout/1_GiB_nar1164=== RUN TestProxyWriteTimeout/10_GiB_nar1165=== PAUSE TestProxyWriteTimeout/10_GiB_nar1166=== RUN TestProxyWriteTimeout/unknown_size11672026/11/11 22:53:28 INFO Vacuumed table table=multipart_uploads1168=== PAUSE TestProxyWriteTimeout/unknown_size1169=== CONT TestLeadElectsOneAndHandsOver11702026/11/11 22:53:28 INFO Vacuumed table table=closures1171--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.85s)1172=== CONT TestConnectWaitsForAPeerMigration11732026/11/11 22:53:28 INFO Vacuumed table table=objects1174--- PASS: TestSweepRechecksPendingAfterLocking (0.66s)1175=== CONT TestResolveDBConnectionString1176=== RUN TestResolveDBConnectionString/flag_wins1177=== PAUSE TestResolveDBConnectionString/flag_wins1178=== RUN TestResolveDBConnectionString/file_when_flag_empty1179=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1180=== RUN TestResolveDBConnectionString/missing_file_is_an_error1181=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1182=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1183=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1184=== RUN TestResolveDBConnectionString/nothing_configured1185=== PAUSE TestResolveDBConnectionString/nothing_configured1186=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1187--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.57s)1188=== CONT TestSkippedUploadsHandler11892026/11/11 22:53:28 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001190--- PASS: TestSkippedUploadsHandler (0.01s)1191=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock11922026/11/11 22:53:28 INFO Received push request method=POST path=/api/pushes11932026/11/11 22:53:28 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11942026/11/11 22:53:28 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11952026/11/11 22:53:28 WARN Failed to register uploaded object key=s6l50m83k8nl9n82vwzas2akr48p6gld.ls error="server returned 404: 404 page not found\n"11962026/11/11 22:53:28 INFO Signed narinfos id=2 count=111972026/11/11 22:53:28 INFO Uploading 1 narinfos11982026/11/11 22:53:28 INFO Received complete push request method=POST path=/api/pushes/2/complete11992026/11/11 22:53:28 WARN Failed to register uploaded object key=s6l50m83k8nl9n82vwzas2akr48p6gld.narinfo error="server returned 404: 404 page not found\n"12002026/11/11 22:53:28 INFO Completed push id=2 objects=3 duration=2.997888ms12012026/11/11 22:53:28 INFO Upload complete. (57ms)1202=== NAME TestNARDeduplicationMetadataUploadBug1203 metadata_upload_test.go:76: Retrieved narinfo from S3:1204 StorePath: /build/TestNARDeduplicationMetadataUploadBug3920864162/001/store/s6l50m83k8nl9n82vwzas2akr48p6gld-file2.txt1205 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1206 Compression: zstd1207 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1208 NarSize: 1601209 References: 1210 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1211 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1212 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1213 {"version":1,"root":{"type":"regular","size":44}}12142026/11/11 22:53:28 INFO Aborted multipart uploads count=0 kept=012152026/11/11 22:53:28 INFO Received uploads request method=POST path=/api/pending_closures1216--- PASS: TestNARDeduplicationMetadataUploadBug (0.98s)1217=== CONT TestParseSize1218--- PASS: TestParseSize (0.00s)1219=== CONT TestDeleteClosuresRacingPins12202026/11/11 22:53:28 WARN Force mode enabled - objects will be deleted immediately without grace period12212026/11/11 22:53:28 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=012222026/11/11 22:53:28 INFO Vacuumed table table=pending_closures12232026/11/11 22:53:28 INFO Vacuumed table table=pending_objects12242026/11/11 22:53:28 INFO Vacuumed table table=multipart_uploads12252026/11/11 22:53:28 INFO Vacuumed table table=closures12262026/11/11 22:53:28 INFO Vacuumed table table=objects12272026/11/11 22:53:29 INFO Aborted multipart uploads count=0 kept=012282026/11/11 22:53:29 INFO Received uploads request method=POST path=/api/pending_closures12292026/11/11 22:53:29 WARN Force mode enabled - objects will be deleted immediately without grace period12302026/11/11 22:53:29 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=012312026/11/11 22:53:29 INFO Vacuumed table table=pending_closures12322026/11/11 22:53:29 INFO Vacuumed table table=pending_objects12332026/11/11 22:53:29 INFO Vacuumed table table=multipart_uploads12342026/11/11 22:53:29 INFO Vacuumed table table=closures12352026/11/11 22:53:29 INFO Vacuumed table table=objects1236--- PASS: TestSweepSkipsRowsLockedByPush (0.63s)1237=== CONT TestService_Rustfstest12382026/11/11 22:53:29 INFO Received uploads request method=POST path=/api/pending_closures12392026/11/11 22:53:29 INFO Aborted multipart uploads count=0 kept=012402026/11/11 22:53:29 INFO Aborted multipart uploads count=0 kept=012412026/11/11 22:53:29 WARN Force mode enabled - objects will be deleted immediately without grace period1242--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.47s)1243=== CONT TestClientFallsBackToClosures12442026/11/11 22:53:29 WARN Force mode enabled - objects will be deleted immediately without grace period12452026/11/11 22:53:29 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12462026/11/11 22:53:29 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1247--- PASS: TestFailedS3DeleteKeepsTombstone (0.64s)1248=== CONT TestPresignedUploadRegisteredBeforeCommit12492026/11/11 22:53:29 INFO Received uploads request method=POST path=/api/pending_closures12502026/11/11 22:53:29 INFO Aborted multipart uploads count=0 kept=012512026/11/11 22:53:29 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=012522026/11/11 22:53:29 INFO Received uploads request method=POST path=/api/pending_closures12532026/11/11 22:53:29 INFO Vacuumed table table=pending_closures12542026/11/11 22:53:29 WARN Force mode enabled - objects will be deleted immediately without grace period12552026/11/11 22:53:29 INFO Vacuumed table table=pending_objects12562026/11/11 22:53:29 INFO Vacuumed table table=multipart_uploads12572026/11/11 22:53:29 INFO Vacuumed table table=closures12582026/11/11 22:53:29 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=012592026/11/11 22:53:29 INFO Vacuumed table table=pending_closures12602026/11/11 22:53:29 INFO Vacuumed table table=objects1261--- PASS: TestGCSweepDeliversEachKeyOnce (0.57s)1262=== CONT TestClientPushesUseOnePush12632026/11/11 22:53:29 INFO Vacuumed table table=pending_objects12642026/11/11 22:53:29 INFO Vacuumed table table=multipart_uploads1265--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.52s)1266=== CONT TestCompletedNarNotReofferedAcrossClosures12672026/11/11 22:53:29 INFO Vacuumed table table=closures12682026/11/11 22:53:29 INFO Vacuumed table table=objects1269--- PASS: TestGCSweepSkipsPendingObjects (0.56s)1270=== CONT TestCompleteMultipartUpload_ErrorButObjectExists12712026/11/11 22:53:29 INFO Received uploads request method=POST path=/api/pending_closures12722026/11/11 22:53:29 INFO Aborted multipart uploads count=0 kept=012732026/11/11 22:53:29 WARN Force mode enabled - objects will be deleted immediately without grace period12742026/11/11 22:53:29 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=012752026/11/11 22:53:29 INFO Vacuumed table table=pending_closures12762026/11/11 22:53:29 INFO Vacuumed table table=pending_objects12772026/11/11 22:53:29 INFO Vacuumed table table=multipart_uploads12782026/11/11 22:53:29 INFO Vacuumed table table=closures12792026/11/11 22:53:29 INFO Vacuumed table table=objects1280--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.70s)1281=== CONT TestPinProtectsFromGC1282--- PASS: TestGCMetrics (0.54s)1283=== CONT TestSharedNarBothUploadsComplete12842026/11/11 22:53:29 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"1285--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.52s)1286=== CONT TestClientSharedPathCommittedMidPush12872026/11/11 22:53:29 INFO Aborted multipart uploads count=0 kept=01288--- PASS: TestPushWaitsForSweepHoldingRow (1.21s)1289=== CONT TestPush_SignsNarinfosOfItsPendingObjects12902026/11/11 22:53:29 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=012912026/11/11 22:53:29 INFO Vacuumed table table=pending_closures12922026/11/11 22:53:29 INFO Vacuumed table table=pending_objects12932026/11/11 22:53:29 INFO Vacuumed table table=multipart_uploads12942026/11/11 22:53:29 INFO lead: acquired remote=192.0.2.1:1234 generation=112952026/11/11 22:53:29 INFO Vacuumed table table=closures12962026/11/11 22:53:29 INFO Vacuumed table table=objects12972026/11/11 22:53:29 INFO Aborted multipart uploads count=0 kept=012982026/11/11 22:53:29 WARN Force mode enabled - objects will be deleted immediately without grace period12992026/11/11 22:53:29 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=013002026/11/11 22:53:29 INFO Received push request method=POST path=/api/pushes13012026/11/11 22:53:29 INFO Vacuumed table table=pending_closures13022026/11/11 22:53:29 INFO Vacuumed table table=pending_objects13032026/11/11 22:53:29 INFO Vacuumed table table=multipart_uploads13042026/11/11 22:53:29 INFO Vacuumed table table=closures13052026/11/11 22:53:29 INFO Vacuumed table table=objects1306--- PASS: TestPushDedupSurvivesConcurrentGC (0.69s)1307=== CONT TestClientWithDependencies13082026/11/11 22:53:29 INFO Received complete push request method=POST path=/api/pushes/1/complete13092026/11/11 22:53:29 INFO Completed push id=1 objects=6 duration=9.877101ms1310--- PASS: TestPush_CompleteCommitsEveryRoot (0.55s)1311=== CONT TestPush_RejectsBadRequests13122026/11/11 22:53:29 INFO lead: acquired remote=192.0.2.1:1234 generation=113132026/11/11 22:53:29 INFO lead: acquired remote=192.0.2.1:1234 generation=113142026/11/11 22:53:29 INFO lead: released remote=192.0.2.1:1234 generation=11315--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.57s)1316=== CONT TestClientMultipleUploads13172026/11/11 22:53:29 INFO lead: acquired remote=192.0.2.1:1234 generation=113182026/11/11 22:53:29 INFO lead: acquired remote=192.0.2.1:1234 generation=113192026/11/11 22:53:29 INFO Received uploads request method=POST path=/api/pending_closures1320--- PASS: TestGCBugBareHashReferences (0.74s)1321=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1322--- PASS: TestService_Rustfstest (0.52s)1323=== CONT TestClientIntegration13242026/11/11 22:53:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13252026/11/11 22:53:29 INFO Received uploads request method=POST path=/api/pending_closures13262026/11/11 22:53:29 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst13272026/11/11 22:53:29 INFO Received uploads request method=POST path=/api/pending_closures1328--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.57s)1329=== CONT TestPush_RootsAreLockedInByteOrder13302026/11/11 22:53:29 INFO Received uploads request method=POST path=/api/pending_closures13312026/11/11 22:53:29 INFO Received uploads request method=POST path=/api/pending_closures13322026/11/11 22:53:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13332026/11/11 22:53:29 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZjE4N2NiZjQtZGJlMi00NWM0LWE3NGMtODMxMmUyZmRjZjdmLjMxMTVmZmViLTZlY2QtNDg1MS04NDNhLTcyNmJlZTA3YjdmNXgxNzk0NDM3NjA5Njg2NDM5MTI41334--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.80s)1335=== CONT TestClientErrorHandling1336=== RUN TestClientErrorHandling/InvalidStorePath1337=== PAUSE TestClientErrorHandling/InvalidStorePath1338=== RUN TestClientErrorHandling/InvalidAuthToken1339=== PAUSE TestClientErrorHandling/InvalidAuthToken1340=== RUN TestClientErrorHandling/ServerNotAvailable1341=== PAUSE TestClientErrorHandling/ServerNotAvailable1342=== CONT TestClientCADerivations13432026/11/11 22:53:29 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZjE4N2NiZjQtZGJlMi00NWM0LWE3NGMtODMxMmUyZmRjZjdmLjMxMTVmZmViLTZlY2QtNDg1MS04NDNhLTcyNmJlZTA3YjdmNXgxNzk0NDM3NjA5Njg2NDM5MTI4 parts=11344--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.57s)1345=== CONT TestPush_CompleteWaitsForCleanupOfThePush13462026/11/11 22:53:29 INFO Received uploads request method=POST path=/api/pending_closures13472026/11/11 22:53:29 INFO Received uploads request method=POST path=/api/pending_closures13482026/11/11 22:53:29 INFO Received uploads request method=POST path=/api/pending_closures13492026/11/11 22:53:29 INFO Received uploads request method=POST path=/api/pending_closures13502026/11/11 22:53:29 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13512026/11/11 22:53:29 INFO Uploading q9ywfqpx1qwrc1w9v2xasx9l1vc4ipnx-b (216B)13522026/11/11 22:53:29 INFO Uploading 2j3rdv61y2yaq2qbzd0kq5gz926p696m-shared-dep (136B)13532026/11/11 22:53:29 WARN Failed to register uploaded object key=873b5nrfw1dafwbfzlvpj433gpigiy6x.ls error="server returned 404: 404 page not found\n"13542026/11/11 22:53:29 WARN Failed to register uploaded object key=nar/0sm2qwf9mjqsshf2jhmlfhm8pisz5nxa7c7sz6f5m46ay1afgm8s.nar.zst error="server returned 404: 404 page not found\n"13552026/11/11 22:53:29 WARN Failed to register uploaded object key=2j3rdv61y2yaq2qbzd0kq5gz926p696m.ls error="server returned 404: 404 page not found\n"13562026/11/11 22:53:29 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13572026/11/11 22:53:29 WARN Failed to register uploaded object key=q9ywfqpx1qwrc1w9v2xasx9l1vc4ipnx.ls error="server returned 404: 404 page not found\n"13582026/11/11 22:53:29 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13592026/11/11 22:53:29 INFO Signed narinfos id=1 count=213602026/11/11 22:53:29 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13612026/11/11 22:53:29 INFO Signed narinfos id=2 count=213622026/11/11 22:53:29 INFO Uploading 4 narinfos13632026/11/11 22:53:29 WARN Failed to register uploaded object key=2j3rdv61y2yaq2qbzd0kq5gz926p696m.narinfo error="server returned 404: 404 page not found\n"13642026/11/11 22:53:29 WARN Failed to register uploaded object key=q9ywfqpx1qwrc1w9v2xasx9l1vc4ipnx.narinfo error="server returned 404: 404 page not found\n"13652026/11/11 22:53:29 WARN Failed to register uploaded object key=873b5nrfw1dafwbfzlvpj433gpigiy6x.narinfo error="server returned 404: 404 page not found\n"13662026/11/11 22:53:29 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13672026/11/11 22:53:29 WARN Failed to register uploaded object key=2j3rdv61y2yaq2qbzd0kq5gz926p696m.narinfo error="server returned 404: 404 page not found\n"13682026/11/11 22:53:29 INFO Completed upload id=1 objects=6 duration=6.771104ms13692026/11/11 22:53:29 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1370=== NAME TestPinProtectsFromGC1371 client_integration_test.go:778: Pinned store path: /build/TestPinProtectsFromGC3497793567/001/store/bxg4lnf7xnm6rvvcfdmypzmwbmjq1rh0-pinned-file.txt1372 client_integration_test.go:779: Unpinned store path: /build/TestPinProtectsFromGC3497793567/001/store/i4ai98iwn3vpi6k9r3lcmqlq3wdj1xsp-unpinned-file.txt13732026/11/11 22:53:29 INFO Completed upload id=2 objects=6 duration=2.126468ms13742026/11/11 22:53:29 INFO Upload complete. (81ms)1375=== NAME TestClientFallsBackToClosures1376 client_pushes_test.go:112: Retrieved narinfo from S3:1377 StorePath: /build/TestClientFallsBackToClosures588445185/001/store/2j3rdv61y2yaq2qbzd0kq5gz926p696m-shared-dep1378 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1379 Compression: zstd1380 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821381 NarSize: 1361382 References: 1383 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1384 client_pushes_test.go:112: Retrieved narinfo from S3:1385 StorePath: /build/TestClientFallsBackToClosures588445185/001/store/873b5nrfw1dafwbfzlvpj433gpigiy6x-a1386 URL: nar/0sm2qwf9mjqsshf2jhmlfhm8pisz5nxa7c7sz6f5m46ay1afgm8s.nar.zst1387 Compression: zstd1388 NarHash: sha256:0sm2qwf9mjqsshf2jhmlfhm8pisz5nxa7c7sz6f5m46ay1afgm8s1389 NarSize: 2161390 References: /build/TestClientFallsBackToClosures588445185/001/store/2j3rdv61y2yaq2qbzd0kq5gz926p696m-shared-dep1391 CA: text:sha256:0mbc3l1hg7viw8fqy0902yqh5067fgm6g4kp45jx763phbf194k713922026/11/11 22:53:29 INFO Received push request method=POST path=/api/pushes1393 client_pushes_test.go:112: Retrieved narinfo from S3:1394 StorePath: /build/TestClientFallsBackToClosures588445185/001/store/q9ywfqpx1qwrc1w9v2xasx9l1vc4ipnx-b1395 URL: nar/0sm2qwf9mjqsshf2jhmlfhm8pisz5nxa7c7sz6f5m46ay1afgm8s.nar.zst1396 Compression: zstd1397 NarHash: sha256:0sm2qwf9mjqsshf2jhmlfhm8pisz5nxa7c7sz6f5m46ay1afgm8s1398 NarSize: 2161399 References: /build/TestClientFallsBackToClosures588445185/001/store/2j3rdv61y2yaq2qbzd0kq5gz926p696m-shared-dep1400 CA: text:sha256:0mbc3l1hg7viw8fqy0902yqh5067fgm6g4kp45jx763phbf194k71401--- PASS: TestClientFallsBackToClosures (0.77s)1402=== CONT TestPush_RepeatedRootCommitsOnce14032026/11/11 22:53:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14042026/11/11 22:53:29 INFO Received push request method=POST path=/api/pushes14052026/11/11 22:53:29 INFO Signed narinfos id=1 count=114062026/11/11 22:53:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14072026/11/11 22:53:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14082026/11/11 22:53:29 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"14092026/11/11 22:53:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14102026/11/11 22:53:29 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"14112026/11/11 22:53:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14122026/11/11 22:53:29 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=114132026/11/11 22:53:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14142026/11/11 22:53:29 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1415--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.56s)1416=== CONT TestCacheStatsHandler14172026/11/11 22:53:29 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14182026/11/11 22:53:29 INFO Uploading hw9w9v5x2bli9iz0mb8vazqrvfazkghq-a (216B)14192026/11/11 22:53:29 INFO Uploading lwwln0q726x3laqi6q66m6hy8dxsq01i-shared-dep (136B)14202026/11/11 22:53:29 WARN Failed to register uploaded object key=ai3k474mdm9szkkn2hpxwwq9fk2hrl5h.ls error="server returned 404: 404 page not found\n"14212026/11/11 22:53:29 WARN Failed to register uploaded object key=lwwln0q726x3laqi6q66m6hy8dxsq01i.ls error="server returned 404: 404 page not found\n"14222026/11/11 22:53:29 WARN Failed to register uploaded object key=hw9w9v5x2bli9iz0mb8vazqrvfazkghq.ls error="server returned 404: 404 page not found\n"14232026/11/11 22:53:29 WARN Failed to register uploaded object key=nar/1yad8gbi897yw13779s56xz94qy48ma31y1cki6vd9xa8fv4nzqz.nar.zst error="server returned 404: 404 page not found\n"14242026/11/11 22:53:29 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14252026/11/11 22:53:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14262026/11/11 22:53:29 INFO Signed narinfos id=1 count=314272026/11/11 22:53:29 INFO Uploading 3 narinfos14282026/11/11 22:53:29 WARN Failed to register uploaded object key=hw9w9v5x2bli9iz0mb8vazqrvfazkghq.narinfo error="server returned 404: 404 page not found\n"14292026/11/11 22:53:29 WARN Failed to register uploaded object key=lwwln0q726x3laqi6q66m6hy8dxsq01i.narinfo error="server returned 404: 404 page not found\n"14302026/11/11 22:53:29 INFO Received complete push request method=POST path=/api/pushes/1/complete14312026/11/11 22:53:29 WARN Failed to register uploaded object key=ai3k474mdm9szkkn2hpxwwq9fk2hrl5h.narinfo error="server returned 404: 404 page not found\n"14322026/11/11 22:53:29 INFO Completed push id=1 objects=8 duration=6.783034ms14332026/11/11 22:53:29 INFO Upload complete. (65ms)1434=== NAME TestClientPushesUseOnePush1435 client_pushes_test.go:97: Retrieved narinfo from S3:1436 StorePath: /build/TestClientPushesUseOnePush3242051073/001/store/lwwln0q726x3laqi6q66m6hy8dxsq01i-shared-dep1437 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1438 Compression: zstd1439 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821440 NarSize: 1361441 References: 1442 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1443 client_pushes_test.go:97: Retrieved narinfo from S3:1444 StorePath: /build/TestClientPushesUseOnePush3242051073/001/store/hw9w9v5x2bli9iz0mb8vazqrvfazkghq-a1445 URL: nar/1yad8gbi897yw13779s56xz94qy48ma31y1cki6vd9xa8fv4nzqz.nar.zst1446 Compression: zstd1447 NarHash: sha256:1yad8gbi897yw13779s56xz94qy48ma31y1cki6vd9xa8fv4nzqz1448 NarSize: 2161449 References: /build/TestClientPushesUseOnePush3242051073/001/store/lwwln0q726x3laqi6q66m6hy8dxsq01i-shared-dep1450 CA: text:sha256:1zmm6gix16s23gcirph3kh98xcgkisd92sm27aw00sfbkfz45cmk1451 client_pushes_test.go:97: Retrieved narinfo from S3:1452 StorePath: /build/TestClientPushesUseOnePush3242051073/001/store/ai3k474mdm9szkkn2hpxwwq9fk2hrl5h-b1453 URL: nar/1yad8gbi897yw13779s56xz94qy48ma31y1cki6vd9xa8fv4nzqz.nar.zst1454 Compression: zstd1455 NarHash: sha256:1yad8gbi897yw13779s56xz94qy48ma31y1cki6vd9xa8fv4nzqz1456 NarSize: 2161457 References: /build/TestClientPushesUseOnePush3242051073/001/store/lwwln0q726x3laqi6q66m6hy8dxsq01i-shared-dep1458 CA: text:sha256:1zmm6gix16s23gcirph3kh98xcgkisd92sm27aw00sfbkfz45cmk1459--- PASS: TestClientPushesUseOnePush (0.76s)1460=== CONT TestCacheConfigHandler1461=== RUN TestCacheConfigHandler/full_config,_no_issuer1462=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1463=== RUN TestCacheConfigHandler/no_cache_url_configured1464=== PAUSE TestCacheConfigHandler/no_cache_url_configured1465=== RUN TestCacheConfigHandler/no_signing_keys1466=== PAUSE TestCacheConfigHandler/no_signing_keys1467=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1468=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1469=== CONT TestService_ReadScope_PublicByDefault1470=== RUN TestPush_RejectsBadRequests/no_roots1471=== PAUSE TestPush_RejectsBadRequests/no_roots1472=== RUN TestPush_RejectsBadRequests/no_objects1473=== PAUSE TestPush_RejectsBadRequests/no_objects1474=== RUN TestPush_RejectsBadRequests/bad_root1475=== PAUSE TestPush_RejectsBadRequests/bad_root1476=== RUN TestPush_RejectsBadRequests/root_not_in_objects1477=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1478=== CONT TestReadProxyConditionalGet14792026/11/11 22:53:29 INFO Received push request method=POST path=/api/pushes14802026/11/11 22:53:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14812026/11/11 22:53:29 INFO Uploading bxg4lnf7xnm6rvvcfdmypzmwbmjq1rh0-pinned-file.txt (128B)14822026/11/11 22:53:29 WARN Failed to register uploaded object key=bxg4lnf7xnm6rvvcfdmypzmwbmjq1rh0.ls error="server returned 404: 404 page not found\n"14832026/11/11 22:53:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14842026/11/11 22:53:29 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14852026/11/11 22:53:29 INFO Signed narinfos id=1 count=114862026/11/11 22:53:29 INFO Uploading 1 narinfos14872026/11/11 22:53:29 INFO Received complete push request method=POST path=/api/pushes/1/complete14882026/11/11 22:53:29 WARN Failed to register uploaded object key=bxg4lnf7xnm6rvvcfdmypzmwbmjq1rh0.narinfo error="server returned 404: 404 page not found\n"14892026/11/11 22:53:29 INFO Completed push id=1 objects=3 duration=11.01857ms14902026/11/11 22:53:29 INFO Upload complete. (74ms)14912026/11/11 22:53:29 INFO Received push request method=POST path=/api/pushes1492=== NAME TestClientWithDependencies1493 client_integration_test.go:660: Built derivation: /build/TestClientWithDependencies1680122814/001/store/gbi57ixbn8iifbaikbbyha50d43594ka-test-script14942026/11/11 22:53:29 INFO Received push request method=POST path=/api/pushes14952026/11/11 22:53:29 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)14962026/11/11 22:53:29 INFO Uploading qpxl12qhd98fwimi0m8nvmsmjlm6lh70-shared-dep (136B)14972026/11/11 22:53:29 INFO Uploading cg0fk4pq7xq757gicv92z73vijr19ysl-top (224B)14982026/11/11 22:53:29 WARN Failed to register uploaded object key=cg0fk4pq7xq757gicv92z73vijr19ysl.ls error="server returned 404: 404 page not found\n"1499=== NAME TestClientMultipleUploads15002026/11/11 22:53:29 WARN Failed to register uploaded object key=qpxl12qhd98fwimi0m8nvmsmjlm6lh70.ls error="server returned 404: 404 page not found\n"1501 client_integration_test.go:405: Created store path 0: /build/TestClientMultipleUploads3315094630/001/store/h6iy4hmi6lnya0lxzp4j8g082jdmfnia-test-file-0.txt15022026/11/11 22:53:29 WARN Failed to register uploaded object key=nar/1dgvnzxdmzlc0mcywabq6gmhmyapj2nzyx01lx7hhlryw46vczp1.nar.zst error="server returned 404: 404 page not found\n"15032026/11/11 22:53:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15042026/11/11 22:53:29 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15052026/11/11 22:53:29 INFO Signed narinfos id=1 count=215062026/11/11 22:53:29 INFO Uploading 2 narinfos15072026/11/11 22:53:29 INFO Received complete push request method=POST path=/api/pushes/1/complete15082026/11/11 22:53:29 WARN Failed to register uploaded object key=qpxl12qhd98fwimi0m8nvmsmjlm6lh70.narinfo error="server returned 404: 404 page not found\n"15092026/11/11 22:53:29 INFO Received complete push request method=POST path=/api/pushes/1/complete15102026/11/11 22:53:29 WARN Failed to register uploaded object key=cg0fk4pq7xq757gicv92z73vijr19ysl.narinfo error="server returned 404: 404 page not found\n"15112026/11/11 22:53:29 INFO Completed push id=1 objects=4 duration=6.818144ms15122026/11/11 22:53:29 INFO Received push request method=POST path=/api/pushes15132026/11/11 22:53:29 INFO Completed push id=1 objects=6 duration=5.342935ms15142026/11/11 22:53:29 INFO Upload complete. (66ms)1515=== NAME TestClientSharedPathCommittedMidPush1516 client_integration_test.go:727: Retrieved narinfo from S3:1517 StorePath: /build/TestClientSharedPathCommittedMidPush2281303806/001/store/qpxl12qhd98fwimi0m8nvmsmjlm6lh70-shared-dep1518 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1519 Compression: zstd1520 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821521 NarSize: 1361522 References: 1523 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1524 client_integration_test.go:727: Retrieved narinfo from S3:1525 StorePath: /build/TestClientSharedPathCommittedMidPush2281303806/001/store/cg0fk4pq7xq757gicv92z73vijr19ysl-top1526 URL: nar/1dgvnzxdmzlc0mcywabq6gmhmyapj2nzyx01lx7hhlryw46vczp1.nar.zst1527 Compression: zstd1528 NarHash: sha256:1dgvnzxdmzlc0mcywabq6gmhmyapj2nzyx01lx7hhlryw46vczp11529 NarSize: 2241530 References: /build/TestClientSharedPathCommittedMidPush2281303806/001/store/qpxl12qhd98fwimi0m8nvmsmjlm6lh70-shared-dep1531 CA: text:sha256:1d9k5qzghr6hbmxal2fj2k7x41v2izrk5rjzlvhwm0lg3d89gs841532=== NAME TestClientWithDependencies1533 client_integration_test.go:662: Found 1 dependencies (including self)1534--- PASS: TestClientSharedPathCommittedMidPush (0.73s)1535=== CONT TestService_RequireScope_OIDC15362026/11/11 22:53:29 INFO Received push request method=POST path=/api/pushes1537=== NAME TestClientMultipleUploads1538 client_integration_test.go:405: Created store path 1: /build/TestClientMultipleUploads3315094630/001/store/475wwji349is1j43i0gv3wdzaci2dydi-test-file-1.txt15392026/11/11 22:53:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15402026/11/11 22:53:30 INFO Uploading i4ai98iwn3vpi6k9r3lcmqlq3wdj1xsp-unpinned-file.txt (128B)15412026/11/11 22:53:30 INFO Received push request method=POST path=/api/pushes15422026/11/11 22:53:30 WARN Failed to register uploaded object key=i4ai98iwn3vpi6k9r3lcmqlq3wdj1xsp.ls error="server returned 404: 404 page not found\n"15432026/11/11 22:53:30 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15442026/11/11 22:53:30 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15452026/11/11 22:53:30 INFO Signed narinfos id=2 count=115462026/11/11 22:53:30 INFO Uploading 1 narinfos15472026/11/11 22:53:30 INFO Received complete push request method=POST path=/api/pushes/2/complete15482026/11/11 22:53:30 WARN Failed to register uploaded object key=i4ai98iwn3vpi6k9r3lcmqlq3wdj1xsp.narinfo error="server returned 404: 404 page not found\n"15492026/11/11 22:53:30 INFO Completed push id=2 objects=3 duration=1.481109ms15502026/11/11 22:53:30 INFO Upload complete. (50ms)1551=== NAME TestClientIntegration1552 client_integration_test.go:291: Created store path: /build/TestClientIntegration3797023952/002/store/8i5wihx3d5xj7cnzmfqjgixadf1swjsm-test-file.txt1553=== NAME TestClientMultipleUploads1554 client_integration_test.go:405: Created store path 2: /build/TestClientMultipleUploads3315094630/001/store/jaq81b4ajqbj79r58b7k25b8bpwgxg2f-test-file-2.txt15552026/11/11 22:53:30 INFO Aborted multipart uploads count=0 kept=015562026-11-11 22:53:30.039 UTC [1456] ERROR: could not obtain lock on row in relation "closures"15572026-11-11 22:53:30.039 UTC [1456] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT15582026/11/11 22:53:30 WARN Force mode enabled - objects will be deleted immediately without grace period15592026-11-11 22:53:30.040 UTC [1456] ERROR: could not obtain lock on row in relation "closures"15602026-11-11 22:53:30.040 UTC [1456] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT15612026-11-11 22:53:30.040 UTC [1456] ERROR: could not obtain lock on row in relation "closures"15622026-11-11 22:53:30.040 UTC [1456] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT15632026-11-11 22:53:30.041 UTC [1456] ERROR: could not obtain lock on row in relation "closures"15642026-11-11 22:53:30.041 UTC [1456] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT15652026-11-11 22:53:30.041 UTC [1456] ERROR: could not obtain lock on row in relation "closures"15662026-11-11 22:53:30.041 UTC [1456] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1567--- PASS: TestPush_RootsAreLockedInByteOrder (0.40s)1568=== CONT TestService_AuthMiddleware_OIDC15692026/11/11 22:53:30 INFO Received push request method=POST path=/api/pushes15702026/11/11 22:53:30 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=015712026/11/11 22:53:30 INFO Vacuumed table table=pending_closures15722026/11/11 22:53:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15732026/11/11 22:53:30 INFO Uploading gbi57ixbn8iifbaikbbyha50d43594ka-test-script (136B)15742026/11/11 22:53:30 INFO Vacuumed table table=pending_objects15752026/11/11 22:53:30 INFO Vacuumed table table=multipart_uploads15762026/11/11 22:53:30 INFO Vacuumed table table=closures15772026/11/11 22:53:30 INFO Vacuumed table table=objects15782026/11/11 22:53:30 INFO Received complete push request method=POST path=/api/pushes/2/complete15792026/11/11 22:53:30 INFO Received push request method=POST path=/api/pushes15802026/11/11 22:53:30 WARN Failed to register uploaded object key=gbi57ixbn8iifbaikbbyha50d43594ka.ls error="server returned 404: 404 page not found\n"15812026/11/11 22:53:30 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15822026/11/11 22:53:30 INFO Starting cleanup of old closures method=DELETE path=/api/closures15832026/11/11 22:53:30 INFO Garbage collection started15842026/11/11 22:53:30 INFO Completed push id=2 objects=4 duration=3.053977ms1585--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.60s)1586=== CONT TestPush_OverlappingRootsStoreOneRowPerKey15872026/11/11 22:53:30 WARN Failed to register uploaded object key=log/2hdav96fv2j7r4l3w793ffgrlrq83zp5-test-script.drv error="server returned 404: 404 page not found\n"15882026/11/11 22:53:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15892026/11/11 22:53:30 INFO Signed narinfos id=1 count=115902026/11/11 22:53:30 INFO Uploading 1 narinfos15912026/11/11 22:53:30 INFO Received complete push request method=POST path=/api/pushes/1/complete15922026/11/11 22:53:30 WARN Failed to register uploaded object key=gbi57ixbn8iifbaikbbyha50d43594ka.narinfo error="server returned 404: 404 page not found\n"15932026/11/11 22:53:30 INFO Aborted multipart uploads count=0 kept=015942026/11/11 22:53:30 WARN Force mode enabled - objects will be deleted immediately without grace period15952026/11/11 22:53:30 INFO Completed push id=1 objects=4 duration=8.878742ms15962026/11/11 22:53:30 INFO Upload complete. (70ms)1597=== NAME TestClientWithDependencies1598 client_integration_test.go:664: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1680122814/001/store) requires matching store prefix15992026/11/11 22:53:30 INFO Received push request method=POST path=/api/pushes16002026/11/11 22:53:30 INFO Received push request method=POST path=/api/pushes1601--- PASS: TestClientWithDependencies (0.77s)1602=== CONT TestService_ReadAuthMiddleware16032026/11/11 22:53:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16042026/11/11 22:53:30 INFO Uploading 8i5wihx3d5xj7cnzmfqjgixadf1swjsm-test-file.txt (152B)16052026/11/11 22:53:30 INFO Received push request method=POST path=/api/pushes16062026/11/11 22:53:30 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"16072026/11/11 22:53:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16082026/11/11 22:53:30 WARN Failed to register uploaded object key=8i5wihx3d5xj7cnzmfqjgixadf1swjsm.ls error="server returned 404: 404 page not found\n"16092026/11/11 22:53:30 INFO Signed narinfos id=1 count=116102026/11/11 22:53:30 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)16112026/11/11 22:53:30 INFO Uploading 1 narinfos16122026/11/11 22:53:30 INFO Uploading 475wwji349is1j43i0gv3wdzaci2dydi-test-file-1.txt (160B)16132026/11/11 22:53:30 INFO Uploading h6iy4hmi6lnya0lxzp4j8g082jdmfnia-test-file-0.txt (160B)16142026/11/11 22:53:30 INFO Uploading jaq81b4ajqbj79r58b7k25b8bpwgxg2f-test-file-2.txt (160B)16152026/11/11 22:53:30 INFO Received complete push request method=POST path=/api/pushes/1/complete16162026/11/11 22:53:30 INFO Received complete push request method=POST path=/api/pushes/1/complete16172026/11/11 22:53:30 WARN Failed to register uploaded object key=8i5wihx3d5xj7cnzmfqjgixadf1swjsm.narinfo error="server returned 404: 404 page not found\n"16182026/11/11 22:53:30 WARN Failed to register uploaded object key=475wwji349is1j43i0gv3wdzaci2dydi.ls error="server returned 404: 404 page not found\n"16192026/11/11 22:53:30 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"16202026/11/11 22:53:30 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"16212026/11/11 22:53:30 WARN Failed to register uploaded object key=jaq81b4ajqbj79r58b7k25b8bpwgxg2f.ls error="server returned 404: 404 page not found\n"16222026/11/11 22:53:30 WARN Failed to register uploaded object key=h6iy4hmi6lnya0lxzp4j8g082jdmfnia.ls error="server returned 404: 404 page not found\n"16232026/11/11 22:53:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16242026/11/11 22:53:30 INFO Completed push id=1 objects=4 duration=7.150823ms16252026/11/11 22:53:30 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"16262026/11/11 22:53:30 INFO Signed narinfos id=1 count=31627--- PASS: TestPush_RepeatedRootCommitsOnce (0.28s)1628=== CONT TestService_AuthMiddleware_MTLSBoundSubjects16292026/11/11 22:53:30 INFO Uploading 3 narinfos16302026/11/11 22:53:30 INFO Completed push id=1 objects=3 duration=7.723473ms16312026/11/11 22:53:30 INFO Upload complete. (65ms)1632=== NAME TestClientCADerivations1633 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations4233379707/001/store/h6v8gyqc09l3a707s94vfd3gmi9y32aw-ca-test16342026/11/11 22:53:30 WARN Failed to register uploaded object key=h6iy4hmi6lnya0lxzp4j8g082jdmfnia.narinfo error="server returned 404: 404 page not found\n"16352026/11/11 22:53:30 WARN Failed to register uploaded object key=jaq81b4ajqbj79r58b7k25b8bpwgxg2f.narinfo error="server returned 404: 404 page not found\n"16362026/11/11 22:53:30 INFO Received complete push request method=POST path=/api/pushes/1/complete16372026/11/11 22:53:30 WARN Failed to register uploaded object key=475wwji349is1j43i0gv3wdzaci2dydi.narinfo error="server returned 404: 404 page not found\n"16382026/11/11 22:53:30 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=016392026/11/11 22:53:30 INFO Completed push id=1 objects=9 duration=9.604532ms16402026/11/11 22:53:30 INFO Upload complete. (71ms)1641=== NAME TestClientMultipleUploads1642 client_integration_test.go:416: Uploaded 3 paths in 102.465241ms16432026/11/11 22:53:30 INFO Vacuumed table table=pending_closures1644--- PASS: TestCacheStatsHandler (0.30s)1645=== CONT TestReadRedirectUsesPublicS3URL16462026/11/11 22:53:30 INFO Vacuumed table table=pending_objects16472026/11/11 22:53:30 INFO Vacuumed table table=multipart_uploads16482026/11/11 22:53:30 INFO Vacuumed table table=closures1649--- PASS: TestClientMultipleUploads (0.77s)1650=== CONT TestService_AuthMiddleware_MTLSProxyHeader16512026/11/11 22:53:30 INFO Vacuumed table table=objects1652--- PASS: TestService_ReadScope_PublicByDefault (0.28s)1653=== CONT TestReadProxyRangeRequest1654=== NAME TestClientCADerivations1655 client_ca_test.go:139: Found 1 dependencies (including self)16562026/11/11 22:53:30 INFO All 1 paths already cached1657=== NAME TestClientIntegration1658 client_integration_test.go:317: Retrieved narinfo from S3:1659 StorePath: /build/TestClientIntegration3797023952/002/store/8i5wihx3d5xj7cnzmfqjgixadf1swjsm-test-file.txt1660 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1661 Compression: zstd1662 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11663 NarSize: 1521664 References: 1665 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11666 client_integration_test.go:318: Retrieved .ls file from S3 (compressed size: 77 bytes)1667 client_integration_test.go:318: Decompressed .ls content (64 bytes):1668 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}16692026/11/11 22:53:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41833/oidc1670--- PASS: TestReadProxyConditionalGet (0.31s)1671=== CONT TestReadRedirectKeepsNarinfoProxied16722026/11/11 22:53:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42277/oidc16732026/11/11 22:53:30 INFO Received push request method=POST path=/api/pushes16742026/11/11 22:53:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16752026/11/11 22:53:30 INFO Received push request method=POST path=/api/pushes16762026/11/11 22:53:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16772026/11/11 22:53:30 INFO Uploading h6v8gyqc09l3a707s94vfd3gmi9y32aw-ca-test (144B)16782026/11/11 22:53:30 INFO Received push request method=POST path=/api/pushes1679--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.20s)1680=== CONT TestReadProxyRootRedirectsToIndexHTML16812026/11/11 22:53:30 WARN Failed to register uploaded object key=h6v8gyqc09l3a707s94vfd3gmi9y32aw.ls error="server returned 404: 404 page not found\n"16822026/11/11 22:53:30 WARN Failed to register uploaded object key=log/91y4m9fnhhb3aqyb3kzi9dqikrmda6nf-ca-test.drv error="server returned 404: 404 page not found\n"16832026/11/11 22:53:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16842026/11/11 22:53:30 INFO Object in database but missing from S3 key=8i5wihx3d5xj7cnzmfqjgixadf1swjsm.ls16852026/11/11 22:53:30 WARN Found objects in DB but missing from S3, will re-upload count=116862026/11/11 22:53:30 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16872026/11/11 22:53:30 INFO Signed narinfos id=1 count=116882026/11/11 22:53:30 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16892026/11/11 22:53:30 INFO Uploading 1 narinfos16902026/11/11 22:53:30 INFO Received complete push request method=POST path=/api/pushes/1/complete16912026/11/11 22:53:30 WARN Failed to register uploaded object key=h6v8gyqc09l3a707s94vfd3gmi9y32aw.narinfo error="server returned 404: 404 page not found\n"16922026/11/11 22:53:30 INFO Received complete push request method=POST path=/api/pushes/2/complete16932026/11/11 22:53:30 WARN Failed to register uploaded object key=8i5wihx3d5xj7cnzmfqjgixadf1swjsm.ls error="server returned 404: 404 page not found\n"16942026/11/11 22:53:30 INFO Completed push id=2 objects=3 duration=16.724475ms16952026/11/11 22:53:30 INFO Completed push id=1 objects=4 duration=17.508964ms16962026/11/11 22:53:30 INFO Upload complete. (60ms)16972026/11/11 22:53:30 INFO Upload complete. (105ms)16982026/11/11 22:53:30 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZjE4N2NiZjQtZGJlMi00NWM0LWE3NGMtODMxMmUyZmRjZjdmLmMwYzllMTU5LTdmY2ItNGI5My1iN2ZjLTJhOWYxNjczYjA5ZngxNzk0NDM3NjA5NzE2MzU3MjEy parts=121699=== NAME TestClientIntegration1700 client_integration_test.go:335: Retrieved .ls file from S3 (compressed size: 62 bytes)1701 client_integration_test.go:335: Decompressed .ls content (49 bytes):1702 {"version":1,"root":{"type":"regular","size":39}}17032026/11/11 22:53:30 INFO Received uploads request method=POST path=/api/pending_closures1704=== NAME TestClientCADerivations1705 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations4233379707/001/store/h6v8gyqc09l3a707s94vfd3gmi9y32aw-ca-test1706 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1707 Compression: zstd1708 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1709 NarSize: 1441710 References: 1711 Deriver: /build/TestClientCADerivations4233379707/001/store/91y4m9fnhhb3aqyb3kzi9dqikrmda6nf-ca-test.drv1712 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1713 client_ca_test.go:185: Checking for realisation files in S3...1714 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1715 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1716--- PASS: TestService_ReadAuthMiddleware (0.21s)1717=== CONT TestReadProxy4041718--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.18s)1719=== CONT TestService_AuthMiddleware17202026/11/11 22:53:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17212026/11/11 22:53:30 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17222026/11/11 22:53:30 WARN mTLS auth: bound subjects configured but subject DN unavailable17232026/11/11 22:53:30 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1724--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.25s)1725=== CONT TestReadProxyOutlastsServerWriteTimeout17262026-11-11 22:53:30.376 UTC [1570] ERROR: Push does not exist: id=117272026-11-11 22:53:30.376 UTC [1570] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE17282026-11-11 22:53:30.376 UTC [1570] STATEMENT: SELECT commit_push($1)1729--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.65s)1730=== CONT TestReadProxyHead17312026/11/11 22:53:30 INFO lead: released remote=192.0.2.1:1234 generation=11732--- PASS: TestLeadEndsOnShutdown (1.59s)1733=== CONT TestReadProxyDisabled17342026/11/11 22:53:30 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZjE4N2NiZjQtZGJlMi00NWM0LWE3NGMtODMxMmUyZmRjZjdmLmIxZTA4YWU4LWViNjMtNGMzZi04ZGQ4LWJkNTQ0ODM4OWUxMXgxNzk0NDM3NjA5Nzc0NzE2MDAw parts=121735--- PASS: TestReadRedirectUsesPublicS3URL (0.27s)1736=== CONT TestReadProxyInvalidPath1737--- PASS: TestDeleteClosuresRacingPins (1.44s)1738=== CONT TestReadRedirectNar1739=== NAME TestClientCADerivations1740 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1741 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1742 error: binary cache 's3://bucket67?endpoint=http://localhost:35109®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations4233379707/001/store'1743 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 117442026/11/11 22:53:30 INFO Received push request method=POST path=/api/pushes1745--- PASS: TestReadProxyRangeRequest (0.28s)1746=== CONT TestReadProxyContentNegotiation1747--- PASS: TestClientCADerivations (0.71s)1748=== CONT TestReadProxyNarStreaming17492026/11/11 22:53:30 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17502026/11/11 22:53:30 INFO Received complete push request method=POST path=/api/pushes/3/complete17512026/11/11 22:53:30 WARN Failed to register uploaded object key=8i5wihx3d5xj7cnzmfqjgixadf1swjsm.ls error="server returned 404: 404 page not found\n"1752--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.30s)1753=== CONT TestReadProxyNarinfo17542026/11/11 22:53:30 INFO Completed push id=3 objects=3 duration=3.377507ms17552026/11/11 22:53:30 INFO Upload complete. (50ms)1756=== NAME TestClientIntegration1757 client_integration_test.go:352: Retrieved .ls file from S3 (compressed size: 62 bytes)1758 client_integration_test.go:352: Decompressed .ls content (49 bytes):1759 {"version":1,"root":{"type":"regular","size":39}}1760 client_integration_test.go:363: Testing garbage collection...1761=== RUN TestService_RequireScope_OIDC/builder_may_write1762=== PAUSE TestService_RequireScope_OIDC/builder_may_write1763=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1764=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1765=== RUN TestService_RequireScope_OIDC/ops_may_admin1766=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1767=== RUN TestService_RequireScope_OIDC/ops_may_not_write1768=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1769=== RUN TestService_RequireScope_OIDC/reader_may_not_write1770=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1771=== RUN TestService_RequireScope_OIDC/static_token_may_admin1772=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1773=== RUN TestService_RequireScope_OIDC/static_token_may_write1774=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1775=== RUN TestService_RequireScope_OIDC/reader_may_read1776=== PAUSE TestService_RequireScope_OIDC/reader_may_read1777=== RUN TestService_RequireScope_OIDC/writer_implies_read1778=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1779=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1780=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1781=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1782=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1783=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1784=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1785=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1786=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1787=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1788=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1789=== CONT TestReadProxyNarinfoAlreadyDecompressed17902026/11/11 22:53:30 INFO Starting cleanup of old closures method=DELETE path=/api/closures17912026/11/11 22:53:30 INFO Garbage collection started17922026/11/11 22:53:30 INFO lead: released remote=192.0.2.1:1234 generation=117932026/11/11 22:53:30 INFO lead: acquired remote=192.0.2.1:1234 generation=217942026/11/11 22:53:30 INFO Aborted multipart uploads count=0 kept=01795=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1796=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1797=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1798=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1799=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1800=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1801=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1802=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1803=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale18042026/11/11 22:53:30 WARN Force mode enabled - objects will be deleted immediately without grace period18052026/11/11 22:53:30 INFO lead: released remote=192.0.2.1:1234 generation=11806--- PASS: TestReadRedirectKeepsNarinfoProxied (0.35s)1807=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh18082026/11/11 22:53:30 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=018092026/11/11 22:53:30 INFO Vacuumed table table=pending_closures18102026/11/11 22:53:30 INFO Vacuumed table table=pending_objects18112026/11/11 22:53:30 INFO Vacuumed table table=multipart_uploads18122026/11/11 22:53:30 INFO lead: acquired remote=192.0.2.1:1234 generation=218132026/11/11 22:53:30 INFO Vacuumed table table=closures18142026/11/11 22:53:30 INFO Vacuumed table table=objects1815--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.30s)1816=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18172026/11/11 22:53:30 INFO Received uploads request method=POST path=/1818=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18192026/11/11 22:53:30 INFO Received complete multipart upload request method=POST path=/1820=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18212026/11/11 22:53:30 INFO Received uploads request method=POST path=/1822=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18232026/11/11 22:53:30 INFO Received request for more parts method=POST path=/1824=== CONT TestServerTLSConfig/no_client_CA1825=== CONT TestServerTLSConfig/not_a_PEM_file1826--- PASS: TestUploadHandlersRejectInvalidKeys (0.10s)1827 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1828 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1829 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1830 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1831=== CONT TestServerTLSConfig/missing_CA_file1832=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed1833--- PASS: TestServerTLSConfig (0.10s)1834 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1835 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1836 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)18372026/11/11 22:53:30 INFO lead: given back to the incumbent remote=192.0.2.1:1234 generation=218382026/11/11 22:53:30 INFO lead: acquired remote=192.0.2.1:1234 generation=318392026/11/11 22:53:30 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1840--- PASS: TestService_AuthMiddleware (0.33s)1841=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed1842=== NAME TestOrphanedObjectsGCStressTest1843 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1844--- PASS: TestReadProxy404 (0.37s)1845=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed1846=== NAME TestOrphanedObjectsGCStressTest1847 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion18482026/11/11 22:53:30 INFO lead: released remote=192.0.2.1:1234 generation=11849--- PASS: TestReadProxyHead (0.33s)1850=== CONT TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed1851--- PASS: TestReadProxyDisabled (0.35s)1852=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost18532026/11/11 22:53:30 INFO lead: acquired remote=192.0.2.1:1234 generation=21854--- PASS: TestReadProxyInvalidPath (0.35s)1855=== CONT TestParseSingleRange/none1856=== CONT TestParseSingleRange/open-ended1857=== CONT TestParseSingleRange/closed1858=== CONT TestParseSingleRange/malformed_end_before_start1859=== CONT TestParseSingleRange/malformed_both_empty1860=== CONT TestParseSingleRange/malformed_no_dash1861=== CONT TestParseSingleRange/multi-range_ignored1862=== CONT TestParseSingleRange/unknown_unit1863=== CONT TestParseSingleRange/end_clamped_to_size1864=== CONT TestParseSingleRange/start_past_EOF1865=== CONT TestParseSingleRange/single_byte1866=== CONT TestParseSingleRange/start_far_past_EOF1867=== CONT TestParseSingleRange/suffix_exceeds_size1868=== CONT TestParseSingleRange/suffix1869--- PASS: TestParseSingleRange (0.10s)1870 --- PASS: TestParseSingleRange/none (0.00s)1871 --- PASS: TestParseSingleRange/open-ended (0.00s)1872 --- PASS: TestParseSingleRange/closed (0.00s)1873 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1874 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1875 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1876 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1877 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1878 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1879 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1880 --- PASS: TestParseSingleRange/single_byte (0.00s)1881 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1882 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1883 --- PASS: TestParseSingleRange/suffix (0.00s)1884=== CONT TestIsValidUploadKey/narinfo1885=== CONT TestIsValidUploadKey/nix-cache-info1886=== CONT TestIsValidUploadKey/build_log_home-manager_file1887=== CONT TestIsValidUploadKey/realisation_plus_in_output1888=== CONT TestIsValidUploadKey/realisation1889=== CONT TestIsValidUploadKey/build_log_equals1890=== CONT TestIsValidUploadKey/build_log_question_mark1891=== CONT TestIsValidUploadKey/build_log_plus_in_name1892=== CONT TestIsValidUploadKey/nar_plain1893=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1894=== CONT TestIsValidUploadKey/build_log1895=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1896=== CONT TestIsValidUploadKey/listing1897=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1898=== CONT TestIsValidUploadKey/nar_xz1899=== CONT TestIsValidUploadKey/index.html1900=== CONT TestIsValidUploadKey/empty_key1901=== CONT TestIsValidUploadKey/unknown_type1902=== CONT TestIsValidUploadKey/nar_zst1903=== CONT TestIsValidUploadKey/absolute1904=== CONT TestIsValidUploadKey/traversal_nar1905=== CONT TestIsValidUploadKey/traversal1906--- PASS: TestIsValidUploadKey (0.10s)1907 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1908 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1909 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1910 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1911 --- PASS: TestIsValidUploadKey/realisation (0.00s)1912 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1913 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1914 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1915 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1916 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1917 --- PASS: TestIsValidUploadKey/build_log (0.00s)1918 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1919 --- PASS: TestIsValidUploadKey/listing (0.00s)1920 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1921 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1922 --- PASS: TestIsValidUploadKey/index.html (0.00s)1923 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1924 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1925 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1926 --- PASS: TestIsValidUploadKey/absolute (0.00s)1927 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1928 --- PASS: TestIsValidUploadKey/traversal (0.00s)1929=== CONT TestIsValidCachePath/narinfo1930=== CONT TestIsValidCachePath/index.html1931=== CONT TestIsValidCachePath/short_hash1932=== CONT TestIsValidCachePath/wrong_extension1933=== CONT TestIsValidCachePath/leading_slash1934=== CONT TestIsValidCachePath/empty1935=== CONT TestIsValidCachePath/random_path1936=== CONT TestIsValidCachePath/nar_uncompressed1937=== CONT TestIsValidCachePath/invalid_char_u1938=== CONT TestIsValidCachePath/nix-cache-info1939=== CONT TestIsValidCachePath/invalid_char_e1940=== CONT TestIsValidCachePath/realisation1941=== CONT TestIsValidCachePath/traversal_in_middle1942=== CONT TestIsValidCachePath/log1943=== CONT TestIsValidCachePath/traversal_parent1944=== CONT TestIsValidCachePath/ls1945=== CONT TestIsValidCachePath/nar_xz1946=== CONT TestIsValidCachePath/nar_zst1947=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1948=== CONT TestIsValidCachePath/nar_bz21949--- PASS: TestIsValidCachePath (0.10s)1950 --- PASS: TestIsValidCachePath/narinfo (0.00s)1951 --- PASS: TestIsValidCachePath/index.html (0.00s)1952 --- PASS: TestIsValidCachePath/short_hash (0.00s)1953 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1954 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1955 --- PASS: TestIsValidCachePath/empty (0.00s)1956 --- PASS: TestIsValidCachePath/random_path (0.00s)1957 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1958 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1959 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1960 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1961 --- PASS: TestIsValidCachePath/realisation (0.00s)1962 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1963 --- PASS: TestIsValidCachePath/log (0.00s)1964 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1965 --- PASS: TestIsValidCachePath/ls (0.00s)1966 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1967 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1968 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1969 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1970=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts19712026/11/11 22:53:30 INFO Received request for more parts method=POST path=/1972--- PASS: TestReadRedirectNar (0.38s)1973=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19742026/11/11 22:53:30 INFO Received complete multipart upload request method=POST path=/1975--- PASS: TestReadProxyNarStreaming (0.39s)1976=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19772026/11/11 22:53:30 INFO Received uploads request method=POST path=/1978=== CONT TestGCEndsOnShutdown/before_the_run1979=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark19802026/11/11 22:53:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19812026/11/11 22:53:30 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZjE4N2NiZjQtZGJlMi00NWM0LWE3NGMtODMxMmUyZmRjZjdmLmQ4ZmJmYzM4LWFkMjctNDIzYS04ZjYxLWMwNzhhN2RlODgyN3gxNzk0NDM3NjA5NzgzMzg2NDYz parts=121982--- PASS: TestSharedNarBothUploadsComplete (1.68s)1983=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1984--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.43s)1985=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1986--- PASS: TestReadProxyContentNegotiation (0.50s)1987=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check19882026/11/11 22:53:30 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1989--- PASS: TestReadProxyNarinfo (0.51s)1990=== CONT TestPendingClosureWriteTimeout/empty1991=== CONT TestPendingClosureWriteTimeout/670k_objects1992=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline19932026/11/11 22:53:30 INFO Received uploads request method=POST path=/api/pending_closures19942026/11/11 22:53:31 INFO Received uploads request method=POST path=/api/pending_closures19952026/11/11 22:53:31 INFO Received uploads request method=POST path=/api/pending_closures19962026/11/11 22:53:31 INFO Received uploads request method=POST path=/api/pending_closures19972026/11/11 22:53:31 INFO Received uploads request method=POST path=/api/pending_closures1998=== CONT TestPendingClosureWriteTimeout/400_objects1999=== CONT TestProxyWriteTimeout/narinfo2000=== CONT TestProxyWriteTimeout/10_GiB_nar2001=== CONT TestProxyWriteTimeout/unknown_size2002=== CONT TestProxyWriteTimeout/1_GiB_nar2003--- PASS: TestProxyWriteTimeout (0.00s)2004 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2005 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2006 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2007 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2008=== CONT TestResolveDBConnectionString/flag_wins2009=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2010=== CONT TestResolveDBConnectionString/nothing_configured2011=== CONT TestResolveDBConnectionString/missing_file_is_an_error2012=== CONT TestResolveDBConnectionString/file_when_flag_empty2013=== CONT TestClientErrorHandling/InvalidStorePath2014--- PASS: TestResolveDBConnectionString (0.00s)2015 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2016 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2017 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2018 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2019 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)20202026/11/11 22:53:31 INFO Aborted multipart uploads count=0 kept=020212026/11/11 22:53:31 WARN Force mode enabled - objects will be deleted immediately without grace period2022=== CONT TestClientErrorHandling/ServerNotAvailable20232026/11/11 22:53:31 INFO Aborted multipart uploads count=0 kept=020242026/11/11 22:53:31 WARN Force mode enabled - objects will be deleted immediately without grace period20252026/11/11 22:53:31 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:35109/bucket103/?delete=\": context canceled"2026--- PASS: TestGCEndsOnShutdown (0.00s)2027 --- PASS: TestGCEndsOnShutdown/before_the_run (0.32s)2028 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.36s)2029 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.34s)2030=== CONT TestClientErrorHandling/InvalidAuthToken20312026/11/11 22:53:31 INFO Received uploads request method=POST path=/api/pending_closures20322026/11/11 22:53:31 INFO Aborted multipart uploads count=0 kept=020332026/11/11 22:53:31 WARN Force mode enabled - objects will be deleted immediately without grace period20342026/11/11 22:53:31 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=020352026/11/11 22:53:31 INFO Vacuumed table table=pending_closures20362026/11/11 22:53:31 INFO Vacuumed table table=pending_objects20372026/11/11 22:53:31 INFO Vacuumed table table=multipart_uploads20382026/11/11 22:53:31 INFO Vacuumed table table=closures20392026/11/11 22:53:31 INFO Vacuumed table table=objects20402026/11/11 22:53:31 INFO Received uploads request method=POST path=/api/pending_closures20412026/11/11 22:53:31 INFO Aborted multipart uploads count=0 kept=02042=== CONT TestCacheConfigHandler/full_config,_no_issuer2043=== CONT TestCacheConfigHandler/no_signing_keys2044=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2045=== CONT TestCacheConfigHandler/no_cache_url_configured2046--- PASS: TestCacheConfigHandler (0.00s)2047 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2048 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2049 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2050 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2051=== CONT TestPush_RejectsBadRequests/no_roots20522026/11/11 22:53:31 INFO Received push request method=POST path=/api/pushes2053=== CONT TestPush_RejectsBadRequests/bad_root20542026/11/11 22:53:31 INFO Received push request method=POST path=/api/pushes2055=== CONT TestPush_RejectsBadRequests/root_not_in_objects20562026/11/11 22:53:31 INFO Received push request method=POST path=/api/pushes2057=== CONT TestPush_RejectsBadRequests/no_objects20582026/11/11 22:53:31 INFO Received push request method=POST path=/api/pushes2059=== CONT TestService_RequireScope_OIDC/builder_may_write2060--- PASS: TestPush_RejectsBadRequests (0.54s)2061 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2062 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2063 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2064 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2065=== CONT TestService_RequireScope_OIDC/reader_may_read2066=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2067=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read20682026/11/11 22:53:31 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]2069=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2070=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2071=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read20722026/11/11 22:53:31 WARN Force mode enabled - objects will be deleted immediately without grace period2073=== CONT TestService_RequireScope_OIDC/writer_implies_read2074=== CONT TestService_RequireScope_OIDC/reader_may_not_write20752026/11/11 22:53:31 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/present2076=== CONT TestService_RequireScope_OIDC/static_token_may_write20772026/11/11 22:53:31 INFO Received uploads request method=POST path=/api/pending_closures2078=== CONT TestService_RequireScope_OIDC/static_token_may_admin2079--- PASS: TestUploadHandlersRejectOversizedBody (0.17s)2080 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.08s)2081 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)2082 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.53s)2083=== CONT TestService_RequireScope_OIDC/ops_may_admin2084=== CONT TestService_RequireScope_OIDC/ops_may_not_write2085=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2086=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2087=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20882026/11/11 22:53:31 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]2089=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2090=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2091--- PASS: TestService_RequireScope_OIDC (0.49s)2092 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2093 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2094 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2095 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2096 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2097 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2098 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.07s)2099 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2100 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2101 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2102 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2103 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2104 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2105 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)21062026/11/11 22:53:31 WARN Authentication failed token_preview=eyJhbGciOi...LD0V1dHTkg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2107--- PASS: TestService_AuthMiddleware_OIDC (0.46s)2108 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2109 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2110 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2111 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)21122026/11/11 22:53:31 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=021132026/11/11 22:53:31 INFO Vacuumed table table=pending_closures21142026/11/11 22:53:31 INFO Vacuumed table table=pending_objects21152026/11/11 22:53:31 INFO Vacuumed table table=multipart_uploads21162026/11/11 22:53:31 INFO Vacuumed table table=closures21172026/11/11 22:53:31 INFO Vacuumed table table=objects2118--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2119 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.36s)2120 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.51s)21212026/11/11 22:53:31 WARN Request failed, retrying attempt=2 backoff=208.494814ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2122--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.02s)2123 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.94s)2124 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.93s)21252026/11/11 22:53:31 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21262026/11/11 22:53:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21272026/11/11 22:53:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21282026/11/11 22:53:31 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21292026/11/11 22:53:31 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst upload_id=ZjE4N2NiZjQtZGJlMi00NWM0LWE3NGMtODMxMmUyZmRjZjdmLjVlNDM4MjI4LWRiYjQtNGE1ZC04NDAwLTY4ZTM0OTVlMTczMXgxNzk0NDM3NjExMDE3NTU2MzIz parts=1021302026/11/11 22:53:31 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst upload_id=ZjE4N2NiZjQtZGJlMi00NWM0LWE3NGMtODMxMmUyZmRjZjdmLjdhYWI2OGI0LWY3ZjktNDliZC04NzMxLTRhMmRmNTY0ZjVkZHgxNzk0NDM3NjExMDM2MDU3NDM3 parts=1021312026/11/11 22:53:31 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21322026/11/11 22:53:31 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21332026/11/11 22:53:31 INFO Completed upload id=1 objects=3 duration=1.704128ms21342026/11/11 22:53:31 INFO Completed upload id=1 objects=3 duration=3.124227ms21352026/11/11 22:53:31 INFO Received uploads request method=POST path=/api/pending_closures21362026/11/11 22:53:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21372026/11/11 22:53:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21382026/11/11 22:53:31 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000200000000000000000000.nar.zst upload_id=ZjE4N2NiZjQtZGJlMi00NWM0LWE3NGMtODMxMmUyZmRjZjdmLjI3N2ZkNGJkLTk1ZWYtNDY1NS04ZTY1LTdhNWE1ZDEwNGEwYXgxNzk0NDM3NjExMDkyNDQ2NDY3 parts=1021392026/11/11 22:53:31 INFO lead: released remote=192.0.2.1:1234 generation=221402026/11/11 22:53:31 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21412026/11/11 22:53:31 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst upload_id=ZjE4N2NiZjQtZGJlMi00NWM0LWE3NGMtODMxMmUyZmRjZjdmLjZmODAxZDVhLWM3OWMtNDU5NS04YzM2LWZmOWM2ZGYwYjgwYXgxNzk0NDM3NjExMDYyNTY2NTQz parts=1021422026/11/11 22:53:31 INFO Completed upload id=1 objects=3 duration=2.884338ms21432026/11/11 22:53:31 INFO Received uploads request method=POST path=/api/pending_closures21442026/11/11 22:53:31 INFO Received uploads request method=POST path=/api/pending_closures21452026/11/11 22:53:31 INFO lead: acquired remote=192.0.2.1:1234 generation=321462026/11/11 22:53:31 INFO lead: released remote=192.0.2.1:1234 generation=32147--- PASS: TestLeadGenerationGrowsWithEveryGrant (2.81s)21482026/11/11 22:53:31 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst21492026/11/11 22:53:31 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0001.narinfo21502026/11/11 22:53:31 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21512026/11/11 22:53:31 INFO Completed upload id=1 objects=3 duration=4.208136ms21522026/11/11 22:53:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21532026/11/11 22:53:31 INFO Received uploads request method=POST path=/api/pending_closures21542026/11/11 22:53:31 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst upload_id=ZjE4N2NiZjQtZGJlMi00NWM0LWE3NGMtODMxMmUyZmRjZjdmLjIwZTVkZTBmLTdjNjItNGM1Yy1iN2I2LWEzNDk2ODQyZDdlNXgxNzk0NDM3NjExMTIyMjQ0NTYx parts=1021552026/11/11 22:53:31 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst21562026/11/11 22:53:31 WARN Found objects in DB but missing from S3, will re-upload count=121572026/11/11 22:53:31 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21582026/11/11 22:53:31 INFO Completed upload id=1 objects=3 duration=3.417407ms21592026/11/11 22:53:31 INFO Received uploads request method=POST path=/api/pending_closures21602026/11/11 22:53:31 WARN Request failed, retrying attempt=3 backoff=416.995188ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21612026/11/11 22:53:31 INFO lead: released remote=192.0.2.1:1234 generation=22162--- PASS: TestLeadElectsOneAndHandsOver (2.93s)21632026/11/11 22:53:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21642026/11/11 22:53:32 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100400000000000000000000.nar.zst upload_id=ZjE4N2NiZjQtZGJlMi00NWM0LWE3NGMtODMxMmUyZmRjZjdmLmQ2NDAwNDNkLWM4M2QtNGI1Ny1iNmNkLWUzYzk5ODA4OTMxMngxNzk0NDM3NjExNTcwNzMzODMw parts=1021652026/11/11 22:53:32 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21662026/11/11 22:53:32 INFO Completed upload id=2 objects=3 duration=1.384949ms21672026/11/11 22:53:32 INFO Received uploads request method=POST path=/api/pending_closures21682026/11/11 22:53:32 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst21692026/11/11 22:53:32 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0004.narinfo21702026/11/11 22:53:32 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=021712026/11/11 22:53:32 INFO Received create pin request method=POST path=/api/pins/myapp2172=== NAME TestOrphanedObjectsGCStressTest2173 orphaned_objects_gc_test.go:503: Stress test completed successfully:2174 orphaned_objects_gc_test.go:504: - Active objects preserved: 202175 orphaned_objects_gc_test.go:505: - Objects deleted: 2102176 orphaned_objects_gc_test.go:506: - Total GC'd: 2102177--- PASS: TestOrphanedObjectsGCStressTest (4.18s)21782026/11/11 22:53:32 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21792026/11/11 22:53:32 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3497793567/001/store/bxg4lnf7xnm6rvvcfdmypzmwbmjq1rh0-pinned-file.txt narinfo_key=bxg4lnf7xnm6rvvcfdmypzmwbmjq1rh0.narinfo21802026/11/11 22:53:32 INFO Starting cleanup of old closures method=DELETE path=/api/closures21812026/11/11 22:53:32 INFO Garbage collection started21822026/11/11 22:53:32 INFO Aborted multipart uploads count=0 kept=021832026/11/11 22:53:32 WARN Request failed, retrying attempt=4 backoff=766.709072ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21842026/11/11 22:53:32 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100300000000000000000000.nar.zst upload_id=ZjE4N2NiZjQtZGJlMi00NWM0LWE3NGMtODMxMmUyZmRjZjdmLjBmNzI1ODMwLTljNWUtNDdhMC05NjNlLTlkMjQ5NGEyMDNlMHgxNzk0NDM3NjExNjU5ODE4NTgy parts=1021852026/11/11 22:53:32 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21862026/11/11 22:53:32 INFO Completed upload id=2 objects=3 duration=1.514989ms21872026/11/11 22:53:32 WARN Force mode enabled - objects will be deleted immediately without grace period21882026/11/11 22:53:32 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=021892026/11/11 22:53:32 INFO Vacuumed table table=pending_closures21902026/11/11 22:53:32 INFO Vacuumed table table=pending_objects21912026/11/11 22:53:32 INFO Vacuumed table table=multipart_uploads21922026/11/11 22:53:32 INFO Vacuumed table table=closures21932026/11/11 22:53:32 INFO Vacuumed table table=objects21942026/11/11 22:53:32 INFO Received uploads request method=POST path=/api/pending_closures21952026/11/11 22:53:32 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst21962026/11/11 22:53:32 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0003.narinfo2197--- PASS: TestService_verifyS3ReuploadsStaleNarinfo (0.10s)2198 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed (0.90s)2199 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed (1.03s)2200 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed (0.98s)2201 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed (1.41s)2202 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost (1.42s)2203--- PASS: TestPendingClosureWriteTimeout (0.00s)2204 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2205 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2206 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2207 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.21s)22082026/11/11 22:53:32 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02209=== NAME TestClientIntegration2210 client_integration_test.go:370: Objects in database after GC:2211 client_integration_test.go:370: Successfully deleted all objects with GC --force2212--- PASS: TestClientIntegration (2.94s)22132026/11/11 22:53:32 INFO lead: released remote=192.0.2.1:1234 generation=32214--- PASS: TestLeadUnannouncedStandbyYieldsToIncumbent (3.69s)22152026/11/11 22:53:32 WARN Request failed, retrying attempt=5 backoff=1.516940745s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2216--- PASS: TestConnectWaitsForAPeerMigration (5.17s)2217=== NAME TestPinProtectsFromGC2218 client_integration_test.go:887: Pin successfully protected closure from garbage collection2219--- PASS: TestPinProtectsFromGC (4.88s)22202026/11/11 22:53:34 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-config22212026/11/11 22:53:34 INFO Aborted multipart uploads count=1 kept=022222026/11/11 22:53:34 INFO Received cleanup request method=DELETE path=/api/pending_closures22232026/11/11 22:53:34 INFO Aborted multipart uploads count=1 kept=02224--- PASS: TestPendingCleanupUsesOneCutoff (6.60s)22252026/11/11 22:53:34 WARN Request failed, retrying attempt=2 backoff=196.516761ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22262026/11/11 22:53:34 WARN Rate limiter enabled after throttle name=s3-test rate=522272026/11/11 22:53:34 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2228=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2229 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102230 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002231--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.67s)22322026/11/11 22:53:34 WARN Request failed, retrying attempt=3 backoff=397.201056ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2233--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.51s)22342026/11/11 22:53:35 WARN Request failed, retrying attempt=4 backoff=754.881636ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22352026/11/11 22:53:35 WARN Request failed, retrying attempt=5 backoff=1.756734482s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22362026/11/11 22:53:37 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"22372026/11/11 22:53:37 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22382026/11/11 22:53:37 WARN Request failed, retrying attempt=2 backoff=210.717333ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22392026/11/11 22:53:37 WARN Request failed, retrying attempt=3 backoff=390.5052ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22402026/11/11 22:53:38 WARN Request failed, retrying attempt=4 backoff=867.129918ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22412026/11/11 22:53:39 WARN Request failed, retrying attempt=5 backoff=1.753943321s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22422026/11/11 22:53:40 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22432026/11/11 22:53:41 WARN Request failed, retrying attempt=2 backoff=215.502703ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22442026/11/11 22:53:41 WARN Request failed, retrying attempt=3 backoff=380.501006ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22452026/11/11 22:53:41 WARN Request failed, retrying attempt=4 backoff=782.586821ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22462026/11/11 22:53:42 WARN Request failed, retrying attempt=5 backoff=1.503102953s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2247--- PASS: TestClientErrorHandling (0.00s)2248 --- PASS: TestClientErrorHandling/InvalidStorePath (0.27s)2249 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.31s)2250 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.74s)2251PASS2252{"timestamp":"2026-11-11T22:53:43.956762019Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:38856","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(390)"}22532026-11-11 22:53:44.262 UTC [129] LOG: received smart shutdown request22542026-11-11 22:53:44.268 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 122552026-11-11 22:53:44.276 UTC [134] LOG: shutting down22562026-11-11 22:53:44.277 UTC [134] LOG: checkpoint starting: shutdown immediate22572026-11-11 22:53:46.215 UTC [134] LOG: checkpoint complete: wrote 11229 buffers (68.5%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.231 s, sync=1.641 s, total=1.939 s; sync files=36842, longest=0.002 s, average=0.001 s; distance=530978 kB, estimate=530978 kB; lsn=0/21DEE800, redo lsn=0/21DEE80022582026-11-11 22:53:46.299 UTC [129] LOG: database system is shut down2259Running OIDC tests...2260=== RUN TestAudienceForIssuer2261=== PAUSE TestAudienceForIssuer2262=== RUN TestGlobMatch2263=== PAUSE TestGlobMatch2264=== RUN TestValidateToken_ValidToken2265=== PAUSE TestValidateToken_ValidToken2266=== RUN TestValidateToken_WrongAudience2267=== PAUSE TestValidateToken_WrongAudience2268=== RUN TestValidateToken_Expired2269=== PAUSE TestValidateToken_Expired2270=== RUN TestValidateToken_BoundClaimsMismatch2271=== PAUSE TestValidateToken_BoundClaimsMismatch2272=== RUN TestValidateToken_BoundSubjectMismatch2273=== PAUSE TestValidateToken_BoundSubjectMismatch2274=== RUN TestValidateToken_MultipleProviders2275=== PAUSE TestValidateToken_MultipleProviders2276=== RUN TestValidateToken_NoMatchingProvider2277=== PAUSE TestValidateToken_NoMatchingProvider2278=== RUN TestValidateToken_KubernetesServiceAccount2279=== PAUSE TestValidateToken_KubernetesServiceAccount2280=== RUN TestNewValidator_KubernetesRequiresCA2281=== PAUSE TestNewValidator_KubernetesRequiresCA2282=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2283=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2284=== RUN TestPins_ReservedForMatchingRule2285=== PAUSE TestPins_ReservedForMatchingRule2286=== RUN TestPins_TopLevelShorthand2287=== PAUSE TestPins_TopLevelShorthand2288=== RUN TestPins_ConfigValidation2289=== PAUSE TestPins_ConfigValidation2290=== RUN TestScopes_LegacyProviderDefaultsToWrite2291=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2292=== RUN TestScopes_Rules2293=== PAUSE TestScopes_Rules2294=== RUN TestScopes_ConfigValidation2295=== PAUSE TestScopes_ConfigValidation2296=== CONT TestAudienceForIssuer2297=== CONT TestPins_ConfigValidation2298--- PASS: TestAudienceForIssuer (0.00s)2299=== CONT TestValidateToken_NoMatchingProvider2300=== CONT TestValidateToken_MultipleProviders2301=== CONT TestValidateToken_BoundSubjectMismatch2302=== CONT TestValidateToken_BoundClaimsMismatch2303--- PASS: TestPins_ConfigValidation (0.00s)2304=== CONT TestValidateToken_Expired2305=== CONT TestValidateToken_KubernetesServiceAccount2306=== CONT TestValidateToken_WrongAudience2307=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2308=== CONT TestValidateToken_ValidToken2309=== CONT TestNewValidator_KubernetesRequiresCA2310=== CONT TestGlobMatch2311=== CONT TestScopes_Rules2312=== CONT TestPins_TopLevelShorthand2313=== CONT TestScopes_ConfigValidation2314=== CONT TestScopes_LegacyProviderDefaultsToWrite2315=== CONT TestPins_ReservedForMatchingRule2316=== RUN TestGlobMatch/foo_foo2317--- PASS: TestScopes_ConfigValidation (0.00s)2318=== PAUSE TestGlobMatch/foo_foo2319=== RUN TestGlobMatch/foo_bar2320=== PAUSE TestGlobMatch/foo_bar2321=== RUN TestGlobMatch/*_2322=== PAUSE TestGlobMatch/*_2323=== RUN TestGlobMatch/*_anything2324=== PAUSE TestGlobMatch/*_anything2325=== RUN TestGlobMatch/foo*_foo2326=== PAUSE TestGlobMatch/foo*_foo2327=== RUN TestGlobMatch/foo*_foobar2328=== PAUSE TestGlobMatch/foo*_foobar2329=== RUN TestGlobMatch/foo*_bar2330=== PAUSE TestGlobMatch/foo*_bar2331=== RUN TestGlobMatch/*bar_bar2332=== PAUSE TestGlobMatch/*bar_bar2333=== RUN TestGlobMatch/*bar_foobar2334=== PAUSE TestGlobMatch/*bar_foobar2335=== RUN TestGlobMatch/*bar_foo2336=== PAUSE TestGlobMatch/*bar_foo2337=== RUN TestGlobMatch/foo*bar_foobar2338=== PAUSE TestGlobMatch/foo*bar_foobar2339=== RUN TestGlobMatch/foo*bar_foo123bar2340=== PAUSE TestGlobMatch/foo*bar_foo123bar2341=== RUN TestGlobMatch/foo*bar_foobarbaz2342=== PAUSE TestGlobMatch/foo*bar_foobarbaz2343=== RUN TestGlobMatch/*/*_foo/bar2344=== PAUSE TestGlobMatch/*/*_foo/bar2345=== RUN TestGlobMatch/*/*_foo2346=== PAUSE TestGlobMatch/*/*_foo2347=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2348=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2349=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02350=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02351=== RUN TestGlobMatch/refs/*/main_refs/heads/main2352=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2353=== RUN TestGlobMatch/fo?_foo2354=== PAUSE TestGlobMatch/fo?_foo2355=== RUN TestGlobMatch/fo?_fo2356=== PAUSE TestGlobMatch/fo?_fo2357=== RUN TestGlobMatch/fo?_fooo2358=== PAUSE TestGlobMatch/fo?_fooo2359=== RUN TestGlobMatch/?oo_foo2360=== PAUSE TestGlobMatch/?oo_foo2361=== RUN TestGlobMatch/?oo_boo2362=== PAUSE TestGlobMatch/?oo_boo2363=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2364=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2365=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2366=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2367=== CONT TestGlobMatch/foo_foo2368=== CONT TestGlobMatch/?oo_foo2369=== CONT TestGlobMatch/*bar_bar2370=== CONT TestGlobMatch/foo*_bar2371=== CONT TestGlobMatch/foo*_foobar2372=== CONT TestGlobMatch/foo*bar_foobarbaz2373=== CONT TestGlobMatch/*_anything2374=== CONT TestGlobMatch/*_2375=== CONT TestGlobMatch/foo_bar2376=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2377=== CONT TestGlobMatch/fo?_fooo2378=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2379=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02380=== CONT TestGlobMatch/fo?_foo2381=== CONT TestGlobMatch/*/*_foo2382=== CONT TestGlobMatch/refs/*/main_refs/heads/main2383=== CONT TestGlobMatch/fo?_fo2384=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2385=== CONT TestGlobMatch/?oo_boo2386=== CONT TestGlobMatch/foo*bar_foo123bar2387=== CONT TestGlobMatch/foo*bar_foobar2388=== CONT TestGlobMatch/*bar_foo2389=== CONT TestGlobMatch/*bar_foobar2390=== CONT TestGlobMatch/*/*_foo/bar2391=== CONT TestGlobMatch/foo*_foo2392--- PASS: TestGlobMatch (0.00s)2393 --- PASS: TestGlobMatch/foo_foo (0.00s)2394 --- PASS: TestGlobMatch/?oo_foo (0.00s)2395 --- PASS: TestGlobMatch/*bar_bar (0.00s)2396 --- PASS: TestGlobMatch/foo*_bar (0.00s)2397 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2398 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2399 --- PASS: TestGlobMatch/*_anything (0.00s)2400 --- PASS: TestGlobMatch/*_ (0.00s)2401 --- PASS: TestGlobMatch/foo_bar (0.00s)2402 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2403 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2404 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2405 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2406 --- PASS: TestGlobMatch/fo?_foo (0.00s)2407 --- PASS: TestGlobMatch/*/*_foo (0.00s)2408 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2409 --- PASS: TestGlobMatch/fo?_fo (0.00s)2410 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2411 --- PASS: TestGlobMatch/?oo_boo (0.00s)2412 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2413 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2414 --- PASS: TestGlobMatch/*bar_foo (0.00s)2415 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2416 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2417 --- PASS: TestGlobMatch/foo*_foo (0.00s)24182026/11/11 22:53:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34293/oidc24192026/11/11 22:53:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40647/oidc2420--- PASS: TestValidateToken_Expired (0.03s)2421--- PASS: TestPins_ReservedForMatchingRule (0.02s)24222026/11/11 22:53:48 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:3945924232026/11/11 22:53:48 http: TLS handshake error from 127.0.0.1:34858: remote error: tls: bad certificate2424--- PASS: TestValidateToken_KubernetesServiceAccount (0.04s)2425--- PASS: TestNewValidator_KubernetesRequiresCA (0.03s)24262026/11/11 22:53:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39291/oidc2427--- PASS: TestValidateToken_BoundClaimsMismatch (0.04s)24282026/11/11 22:53:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45279/oidc24292026/11/11 22:53:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38997/oidc2430--- PASS: TestScopes_Rules (0.04s)2431--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.04s)24322026/11/11 22:53:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46481/oidc2433--- PASS: TestPins_TopLevelShorthand (0.05s)24342026/11/11 22:53:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41941/oidc2435--- PASS: TestValidateToken_ValidToken (0.06s)24362026/11/11 22:53:48 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232437--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.07s)24382026/11/11 22:53:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45817/oidc2439--- PASS: TestValidateToken_BoundSubjectMismatch (0.12s)24402026/11/11 22:53:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38013/oidc2441--- PASS: TestValidateToken_WrongAudience (0.13s)24422026/11/11 22:53:48 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:35111/oidc2443--- PASS: TestValidateToken_NoMatchingProvider (0.14s)24442026/11/11 22:53:48 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:37541/oidc24452026/11/11 22:53:48 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:32831/oidc2446--- PASS: TestValidateToken_MultipleProviders (0.22s)2447PASS2448Running hook tests...2449=== RUN TestSendPathsEmpty2450=== PAUSE TestSendPathsEmpty2451=== RUN TestQueueEnqueueAndFetch2452=== PAUSE TestQueueEnqueueAndFetch2453=== RUN TestQueueDeduplication2454=== PAUSE TestQueueDeduplication2455=== RUN TestQueueRemove2456=== PAUSE TestQueueRemove2457=== RUN TestQueueFetchBatchLimit2458=== PAUSE TestQueueFetchBatchLimit2459=== RUN TestQueueRetryMovesToBack2460=== PAUSE TestQueueRetryMovesToBack2461=== RUN TestQueueFetchRemoveLifecycle2462=== PAUSE TestQueueFetchRemoveLifecycle2463=== RUN TestQueueConcurrentWriters2464=== PAUSE TestQueueConcurrentWriters2465=== RUN TestQueueRemoveLargeClosure2466=== PAUSE TestQueueRemoveLargeClosure2467=== RUN TestServerClientIntegration2468--- PASS: TestServerClientIntegration (0.00s)2469=== RUN TestServerQueueError24702026/11/11 22:53:48 ERROR Failed to queue paths error="permission denied" count=12471--- PASS: TestServerQueueError (0.00s)2472=== RUN TestGetListenerSocketActivation2473 server_test.go:218: === RUN TestGetListenerSocketActivation2474 --- PASS: TestGetListenerSocketActivation (0.00s)2475 PASS2476 2477--- PASS: TestGetListenerSocketActivation (0.01s)2478=== RUN TestServerStalledClientDoesNotBlockShutdown2479=== PAUSE TestServerStalledClientDoesNotBlockShutdown2480=== RUN TestServerBacksOffOnAcceptErrors2481=== PAUSE TestServerBacksOffOnAcceptErrors2482=== RUN TestDrainIsolatesPoisonPath2483=== PAUSE TestDrainIsolatesPoisonPath2484=== RUN TestRunNotBlockedByPoisonHead2485=== PAUSE TestRunNotBlockedByPoisonHead2486=== RUN TestDrainGivesUpWhenServerDown2487=== PAUSE TestDrainGivesUpWhenServerDown2488=== RUN TestFailedPathPrunedByLaterClosure2489=== PAUSE TestFailedPathPrunedByLaterClosure2490=== RUN TestWorkerUploadsAndRemoves2491=== PAUSE TestWorkerUploadsAndRemoves2492=== RUN TestWorkerSkipsGCdPaths2493=== PAUSE TestWorkerSkipsGCdPaths2494=== RUN TestWorkerPrunesClosureDeps2495=== PAUSE TestWorkerPrunesClosureDeps2496=== RUN TestDrainTimeout2497=== PAUSE TestDrainTimeout2498=== RUN TestWorkerRemoveFailureIsNotProgress2499=== PAUSE TestWorkerRemoveFailureIsNotProgress2500=== RUN TestWorkerKeepsPathItCannotStat2501=== PAUSE TestWorkerKeepsPathItCannotStat2502=== CONT TestSendPathsEmpty2503=== CONT TestWorkerPrunesClosureDeps2504--- PASS: TestSendPathsEmpty (0.00s)2505=== CONT TestWorkerKeepsPathItCannotStat2506=== CONT TestWorkerRemoveFailureIsNotProgress2507=== CONT TestDrainTimeout2508=== CONT TestDrainIsolatesPoisonPath2509=== CONT TestQueueRetryMovesToBack2510=== CONT TestQueueFetchBatchLimit2511=== CONT TestQueueRemove2512=== CONT TestQueueDeduplication2513=== CONT TestQueueEnqueueAndFetch2514=== CONT TestFailedPathPrunedByLaterClosure2515=== CONT TestWorkerSkipsGCdPaths2516=== CONT TestWorkerUploadsAndRemoves2517=== CONT TestServerStalledClientDoesNotBlockShutdown2518=== CONT TestServerBacksOffOnAcceptErrors2519=== CONT TestQueueRemoveLargeClosure25202026/11/11 22:53:48 ERROR Accept failed error="too many open files"2521=== CONT TestDrainGivesUpWhenServerDown2522=== CONT TestRunNotBlockedByPoisonHead2523=== CONT TestQueueConcurrentWriters2524=== CONT TestQueueFetchRemoveLifecycle25252026/11/11 22:53:48 ERROR Accept failed error="too many open files"25262026/11/11 22:53:48 INFO Uploading batch count=425272026/11/11 22:53:48 INFO Upload queue status pending=225282026/11/11 22:53:48 INFO Uploading batch count=125292026/11/11 22:53:48 ERROR Upload failed error="upload failed" count=425302026/11/11 22:53:48 INFO Upload queue status pending=225312026/11/11 22:53:48 ERROR Upload failed error="upload failed" count=125322026/11/11 22:53:48 INFO Uploading batch count=225332026/11/11 22:53:48 INFO Upload queue status pending=325342026/11/11 22:53:48 INFO Uploading batch count=225352026/11/11 22:53:48 INFO Uploading batch count=125362026/11/11 22:53:48 ERROR Upload failed error="upload failed" count=125372026/11/11 22:53:48 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3370317297/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat3370317297/002/locked/aaa: permission denied"25382026/11/11 22:53:48 INFO Upload queue status pending=225392026/11/11 22:53:48 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3220582489/002/bbb25402026/11/11 22:53:48 INFO Uploading batch count=225412026/11/11 22:53:48 ERROR Upload failed error="upload failed" count=225422026/11/11 22:53:48 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown305926897/002/a25432026/11/11 22:53:48 INFO Uploading batch count=125442026/11/11 22:53:48 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3370317297/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat3370317297/002/locked/aaa: permission denied"25452026/11/11 22:53:48 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1674224671/002/nonexistent25462026/11/11 22:53:48 INFO Uploading batch count=12547--- PASS: TestQueueFetchBatchLimit (0.02s)2548--- PASS: TestQueueDeduplication (0.02s)25492026/11/11 22:53:48 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown305926897/002/b25502026/11/11 22:53:48 INFO Uploading batch count=125512026/11/11 22:53:48 INFO Uploading batch count=125522026/11/11 22:53:48 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3370317297/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat3370317297/002/locked/aaa: permission denied"25532026/11/11 22:53:48 INFO Uploading batch count=22554--- PASS: TestQueueRetryMovesToBack (0.02s)25552026/11/11 22:53:48 ERROR Upload failed error="upload failed" count=225562026/11/11 22:53:48 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown305926897/002/c2557--- PASS: TestQueueEnqueueAndFetch (0.02s)25582026/11/11 22:53:48 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress2565925473/002/nonexistent25592026/11/11 22:53:48 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125602026/11/11 22:53:48 ERROR Accept failed error="too many open files"25612026/11/11 22:53:48 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress2565925473/002/nonexistent2562--- PASS: TestQueueFetchRemoveLifecycle (0.01s)25632026/11/11 22:53:48 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=12564--- PASS: TestQueueRemove (0.02s)25652026/11/11 22:53:48 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown305926897/002/d25662026/11/11 22:53:48 INFO Uploading batch count=125672026/11/11 22:53:48 ERROR Drain finished with paths left in queue remaining=125682026/11/11 22:53:48 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress2565925473/002/nonexistent25692026/11/11 22:53:48 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125702026/11/11 22:53:48 ERROR Drain finished with paths left in queue remaining=125712026/11/11 22:53:48 ERROR Upload failed error="upload failed" count=125722026/11/11 22:53:48 INFO Uploading batch count=225732026/11/11 22:53:48 ERROR Upload failed error="upload failed" count=225742026/11/11 22:53:48 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown305926897/002/e25752026/11/11 22:53:48 INFO Uploading batch count=125762026/11/11 22:53:48 ERROR Upload failed error="upload failed" count=12577--- PASS: TestWorkerRemoveFailureIsNotProgress (0.02s)2578--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)25792026/11/11 22:53:48 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown305926897/002/f2580--- PASS: TestWorkerKeepsPathItCannotStat (0.02s)25812026/11/11 22:53:48 INFO Uploading batch count=125822026/11/11 22:53:48 ERROR Upload failed error="upload failed" count=125832026/11/11 22:53:48 ERROR Drain finished with paths left in queue remaining=1025842026/11/11 22:53:48 ERROR Drain finished with paths left in queue remaining=12585--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2586--- PASS: TestDrainIsolatesPoisonPath (0.03s)2587--- PASS: TestWorkerUploadsAndRemoves (0.03s)2588--- PASS: TestWorkerPrunesClosureDeps (0.04s)2589--- PASS: TestWorkerSkipsGCdPaths (0.04s)25902026/11/11 22:53:48 ERROR Accept failed error="too many open files"2591--- PASS: TestQueueRemoveLargeClosure (0.06s)25922026/11/11 22:53:48 ERROR Accept failed error="too many open files"25932026/11/11 22:53:48 ERROR Accept failed error="too many open files"25942026/11/11 22:53:48 ERROR Failed to decode request error="read unix /build/hook3772129616/test.sock->@: i/o timeout"25952026/11/11 22:53:48 ERROR Failed to write response error="write unix /build/hook3772129616/test.sock->@: i/o timeout"2596--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)2597--- PASS: TestQueueConcurrentWriters (0.21s)25982026/11/11 22:53:49 ERROR Upload failed error="context deadline exceeded" count=225992026/11/11 22:53:49 ERROR Drain finished with paths left in queue remaining=42600--- PASS: TestDrainTimeout (0.22s)26012026/11/11 22:53:49 ERROR Accept failed error="too many open files"26022026/11/11 22:53:49 ERROR Accept failed error="too many open files"2603--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)26042026/11/11 22:53:49 INFO Uploading batch count=126052026/11/11 22:53:49 INFO Uploading batch count=126062026/11/11 22:53:49 INFO Uploading batch count=126072026/11/11 22:53:49 ERROR Upload failed error="upload failed" count=126082026/11/11 22:53:49 INFO Uploading batch count=126092026/11/11 22:53:49 ERROR Upload failed error="upload failed" count=126102026/11/11 22:53:49 INFO Uploading batch count=126112026/11/11 22:53:49 ERROR Upload failed error="upload failed" count=126122026/11/11 22:53:49 INFO Uploading batch count=126132026/11/11 22:53:49 ERROR Upload failed error="upload failed" count=126142026/11/11 22:53:49 ERROR Drain finished with paths left in queue remaining=12615--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2616PASS2617Running signing tests...2618=== RUN TestExternalSigner2619=== PAUSE TestExternalSigner2620=== RUN TestExternalSignerWrongPublicKey2621=== PAUSE TestExternalSignerWrongPublicKey2622=== RUN TestExternalSignerErrors2623=== PAUSE TestExternalSignerErrors2624=== RUN TestExternalSignerRestartsAfterCrash2625=== PAUSE TestExternalSignerRestartsAfterCrash2626=== RUN TestExternalSignerProgramErrorKeepsProcess2627=== PAUSE TestExternalSignerProgramErrorKeepsProcess2628=== RUN TestExternalSignerClose2629=== PAUSE TestExternalSignerClose2630=== RUN TestExternalSignerRejectsInvalidPublicKey2631=== PAUSE TestExternalSignerRejectsInvalidPublicKey2632=== RUN TestExternalSignerCancellation2633=== PAUSE TestExternalSignerCancellation2634=== RUN TestGenerateFingerprint2635=== PAUSE TestGenerateFingerprint2636=== RUN TestParseSigningKey2637=== PAUSE TestParseSigningKey2638=== RUN TestSign2639=== PAUSE TestSign2640=== RUN TestSignBatch2641=== PAUSE TestSignBatch2642=== RUN TestNilKeyPublicKey2643=== PAUSE TestNilKeyPublicKey2644=== RUN TestSignErrors2645=== PAUSE TestSignErrors2646=== CONT TestExternalSigner2647=== CONT TestExternalSignerProgramErrorKeepsProcess2648=== CONT TestExternalSignerCancellation2649=== CONT TestSign2650=== CONT TestParseSigningKey2651=== CONT TestGenerateFingerprint2652=== RUN TestGenerateFingerprint/basic_with_references2653=== CONT TestExternalSignerErrors2654=== CONT TestExternalSignerRestartsAfterCrash2655=== CONT TestSignErrors2656=== CONT TestExternalSignerRejectsInvalidPublicKey2657=== CONT TestExternalSignerWrongPublicKey2658=== CONT TestExternalSignerClose2659=== CONT TestNilKeyPublicKey2660=== CONT TestSignBatch2661=== RUN TestParseSigningKey/valid_32-byte_key2662=== PAUSE TestParseSigningKey/valid_32-byte_key2663=== RUN TestExternalSignerRejectsInvalidPublicKey/#002664=== PAUSE TestGenerateFingerprint/basic_with_references2665=== RUN TestGenerateFingerprint/no_references2666=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2667=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2668--- PASS: TestNilKeyPublicKey (0.00s)2669--- PASS: TestSign (0.00s)2670--- PASS: TestSignBatch (0.00s)2671=== RUN TestExternalSignerErrors/invalid_JSON2672=== PAUSE TestExternalSignerErrors/invalid_JSON2673=== RUN TestSignErrors/nil_key2674=== PAUSE TestSignErrors/nil_key2675=== RUN TestSignErrors/nil_narinfo2676=== PAUSE TestSignErrors/nil_narinfo2677=== RUN TestSignErrors/invalid_narinfo2678=== PAUSE TestSignErrors/invalid_narinfo2679=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002680=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2681=== PAUSE TestGenerateFingerprint/no_references2682=== RUN TestExternalSignerErrors/wrong_shape2683=== PAUSE TestExternalSignerErrors/wrong_shape2684=== RUN TestParseSigningKey/no_colon2685=== PAUSE TestParseSigningKey/no_colon2686=== RUN TestParseSigningKey/empty_name2687=== PAUSE TestParseSigningKey/empty_name2688=== RUN TestParseSigningKey/invalid_base642689=== PAUSE TestParseSigningKey/invalid_base642690=== RUN TestSignErrors/canceled2691=== PAUSE TestSignErrors/canceled2692=== CONT TestSignErrors/nil_key2693=== CONT TestSignErrors/canceled2694=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2695=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2696=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2697=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2698=== RUN TestGenerateFingerprint/invalid_nar_hash_length2699=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2700=== RUN TestGenerateFingerprint/invalid_store_path_prefix2701=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2702=== RUN TestGenerateFingerprint/invalid_reference_prefix2703=== RUN TestExternalSignerErrors/invalid_signature_base642704=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2705=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2706=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2707=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2708=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2709=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2710=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2711=== CONT TestExternalSignerRejectsInvalidPublicKey/#002712=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2713=== RUN TestParseSigningKey/wrong_length2714=== PAUSE TestParseSigningKey/wrong_length2715=== CONT TestParseSigningKey/valid_32-byte_key2716=== CONT TestParseSigningKey/invalid_base642717=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2718=== CONT TestSignErrors/invalid_narinfo2719=== CONT TestSignErrors/nil_narinfo2720=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2721=== CONT TestGenerateFingerprint/basic_with_references2722=== CONT TestGenerateFingerprint/invalid_nar_hash_length2723=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2724=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2725=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2726=== CONT TestParseSigningKey/no_colon2727=== CONT TestParseSigningKey/empty_name2728=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2729=== CONT TestParseSigningKey/wrong_length2730--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2731=== CONT TestGenerateFingerprint/no_references2732=== CONT TestGenerateFingerprint/invalid_reference_prefix2733=== PAUSE TestExternalSignerErrors/invalid_signature_base642734=== RUN TestExternalSignerErrors/exit_on_request2735=== PAUSE TestExternalSignerErrors/exit_on_request2736=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2737=== CONT TestGenerateFingerprint/invalid_store_path_prefix2738--- PASS: TestExternalSignerClose (0.00s)2739--- PASS: TestSignErrors (0.00s)2740 --- PASS: TestSignErrors/nil_key (0.00s)2741 --- PASS: TestSignErrors/canceled (0.00s)2742 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2743 --- PASS: TestSignErrors/nil_narinfo (0.00s)2744=== RUN TestExternalSignerErrors/wrong_id2745=== PAUSE TestExternalSignerErrors/wrong_id2746=== RUN TestExternalSignerErrors/missing_signature_name2747=== PAUSE TestExternalSignerErrors/missing_signature_name2748--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2749 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2750 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2751 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2752 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2753 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2754=== RUN TestExternalSignerErrors/exit_at_startup2755=== PAUSE TestExternalSignerErrors/exit_at_startup2756--- PASS: TestParseSigningKey (0.00s)2757 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2758 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2759 --- PASS: TestParseSigningKey/no_colon (0.00s)2760 --- PASS: TestParseSigningKey/empty_name (0.00s)2761 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2762 --- PASS: TestParseSigningKey/wrong_length (0.00s)2763=== RUN TestExternalSignerErrors/null_signatures2764=== PAUSE TestExternalSignerErrors/null_signatures2765--- PASS: TestGenerateFingerprint (0.00s)2766 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2767 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2768 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2769 --- PASS: TestGenerateFingerprint/no_references (0.00s)2770 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2771 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2772 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2773=== RUN TestExternalSignerErrors/wrong_signatures_shape2774=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2775=== RUN TestExternalSignerErrors/too_few_signatures2776=== PAUSE TestExternalSignerErrors/too_few_signatures2777=== RUN TestExternalSignerErrors/unrequested_key2778=== PAUSE TestExternalSignerErrors/unrequested_key2779=== RUN TestExternalSignerErrors/wrong_signature_length2780=== PAUSE TestExternalSignerErrors/wrong_signature_length2781=== RUN TestExternalSignerErrors/program_error2782=== PAUSE TestExternalSignerErrors/program_error2783=== RUN TestExternalSignerErrors/null2784=== PAUSE TestExternalSignerErrors/null2785=== RUN TestExternalSignerErrors/missing_signatures2786=== PAUSE TestExternalSignerErrors/missing_signatures2787=== RUN TestExternalSignerErrors/wrong_signature_name2788=== PAUSE TestExternalSignerErrors/wrong_signature_name2789=== CONT TestExternalSignerErrors/invalid_JSON2790=== CONT TestExternalSignerErrors/invalid_signature_base642791=== CONT TestExternalSignerErrors/unrequested_key2792=== CONT TestExternalSignerErrors/wrong_signature_name2793=== CONT TestExternalSignerErrors/missing_signatures2794=== CONT TestExternalSignerErrors/null2795=== CONT TestExternalSignerErrors/program_error2796=== CONT TestExternalSignerErrors/missing_signature_name2797=== CONT TestExternalSignerErrors/wrong_signature_length2798=== CONT TestExternalSignerErrors/too_few_signatures2799=== CONT TestExternalSignerErrors/null_signatures2800=== CONT TestExternalSignerErrors/exit_at_startup2801=== CONT TestExternalSignerErrors/wrong_signatures_shape2802=== CONT TestExternalSignerErrors/exit_on_request2803=== CONT TestExternalSignerErrors/wrong_shape2804=== CONT TestExternalSignerErrors/wrong_id2805--- PASS: TestExternalSignerWrongPublicKey (0.01s)2806--- PASS: TestExternalSigner (0.01s)2807--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2808--- PASS: TestExternalSignerErrors (0.00s)2809 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.00s)2810 --- PASS: TestExternalSignerErrors/unrequested_key (0.00s)2811 --- PASS: TestExternalSignerErrors/null (0.01s)2812 --- PASS: TestExternalSignerErrors/program_error (0.01s)2813 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2814 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2815 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2816 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2817 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2818 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2819 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2820 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2821 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2822 --- PASS: TestExternalSignerErrors/wrong_id (0.00s)2823 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2824 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2825--- PASS: TestExternalSignerCancellation (0.02s)2826PASS2827Running OpenBao signer tests...2828=== RUN TestSign2829=== PAUSE TestSign2830=== RUN TestSignErrors2831=== PAUSE TestSignErrors2832=== RUN TestServe2833=== PAUSE TestServe2834=== RUN TestServeRejectsGarbage2835=== PAUSE TestServeRejectsGarbage2836=== CONT TestSign2837=== CONT TestServe2838=== CONT TestServeRejectsGarbage2839=== CONT TestSignErrors2840--- PASS: TestServeRejectsGarbage (0.00s)2841=== RUN TestSignErrors/invalid_base642842=== PAUSE TestSignErrors/invalid_base642843=== RUN TestSignErrors/http_error2844=== PAUSE TestSignErrors/http_error2845=== RUN TestSignErrors/invalid_json2846=== PAUSE TestSignErrors/invalid_json2847=== RUN TestSignErrors/no_prefix2848=== PAUSE TestSignErrors/no_prefix2849=== CONT TestSignErrors/invalid_base642850=== CONT TestSignErrors/no_prefix2851=== CONT TestSignErrors/invalid_json2852--- PASS: TestServe (0.00s)2853=== CONT TestSignErrors/http_error2854--- PASS: TestSign (0.00s)2855--- PASS: TestSignErrors (0.00s)2856 --- PASS: TestSignErrors/invalid_json (0.00s)2857 --- PASS: TestSignErrors/no_prefix (0.00s)2858 --- PASS: TestSignErrors/http_error (0.00s)2859 --- PASS: TestSignErrors/invalid_base64 (0.00s)2860PASS