niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #379
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica8=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica9=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun10=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun11=== RUN TestCaseHackSuffix12=== PAUSE TestCaseHackSuffix13=== RUN TestFilterOversizedClosures14=== PAUSE TestFilterOversizedClosures15=== RUN TestUploadMultipart_PartsInParallel16=== PAUSE TestUploadMultipart_PartsInParallel17=== RUN TestPartSizeForNAR18=== PAUSE TestPartSizeForNAR19=== RUN TestUploadMultipart_SupersededByPeer20=== PAUSE TestUploadMultipart_SupersededByPeer21=== RUN TestDumpPathCaseHackMatchesNix22--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestDumpPathMatchesNix26=== PAUSE TestDumpPathMatchesNix27=== RUN TestDumpPathSingleFile28=== PAUSE TestDumpPathSingleFile29=== RUN TestDumpPathWriterError30=== PAUSE TestDumpPathWriterError31=== RUN TestEncodeNixBase3232=== PAUSE TestEncodeNixBase3233=== RUN TestEncodeNixBase32WithRealHash34=== PAUSE TestEncodeNixBase32WithRealHash35=== RUN TestConvertHashToNix3236=== PAUSE TestConvertHashToNix3237=== RUN TestGetStorePathHash38=== PAUSE TestGetStorePathHash39=== RUN TestPathInfoHashCompatibility40=== PAUSE TestPathInfoHashCompatibility41=== RUN TestParsePathInfoJSON42=== PAUSE TestParsePathInfoJSON43=== RUN TestParsePathInfoJSONMultiplePaths44=== PAUSE TestParsePathInfoJSONMultiplePaths45=== RUN TestPathInfoCACompatibility46=== PAUSE TestPathInfoCACompatibility47=== RUN TestRateLimiterFeedback48=== PAUSE TestRateLimiterFeedback49=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess51=== RUN TestResolveStorePath52=== PAUSE TestResolveStorePath53=== RUN TestDoWithRetry_BodyReplayedViaGetBody54=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody55=== RUN TestShellSplit56=== PAUSE TestShellSplit57=== RUN TestShellSplitErrors58=== PAUSE TestShellSplitErrors59=== RUN TestStreamPushReportsEveryPath60=== PAUSE TestStreamPushReportsEveryPath61=== RUN TestStreamPushBatchesUnderLoad62=== PAUSE TestStreamPushBatchesUnderLoad63=== RUN TestStreamPushIsolatesFailures64=== PAUSE TestStreamPushIsolatesFailures65=== RUN TestStreamPushGivesUpOnDeadServer66=== PAUSE TestStreamPushGivesUpOnDeadServer67=== RUN TestStreamPushRequestLine68=== PAUSE TestStreamPushRequestLine69=== RUN TestStreamPushReportsSignatures70=== PAUSE TestStreamPushReportsSignatures71=== RUN TestClientSignaturesByStorePath72=== PAUSE TestClientSignaturesByStorePath73=== RUN TestSetClientTLS74=== PAUSE TestSetClientTLS75=== RUN TestSetClientTLSDoesNotMutateDefaultTransport76=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport77=== RUN TestSetClientTLSErrors78=== PAUSE TestSetClientTLSErrors79=== RUN TestStaticToken80=== PAUSE TestStaticToken81=== RUN TestFileTokenReadsAndCaches82=== PAUSE TestFileTokenReadsAndCaches83=== RUN TestFileTokenMissing84=== PAUSE TestFileTokenMissing85=== RUN TestFileTokenEmpty86=== PAUSE TestFileTokenEmpty87=== RUN TestScriptTokenNoExpiryRerunsEveryCall88=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall89=== RUN TestScriptTokenCachesUntilRefresh90=== PAUSE TestScriptTokenCachesUntilRefresh91=== RUN TestScriptTokenEmptyToken92=== PAUSE TestScriptTokenEmptyToken93=== RUN TestScriptTokenBadJSON94=== PAUSE TestScriptTokenBadJSON95=== RUN TestScriptTokenScriptFails96=== PAUSE TestScriptTokenScriptFails97=== RUN TestScriptTokenEmptyCommand98=== PAUSE TestScriptTokenEmptyCommand99=== CONT TestDoServerRequestAttachesToken100=== CONT TestDoWithRetry_BodyReplayedViaGetBody101=== CONT TestEncodeNixBase32102=== CONT TestResolveStorePath103=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess104=== CONT TestRateLimiterFeedback105=== RUN TestRateLimiterFeedback/429_enables_limiter106=== CONT TestPathInfoCACompatibility107=== RUN TestPathInfoCACompatibility/null_ca_field108=== PAUSE TestPathInfoCACompatibility/null_ca_field109=== RUN TestPathInfoCACompatibility/old_string_format_-_text110=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text111=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive112=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive113=== RUN TestPathInfoCACompatibility/new_structured_format_-_text114=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text115=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method116=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method117=== CONT TestParsePathInfoJSONMultiplePaths118=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths119=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths120=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths121=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths122=== CONT TestScriptTokenEmptyCommand123--- PASS: TestScriptTokenEmptyCommand (0.00s)124=== CONT TestScriptTokenBadJSON1252026/10/06 19:57:01 WARN Rate limiter enabled after throttle name=server-test rate=5126--- PASS: TestResolveStorePath (0.00s)127=== CONT TestScriptTokenEmptyToken128=== CONT TestScriptTokenScriptFails129=== CONT TestParsePathInfoJSON130=== CONT TestPathInfoHashCompatibility131=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)132=== CONT TestGetStorePathHash133=== RUN TestGetStorePathHash/valid_store_path134=== RUN TestParsePathInfoJSON/Nix_format135=== PAUSE TestParsePathInfoJSON/Nix_format136=== CONT TestConvertHashToNix32137=== RUN TestConvertHashToNix32/SRI_format_to_Nix32138=== CONT TestEncodeNixBase32WithRealHash139=== PAUSE TestGetStorePathHash/valid_store_path140=== CONT TestUploadMultipart_PartsInParallel141=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32142=== RUN TestConvertHashToNix32/already_Nix32_format143=== CONT TestDumpPathMatchesNix144=== CONT TestUploadMultipart_SupersededByPeer145=== CONT TestPartSizeForNAR146=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun147=== CONT TestFilterOversizedClosures148=== CONT TestCaseHackSuffix149=== CONT TestScriptTokenCachesUntilRefresh150=== CONT TestSetClientTLSErrors151=== RUN TestEncodeNixBase32/test_string_hash152=== PAUSE TestRateLimiterFeedback/429_enables_limiter153=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)154=== RUN TestParsePathInfoJSON/Lix_format155--- PASS: TestEncodeNixBase32WithRealHash (0.00s)156--- PASS: TestScriptTokenScriptFails (0.00s)157=== PAUSE TestEncodeNixBase32/test_string_hash158=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon159=== CONT TestStreamPushGivesUpOnDeadServer160=== CONT TestDumpPathWriterError161=== RUN TestGetStorePathHash/basename_without_hyphen_should_error162=== CONT TestDumpPathSingleFile163=== PAUSE TestConvertHashToNix32/already_Nix32_format164=== RUN TestUploadMultipart_SupersededByPeer/exists165=== RUN TestPartSizeForNAR/zero_stays_at_minimum166=== CONT TestSetClientTLSDoesNotMutateDefaultTransport167=== RUN TestFilterOversizedClosures/no_limit_keeps_everything168=== PAUSE TestParsePathInfoJSON/Lix_format169=== RUN TestParsePathInfoJSON/empty_input170=== RUN TestRateLimiterFeedback/503_enables_limiter171=== RUN TestEncodeNixBase32/empty_input172=== RUN TestSetClientTLSErrors/missing_cert_file173=== PAUSE TestSetClientTLSErrors/missing_cert_file174=== RUN TestSetClientTLSErrors/missing_key_file175=== PAUSE TestParsePathInfoJSON/empty_input176=== PAUSE TestRateLimiterFeedback/503_enables_limiter177=== PAUSE TestUploadMultipart_SupersededByPeer/exists178=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon179=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI180=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI181=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512182=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha5121832026/10/06 19:57:01 WARN Rate limiter enabled after throttle name=server-test rate=5184=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error1852026/10/06 19:57:01 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:33497186=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error187=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error188=== PAUSE TestEncodeNixBase32/empty_input189=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything190=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped191=== CONT TestClientSignaturesByStorePath192--- PASS: TestClientSignaturesByStorePath (0.00s)193=== CONT TestStreamPushReportsSignatures194=== RUN TestParsePathInfoJSON/whitespace_only195=== PAUSE TestParsePathInfoJSON/whitespace_only196--- PASS: TestScriptTokenEmptyToken (0.05s)197=== RUN TestParsePathInfoJSON/invalid_JSON198=== PAUSE TestParsePathInfoJSON/invalid_JSON199=== CONT TestStreamPushRequestLine200=== CONT TestScriptTokenNoExpiryRerunsEveryCall201=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter2022026/10/06 19:57:01 ERROR Upload failed error="connection refused" count=20203--- PASS: TestScriptTokenBadJSON (0.05s)2042026/10/06 19:57:01 ERROR Server seems unavailable, giving up on batch untried=17205=== PAUSE TestSetClientTLSErrors/missing_key_file206=== CONT TestSetClientTLS2072026/10/06 19:57:01 WARN Rate limiter backed off name=server-test rate=5208--- PASS: TestDoServerRequestAttachesToken (0.05s)2092026/10/06 19:57:01 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:33497210=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error211=== RUN TestConvertHashToNix32/invalid_format212=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped213=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum214=== RUN TestUploadMultipart_SupersededByPeer/missing215=== CONT TestFileTokenMissing216=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter217=== RUN TestFilterOversizedClosures/all_closures_skipped218=== RUN TestSetClientTLSErrors/missing_ca_file219=== PAUSE TestSetClientTLSErrors/missing_ca_file220=== RUN TestSetClientTLSErrors/invalid_ca_file221=== PAUSE TestSetClientTLSErrors/invalid_ca_file222--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.05s)223=== CONT TestStreamPushReportsEveryPath224=== CONT TestRegisterUploadedObjectReusesConnections2252026/10/06 19:57:01 ERROR Upload failed error=boom count=1226=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter227--- PASS: TestStreamPushReportsSignatures (0.00s)228=== CONT TestStreamPushIsolatesFailures2292026/10/06 19:57:01 ERROR Upload failed error=boom count=1230=== CONT TestFileTokenEmpty2312026/10/06 19:57:01 ERROR Upload failed error="bad path" count=3232=== CONT TestStaticToken233=== CONT TestShellSplitErrors234=== CONT TestShellSplit235=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica2362026/10/06 19:57:01 INFO Garbage collection started237=== CONT TestPathInfoCACompatibility/null_ca_field238=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths239=== CONT TestPathInfoCACompatibility/old_string_format_-_text240=== CONT TestPathInfoCACompatibility/new_structured_format_-_text241=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive242=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths243=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)244=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512245=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method246=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon247=== CONT TestEncodeNixBase32/test_string_hash248=== CONT TestParsePathInfoJSON/Nix_format249=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error250=== CONT TestEncodeNixBase32/empty_input251=== CONT TestParsePathInfoJSON/whitespace_only252=== CONT TestParsePathInfoJSON/Lix_format2532026/10/06 19:57:01 INFO Garbage collection started254=== CONT TestSetClientTLSErrors/missing_cert_file255=== CONT TestSetClientTLSErrors/invalid_ca_file256=== CONT TestSetClientTLSErrors/missing_ca_file257=== CONT TestSetClientTLSErrors/missing_key_file258=== CONT TestGetStorePathHash/valid_store_path259=== CONT TestParsePathInfoJSON/empty_input260=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error261=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error262=== CONT TestGetStorePathHash/basename_without_hyphen_should_error263=== PAUSE TestConvertHashToNix32/invalid_format264=== CONT TestConvertHashToNix32/SRI_format_to_Nix32265=== PAUSE TestUploadMultipart_SupersededByPeer/missing266=== CONT TestUploadMultipart_SupersededByPeer/exists267=== CONT TestConvertHashToNix32/invalid_format268=== CONT TestConvertHashToNix32/already_Nix32_format269--- PASS: TestStreamPushReportsEveryPath (0.00s)270--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)271--- PASS: TestStreamPushIsolatesFailures (0.00s)272--- PASS: TestStaticToken (0.00s)273--- PASS: TestShellSplitErrors (0.00s)274--- PASS: TestShellSplit (0.00s)275--- PASS: TestFileTokenMissing (0.00s)276=== CONT TestUploadMultipart_SupersededByPeer/missing2772026/10/06 19:57:01 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=0278=== PAUSE TestFilterOversizedClosures/all_closures_skipped279=== CONT TestFilterOversizedClosures/no_limit_keeps_everything280=== RUN TestSetClientTLS/rejects_connection_without_client_cert281=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert282=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA283=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA284=== RUN TestSetClientTLS/preserves_debug_logging_transport285=== PAUSE TestSetClientTLS/preserves_debug_logging_transport286=== CONT TestSetClientTLS/rejects_connection_without_client_cert287--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)288=== CONT TestStreamPushBatchesUnderLoad289=== CONT TestFilterOversizedClosures/all_closures_skipped2902026/10/06 19:57:01 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=50291=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2922026/10/06 19:57:01 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=2000293--- PASS: TestFilterOversizedClosures (0.05s)294 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)295 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)296 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)297=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter298=== CONT TestRateLimiterFeedback/429_enables_limiter299=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI300=== CONT TestSetClientTLS/preserves_debug_logging_transport301=== RUN TestPartSizeForNAR/small_stays_at_minimum302=== CONT TestParsePathInfoJSON/invalid_JSON303=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter304=== CONT TestFileTokenReadsAndCaches305--- PASS: TestUploadMultipart_SupersededByPeer (0.05s)306 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)307 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)308=== PAUSE TestPartSizeForNAR/small_stays_at_minimum309=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA3102026/10/06 19:57:01 WARN Rate limiter enabled after throttle name=server-test rate=53112026/10/06 19:57:01 WARN Garbage collection finished on another replica. Its statistics are not available here312--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)3132026/10/06 19:57:01 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:35083314=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter315--- PASS: TestFileTokenReadsAndCaches (0.00s)316=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum317=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum318=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts319=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts320=== RUN TestPartSizeForNAR/1_TiB321=== PAUSE TestPartSizeForNAR/1_TiB3222026/10/06 19:57:01 WARN Rate limiter backed off name=server-test rate=5323=== RUN TestPartSizeForNAR/5_TiB_S3_max_object324=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object325=== RUN TestPartSizeForNAR/capped_at_5_GiB326=== PAUSE TestPartSizeForNAR/capped_at_5_GiB327=== CONT TestPartSizeForNAR/zero_stays_at_minimum328=== CONT TestRateLimiterFeedback/503_enables_limiter329=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts330=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum331=== CONT TestPartSizeForNAR/small_stays_at_minimum332=== CONT TestPartSizeForNAR/5_TiB_S3_max_object3332026/10/06 19:57:01 WARN Rate limiter enabled after throttle name=server-test rate=5334=== CONT TestPartSizeForNAR/capped_at_5_GiB3352026/10/06 19:57:01 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:44215336--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)337 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)338 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)339--- PASS: TestFileTokenEmpty (0.00s)340--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.05s)341=== CONT TestPartSizeForNAR/1_TiB342--- PASS: TestScriptTokenCachesUntilRefresh (0.06s)343--- PASS: TestPathInfoHashCompatibility (0.05s)344 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)345 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)346 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)347 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)3482026/10/06 19:57:01 WARN Rate limiter backed off name=server-test rate=5349--- PASS: TestPathInfoCACompatibility (0.00s)350 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)351 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)352 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)353 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)354 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)355--- PASS: TestEncodeNixBase32 (0.05s)356 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)357 --- PASS: TestEncodeNixBase32/empty_input (0.00s)358--- PASS: TestParsePathInfoJSON (0.05s)359 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)360 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)361 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)362 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)363 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)364--- PASS: TestGetStorePathHash (0.05s)365 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)366 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)367 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)368 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)369--- PASS: TestConvertHashToNix32 (0.05s)370 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)371 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)372 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)373--- PASS: TestPartSizeForNAR (0.05s)374 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)375 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)376 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)377 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)378 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)379 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)380 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)381--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)382--- PASS: TestRateLimiterFeedback (0.06s)383 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)384 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)385 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)386 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)387--- PASS: TestSetClientTLSErrors (0.05s)388 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)389 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)390 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)391 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)392--- PASS: TestStreamPushRequestLine (0.03s)3932026/10/06 19:57:01 http: TLS handshake error from 127.0.0.1:46066: remote error: tls: bad certificate394--- PASS: TestCaseHackSuffix (0.08s)395--- PASS: TestSetClientTLS (0.01s)396 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)397 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)398 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.03s)399--- PASS: TestDumpPathSingleFile (0.08s)400--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)401--- PASS: TestDumpPathWriterError (0.05s)402--- PASS: TestDumpPathMatchesNix (0.14s)403--- PASS: TestStreamPushBatchesUnderLoad (0.10s)404--- PASS: TestUploadMultipart_PartsInParallel (0.67s)405--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)406PASS407Running server tests...408The files belonging to this database system will be owned by user "nixbld".409This user must also own the server process.410411The database cluster will be initialized with locale "C".412The default database encoding has accordingly been set to "SQL_ASCII".413The default text search configuration will be set to "english".414415Data page checksums are enabled.416417creating directory /build/postgres1521285285/data ... ok418creating subdirectories ... ok419selecting dynamic shared memory implementation ... posix420selecting default "max_connections" ... 100421selecting default "shared_buffers" ... 128MB422selecting default time zone ... UTC423creating configuration files ... ok424running bootstrap script ... ok425performing post-bootstrap initialization ... ok426syncing data to disk ... ok427428initdb: warning: enabling "trust" authentication for local connections429initdb: 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.430431Success. You can now start the database server using:432433 pg_ctl -D /build/postgres1521285285/data -l logfile start434435/build/postgres1521285285:5432 - no response4362026-10-06 19:57:03.584 UTC [130] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-06 19:57:03.584 UTC [130] LOG: listening on Unix socket "/build/postgres1521285285/.s.PGSQL.5432"4382026-10-06 19:57:03.589 UTC [137] LOG: database system was shut down at 2026-10-06 19:57:03 UTC4392026-10-06 19:57:03.592 UTC [130] LOG: database system is ready to accept connections440/build/postgres1521285285:5432 - accepting connections441{"timestamp":"2026-10-06T19:57:03.894638109Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"df579f6c-9df0-4e77-bb37-c70424743609","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":501,"threadName":"rustfs-worker","threadId":"ThreadId(398)"}442=== RUN TestService_AuthMiddleware443=== PAUSE TestService_AuthMiddleware444=== RUN TestService_AuthMiddleware_MTLSProxyHeader445=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader446=== RUN TestService_AuthMiddleware_MTLSBoundSubjects447=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects448=== RUN TestService_ReadAuthMiddleware449=== PAUSE TestService_ReadAuthMiddleware450=== RUN TestService_AuthMiddleware_OIDC451=== PAUSE TestService_AuthMiddleware_OIDC452=== RUN TestService_RequireScope_OIDC453=== PAUSE TestService_RequireScope_OIDC454=== RUN TestService_ReadScope_PublicByDefault455=== PAUSE TestService_ReadScope_PublicByDefault456=== RUN TestCacheConfigHandler457=== PAUSE TestCacheConfigHandler458=== RUN TestCacheStatsHandler459=== PAUSE TestCacheStatsHandler460=== RUN TestClientCADerivations461=== PAUSE TestClientCADerivations462=== RUN TestClientErrorHandling463=== PAUSE TestClientErrorHandling464=== RUN TestClientIntegration465=== PAUSE TestClientIntegration466=== RUN TestClientMultipleUploads467=== PAUSE TestClientMultipleUploads468=== RUN TestClientWithDependencies469=== PAUSE TestClientWithDependencies470=== RUN TestClientSharedPathCommittedMidPush471=== PAUSE TestClientSharedPathCommittedMidPush472=== RUN TestPinProtectsFromGC473=== PAUSE TestPinProtectsFromGC474=== RUN TestClientPushesUseOnePush475=== PAUSE TestClientPushesUseOnePush476=== RUN TestClientFallsBackToClosures477=== PAUSE TestClientFallsBackToClosures478=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock479=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock480=== RUN TestResolveDBConnectionString481=== PAUSE TestResolveDBConnectionString482=== RUN TestConnectWaitsForAPeerMigration483=== PAUSE TestConnectWaitsForAPeerMigration484=== RUN TestLeadElectsOneAndHandsOver485=== PAUSE TestLeadElectsOneAndHandsOver486=== RUN TestLeadIncumbentWinsAfterRestart4872026/10/06 19:57:04 INFO lead: acquired remote=192.0.2.1:12344882026/10/06 19:57:04 INFO lead: released remote=192.0.2.1:12344892026/10/06 19:57:04 INFO lead: acquired remote=192.0.2.1:12344902026/10/06 19:57:05 INFO lead: released remote=192.0.2.1:1234491--- PASS: TestLeadIncumbentWinsAfterRestart (1.88s)492=== RUN TestLeadIncumbentAnnouncesAtOnce493=== PAUSE TestLeadIncumbentAnnouncesAtOnce494=== RUN TestLeadEndsOnShutdown495=== PAUSE TestLeadEndsOnShutdown496=== RUN TestLeadEndsWhenItsConnectionHangs4972026/10/06 19:57:05 INFO lead: acquired remote=192.0.2.1:12344982026-10-06 19:57:07.390 UTC [574] FATAL: terminating connection due to administrator command4992026/10/06 19:57:07 INFO lead: acquired remote=192.0.2.1:12345002026/10/06 19:57:08 WARN lead: lock connection lost error="timeout: context deadline exceeded"5012026/10/06 19:57:08 INFO lead: released remote=192.0.2.1:12345022026/10/06 19:57:08 INFO lead: released remote=192.0.2.1:1234503--- PASS: TestLeadEndsWhenItsConnectionHangs (2.91s)504=== RUN TestGCAdvisoryLockBlocksConcurrentRun505=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun506=== RUN TestGCBugBareHashReferences507=== PAUSE TestGCBugBareHashReferences508=== RUN TestGCMetrics509=== PAUSE TestGCMetrics510=== RUN TestPushDedupSurvivesConcurrentGC511=== PAUSE TestPushDedupSurvivesConcurrentGC512=== RUN TestDeduplicatedObjectsRecordedAsPending513=== PAUSE TestDeduplicatedObjectsRecordedAsPending514=== RUN TestGCSweepSkipsPendingObjects515=== PAUSE TestGCSweepSkipsPendingObjects516=== RUN TestTombstonedObjectOfferedWithoutWaiting517=== PAUSE TestTombstonedObjectOfferedWithoutWaiting518=== RUN TestGCSweepDeliversEachKeyOnce519=== PAUSE TestGCSweepDeliversEachKeyOnce520=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection521=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection522=== RUN TestForceGCDuringPushOffersSweptObject523=== PAUSE TestForceGCDuringPushOffersSweptObject524=== RUN TestFailedS3DeleteKeepsTombstone525=== PAUSE TestFailedS3DeleteKeepsTombstone526=== RUN TestSweepSkipsRowsLockedByPush527=== PAUSE TestSweepSkipsRowsLockedByPush528=== RUN TestRegisterCompletedObjectNeedsPendingRow529=== PAUSE TestRegisterCompletedObjectNeedsPendingRow530=== RUN TestGetExistingObjectsLocksRows531=== PAUSE TestGetExistingObjectsLocksRows532=== RUN TestSweepRechecksPendingAfterLocking533=== PAUSE TestSweepRechecksPendingAfterLocking534=== RUN TestPushWaitsForSweepHoldingRow535=== PAUSE TestPushWaitsForSweepHoldingRow536=== RUN TestCommitRacingPendingCleanupKeepsObjects537=== PAUSE TestCommitRacingPendingCleanupKeepsObjects538=== RUN TestGCEndsOnShutdown539=== PAUSE TestGCEndsOnShutdown540=== RUN TestGCTaskStore_StartNew541=== PAUSE TestGCTaskStore_StartNew542=== RUN TestGCTaskStore_DeduplicateSameParams543=== PAUSE TestGCTaskStore_DeduplicateSameParams544=== RUN TestGCTaskStore_ConflictDifferentParams545=== PAUSE TestGCTaskStore_ConflictDifferentParams546=== RUN TestGCTaskStore_GetEmpty547=== PAUSE TestGCTaskStore_GetEmpty548=== RUN TestGCTaskStore_GetReturnsLatest549=== PAUSE TestGCTaskStore_GetReturnsLatest550=== RUN TestGCTaskStore_CompletedAllowsNewTask551=== PAUSE TestGCTaskStore_CompletedAllowsNewTask552=== RUN TestGCTaskStore_PhaseUpdates553=== PAUSE TestGCTaskStore_PhaseUpdates554=== RUN TestGCTaskStore_Fail555=== PAUSE TestGCTaskStore_Fail556=== RUN TestGracefulShutdownDrainsInflight557=== PAUSE TestGracefulShutdownDrainsInflight558=== RUN TestService_healthCheckHandler559=== PAUSE TestService_healthCheckHandler560=== RUN TestService_readinessHandler561=== PAUSE TestService_readinessHandler562=== RUN TestGenerateLandingPage563=== PAUSE TestGenerateLandingPage564=== RUN TestCacheConfigHandlerMaxNarSize565=== PAUSE TestCacheConfigHandlerMaxNarSize566=== RUN TestCreatePendingClosureRejectsOversizedNAR567=== PAUSE TestCreatePendingClosureRejectsOversizedNAR568=== RUN TestNARDeduplicationMetadataUploadBug569=== PAUSE TestNARDeduplicationMetadataUploadBug570=== RUN TestMetricsInventory571=== PAUSE TestMetricsInventory572=== RUN TestService_NativeMTLS573=== PAUSE TestService_NativeMTLS574=== RUN TestServerTLSConfig575=== PAUSE TestServerTLSConfig576=== RUN TestMultipartCleanup577=== PAUSE TestMultipartCleanup578=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded579=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded580=== RUN TestPendingCleanupUsesOneCutoff581=== PAUSE TestPendingCleanupUsesOneCutoff582=== RUN TestObjectStatsTrigger583=== PAUSE TestObjectStatsTrigger584=== RUN TestOrphanedObjectsGC585=== PAUSE TestOrphanedObjectsGC586=== RUN TestOrphanedObjectsGCStressTest587=== PAUSE TestOrphanedObjectsGCStressTest588=== RUN TestCreatePin_ReservedPins589=== PAUSE TestCreatePin_ReservedPins590=== RUN TestPresentReportsOnlyClosureRoots591=== PAUSE TestPresentReportsOnlyClosureRoots592=== RUN TestPresentNotReportedWhileGCDeletesClosure593=== PAUSE TestPresentNotReportedWhileGCDeletesClosure594=== RUN TestConcurrentPresentSharingKeysDoNotDeadlock595=== PAUSE TestConcurrentPresentSharingKeysDoNotDeadlock596=== RUN TestParseSingleRange597=== PAUSE TestParseSingleRange598=== RUN TestProxyHeadersOnlyTrustedOnSocket599=== PAUSE TestProxyHeadersOnlyTrustedOnSocket600=== RUN TestIsValidCachePath601=== PAUSE TestIsValidCachePath602=== RUN TestReadProxyNarinfo603=== PAUSE TestReadProxyNarinfo604=== RUN TestReadProxyNarinfoAlreadyDecompressed605=== PAUSE TestReadProxyNarinfoAlreadyDecompressed606=== RUN TestReadProxyContentNegotiation607=== PAUSE TestReadProxyContentNegotiation608=== RUN TestReadProxyNarStreaming609=== PAUSE TestReadProxyNarStreaming610=== RUN TestReadProxy404611=== PAUSE TestReadProxy404612=== RUN TestReadProxyInvalidPath613=== PAUSE TestReadProxyInvalidPath614=== RUN TestReadProxyHead615=== PAUSE TestReadProxyHead616=== RUN TestReadProxyOutlastsServerWriteTimeout617=== PAUSE TestReadProxyOutlastsServerWriteTimeout618=== RUN TestReadProxyConditionalGet619=== PAUSE TestReadProxyConditionalGet620=== RUN TestReadProxyRootRedirectsToIndexHTML621=== PAUSE TestReadProxyRootRedirectsToIndexHTML622=== RUN TestReadProxyDisabled623=== PAUSE TestReadProxyDisabled624=== RUN TestReadRedirectNar625=== PAUSE TestReadRedirectNar626=== RUN TestReadRedirectKeepsNarinfoProxied627=== PAUSE TestReadRedirectKeepsNarinfoProxied628=== RUN TestReadProxyRangeRequest629=== PAUSE TestReadProxyRangeRequest630=== RUN TestReadRedirectUsesPublicS3URL631=== PAUSE TestReadRedirectUsesPublicS3URL632=== RUN TestPush_OverlappingRootsStoreOneRowPerKey633=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey634=== RUN TestPush_CompleteCommitsEveryRoot635=== PAUSE TestPush_CompleteCommitsEveryRoot636=== RUN TestPush_RepeatedRootCommitsOnce637=== PAUSE TestPush_RepeatedRootCommitsOnce638=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit639=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit640=== RUN TestPush_RejectsBadRequests641=== PAUSE TestPush_RejectsBadRequests642=== RUN TestPush_SignsNarinfosOfItsPendingObjects643=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects644=== RUN TestRedundantMultipartUpload645=== PAUSE TestRedundantMultipartUpload646=== RUN TestCompleteMultipartUpload_ErrorButObjectExists647=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists648=== RUN TestCompletedNarNotReofferedAcrossClosures649=== PAUSE TestCompletedNarNotReofferedAcrossClosures650=== RUN TestPresignedUploadRegisteredBeforeCommit651=== PAUSE TestPresignedUploadRegisteredBeforeCommit652=== RUN TestService_Rustfstest653=== PAUSE TestService_Rustfstest654=== RUN TestParseSize655=== PAUSE TestParseSize656=== RUN TestSkippedUploadsHandler657=== PAUSE TestSkippedUploadsHandler658=== RUN TestSystemdListenerNotActivated659--- PASS: TestSystemdListenerNotActivated (0.00s)660=== RUN TestWatchdogBeatsWhenHealthy661--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)662=== RUN TestWatchdogSkipsWhenUnhealthy6632026/10/06 19:57:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/06 19:57:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/06 19:57:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/06 19:57:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/06 19:57:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6682026/10/06 19:57:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6692026/10/06 19:57:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6702026/10/06 19:57:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6712026/10/06 19:57:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6722026/10/06 19:57:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"673--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)674=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle675=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle676=== RUN TestProxyWriteTimeout677=== PAUSE TestProxyWriteTimeout678=== RUN TestPendingClosureWriteTimeout679=== PAUSE TestPendingClosureWriteTimeout680=== RUN TestIsValidUploadKey681=== PAUSE TestIsValidUploadKey682=== RUN TestUploadHandlersRejectInvalidKeys683=== PAUSE TestUploadHandlersRejectInvalidKeys684=== RUN TestUploadHandlersRejectOversizedBody685=== PAUSE TestUploadHandlersRejectOversizedBody686=== RUN TestService_cleanupPendingClosuresHandler687=== PAUSE TestService_cleanupPendingClosuresHandler688=== RUN TestService_createPendingClosureHandler689=== PAUSE TestService_createPendingClosureHandler690=== RUN TestService_verifyS3Integrity691=== PAUSE TestService_verifyS3Integrity692=== RUN TestCompleteMultipartUnregistered693=== PAUSE TestCompleteMultipartUnregistered694=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT695=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT696=== CONT TestService_AuthMiddleware697=== CONT TestNARDeduplicationMetadataUploadBug698=== CONT TestService_verifyS3Integrity699=== CONT TestParseSingleRange700=== CONT TestPresignedUploadRegisteredBeforeCommit701=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT702=== CONT TestCompleteMultipartUnregistered703=== CONT TestService_createPendingClosureHandler704=== CONT TestService_cleanupPendingClosuresHandler705=== CONT TestUploadHandlersRejectOversizedBody706=== CONT TestUploadHandlersRejectInvalidKeys707=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info708=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info709=== CONT TestIsValidUploadKey710=== CONT TestPendingClosureWriteTimeout711=== CONT TestProxyWriteTimeout712=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle713=== CONT TestSkippedUploadsHandler714=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal7152026/10/06 19:57:09 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000716=== CONT TestService_Rustfstest717=== CONT TestDeduplicatedObjectsRecordedAsPending718=== CONT TestCreatePendingClosureRejectsOversizedNAR7192026/10/06 19:57:09 INFO Received uploads request method=POST path=/api/pending_closures720=== CONT TestCacheConfigHandlerMaxNarSize721=== CONT TestGenerateLandingPage722=== CONT TestService_readinessHandler723=== CONT TestReadRedirectNar724=== RUN TestParseSingleRange/none725=== PAUSE TestParseSingleRange/none726=== RUN TestParseSingleRange/unknown_unit727=== RUN TestPendingClosureWriteTimeout/empty728=== CONT TestParseSize729=== RUN TestIsValidUploadKey/narinfo730=== RUN TestProxyWriteTimeout/narinfo731=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal732--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)733=== CONT TestService_healthCheckHandler734=== CONT TestGracefulShutdownDrainsInflight735=== PAUSE TestParseSingleRange/unknown_unit736=== RUN TestParseSingleRange/multi-range_ignored737=== PAUSE TestParseSingleRange/multi-range_ignored738=== RUN TestParseSingleRange/malformed_no_dash739=== PAUSE TestParseSingleRange/malformed_no_dash740=== RUN TestParseSingleRange/malformed_both_empty741=== CONT TestGCTaskStore_Fail742=== CONT TestGCTaskStore_PhaseUpdates743=== PAUSE TestIsValidUploadKey/narinfo744=== PAUSE TestProxyWriteTimeout/narinfo745=== RUN TestProxyWriteTimeout/1_GiB_nar7462026/10/06 19:57:09 INFO Starting HTTP server address=127.0.0.1:33943747=== PAUSE TestProxyWriteTimeout/1_GiB_nar748=== RUN TestProxyWriteTimeout/10_GiB_nar749=== PAUSE TestProxyWriteTimeout/10_GiB_nar750=== RUN TestProxyWriteTimeout/unknown_size751=== PAUSE TestPendingClosureWriteTimeout/empty752=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key753--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)754=== PAUSE TestParseSingleRange/malformed_both_empty755=== CONT TestGCTaskStore_CompletedAllowsNewTask756=== CONT TestGCTaskStore_GetReturnsLatest7572026/10/06 19:57:09 INFO Shutdown signal received, draining in-flight requests timeout=10s758=== CONT TestGCTaskStore_GetEmpty759=== CONT TestGCTaskStore_ConflictDifferentParams760=== RUN TestIsValidUploadKey/nar_zst761=== PAUSE TestProxyWriteTimeout/unknown_size762=== PAUSE TestIsValidUploadKey/nar_zst763=== RUN TestIsValidUploadKey/nar_xz764=== PAUSE TestIsValidUploadKey/nar_xz765=== RUN TestIsValidUploadKey/nar_plain766=== PAUSE TestIsValidUploadKey/nar_plain767=== RUN TestIsValidUploadKey/listing768=== RUN TestPendingClosureWriteTimeout/400_objects769=== PAUSE TestPendingClosureWriteTimeout/400_objects770=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key771--- PASS: TestParseSize (0.00s)772=== RUN TestParseSingleRange/malformed_end_before_start773=== CONT TestGCTaskStore_DeduplicateSameParams774=== CONT TestPushWaitsForSweepHoldingRow775=== CONT TestGCTaskStore_StartNew776=== CONT TestSweepRechecksPendingAfterLocking777=== CONT TestGCEndsOnShutdown778=== RUN TestGCEndsOnShutdown/before_the_run779=== PAUSE TestGCEndsOnShutdown/before_the_run780=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete781=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete782=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark783=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark784=== PAUSE TestIsValidUploadKey/listing785=== CONT TestGetExistingObjectsLocksRows786=== CONT TestCommitRacingPendingCleanupKeepsObjects787=== RUN TestPendingClosureWriteTimeout/670k_objects788=== PAUSE TestPendingClosureWriteTimeout/670k_objects789=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key790--- PASS: TestGCTaskStore_Fail (0.00s)791=== PAUSE TestParseSingleRange/malformed_end_before_start792=== RUN TestIsValidUploadKey/build_log793=== PAUSE TestIsValidUploadKey/build_log794=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline795=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline796=== CONT TestRegisterCompletedObjectNeedsPendingRow797=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key798--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)799--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)800--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)801--- PASS: TestGCTaskStore_GetEmpty (0.00s)802--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)803=== CONT TestSweepSkipsRowsLockedByPush804=== RUN TestIsValidUploadKey/build_log_home-manager_file805=== PAUSE TestIsValidUploadKey/build_log_home-manager_file806=== RUN TestIsValidUploadKey/build_log_plus_in_name807=== PAUSE TestIsValidUploadKey/build_log_plus_in_name808=== RUN TestIsValidUploadKey/build_log_question_mark809=== PAUSE TestIsValidUploadKey/build_log_question_mark810=== RUN TestIsValidUploadKey/build_log_equals811=== PAUSE TestIsValidUploadKey/build_log_equals812=== RUN TestIsValidUploadKey/realisation813=== PAUSE TestIsValidUploadKey/realisation814=== RUN TestIsValidUploadKey/realisation_plus_in_output815=== PAUSE TestIsValidUploadKey/realisation_plus_in_output816=== RUN TestIsValidUploadKey/nix-cache-info817=== PAUSE TestIsValidUploadKey/nix-cache-info818=== RUN TestIsValidUploadKey/index.html819=== PAUSE TestIsValidUploadKey/index.html820=== RUN TestIsValidUploadKey/narinfo_key,_nar_type821=== RUN TestParseSingleRange/closed822--- PASS: TestSkippedUploadsHandler (0.16s)823=== PAUSE TestParseSingleRange/closed824=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type825--- PASS: TestGenerateLandingPage (0.00s)826--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)827--- PASS: TestGCTaskStore_StartNew (0.00s)828=== RUN TestParseSingleRange/open-ended829=== PAUSE TestParseSingleRange/open-ended830=== RUN TestParseSingleRange/end_clamped_to_size831=== PAUSE TestParseSingleRange/end_clamped_to_size832=== RUN TestParseSingleRange/suffix833=== PAUSE TestParseSingleRange/suffix834=== RUN TestParseSingleRange/suffix_exceeds_size835=== PAUSE TestParseSingleRange/suffix_exceeds_size836=== RUN TestParseSingleRange/single_byte837=== PAUSE TestParseSingleRange/single_byte838=== RUN TestParseSingleRange/start_past_EOF839=== PAUSE TestParseSingleRange/start_past_EOF840=== RUN TestParseSingleRange/start_far_past_EOF841=== PAUSE TestParseSingleRange/start_far_past_EOF842=== RUN TestIsValidUploadKey/nar_key,_narinfo_type843=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type844=== CONT TestFailedS3DeleteKeepsTombstone845=== RUN TestIsValidUploadKey/listing_key,_narinfo_type846=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type847=== RUN TestIsValidUploadKey/traversal848=== PAUSE TestIsValidUploadKey/traversal849=== RUN TestIsValidUploadKey/traversal_nar850=== PAUSE TestIsValidUploadKey/traversal_nar851=== RUN TestIsValidUploadKey/absolute852=== PAUSE TestIsValidUploadKey/absolute853=== RUN TestIsValidUploadKey/empty_key854=== PAUSE TestIsValidUploadKey/empty_key855=== RUN TestIsValidUploadKey/unknown_type856=== PAUSE TestIsValidUploadKey/unknown_type857=== CONT TestForceGCDuringPushOffersSweptObject858=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows859=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows860=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check861=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check862=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection863--- PASS: TestGracefulShutdownDrainsInflight (0.07s)864=== CONT TestGCSweepDeliversEachKeyOnce865=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure866=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure867=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart868=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart869=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts870=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts871=== CONT TestTombstonedObjectOfferedWithoutWaiting8722026/10/06 19:57:09 INFO Received cleanup request method=DELETE path=/api/pending_closures8732026/10/06 19:57:09 INFO Aborted multipart uploads count=0 kept=08742026/10/06 19:57:09 INFO Received uploads request method=POST path=/api/pending_closures8752026/10/06 19:57:09 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"876--- PASS: TestService_AuthMiddleware (0.40s)877=== CONT TestGCSweepSkipsPendingObjects8782026/10/06 19:57:09 INFO Received cleanup request method=DELETE path=/api/pending_closures8792026/10/06 19:57:09 INFO Aborted multipart uploads count=1 kept=08802026/10/06 19:57:09 INFO Received uploads request method=POST path=/api/pending_closures8812026/10/06 19:57:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8822026-10-06 19:57:09.447 UTC [646] ERROR: Closure does not exist: id=18832026-10-06 19:57:09.447 UTC [646] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE8842026-10-06 19:57:09.447 UTC [646] STATEMENT: -- name: CommitPendingClosure :exec885 SELECT commit_pending_closure($1::bigint)886 887--- PASS: TestService_cleanupPendingClosuresHandler (0.42s)888=== CONT TestReadProxy404889--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.44s)890=== CONT TestReadProxyDisabled8912026/10/06 19:57:09 INFO Received uploads request method=POST path=/api/pending_closures892=== NAME TestNARDeduplicationMetadataUploadBug893 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3087719061/001/store/gxvv5p6agx57gf6zkghnxmb57fh0hhb5-file1.txt8942026/10/06 19:57:09 INFO Received uploads request method=POST path=/api/pending_closures8952026/10/06 19:57:09 INFO Received uploads request method=POST path=/api/pending_closures8962026/10/06 19:57:09 INFO Received uploads request method=POST path=/api/pending_closures8972026/10/06 19:57:09 INFO Received uploads request method=POST path=/api/pending_closures8982026/10/06 19:57:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8992026/10/06 19:57:09 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst900--- PASS: TestCompleteMultipartUnregistered (0.56s)901=== CONT TestReadProxyRootRedirectsToIndexHTML9022026/10/06 19:57:09 INFO Received push request method=POST path=/api/pushes9032026/10/06 19:57:09 INFO Received uploads request method=POST path=/api/pending_closures9042026/10/06 19:57:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9052026/10/06 19:57:09 INFO Uploading gxvv5p6agx57gf6zkghnxmb57fh0hhb5-file1.txt (160B)9062026/10/06 19:57:09 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"9072026/10/06 19:57:09 WARN Failed to register uploaded object key=gxvv5p6agx57gf6zkghnxmb57fh0hhb5.ls error="server returned 404: 404 page not found\n"9082026/10/06 19:57:09 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9092026/10/06 19:57:09 INFO Signed narinfos id=1 count=19102026/10/06 19:57:09 INFO Uploading 1 narinfos9112026/10/06 19:57:09 INFO Received complete push request method=POST path=/api/pushes/1/complete9122026/10/06 19:57:09 WARN Failed to register uploaded object key=gxvv5p6agx57gf6zkghnxmb57fh0hhb5.narinfo error="server returned 404: 404 page not found\n"9132026/10/06 19:57:09 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9142026/10/06 19:57:09 INFO Received uploads request method=POST path=/api/pending_closures915--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.61s)916=== CONT TestReadProxyConditionalGet9172026/10/06 19:57:09 INFO Completed push id=19182026/10/06 19:57:09 INFO Upload complete. (64ms)919=== NAME TestNARDeduplicationMetadataUploadBug920 metadata_upload_test.go:54: Retrieved narinfo from S3:921 StorePath: /build/TestNARDeduplicationMetadataUploadBug3087719061/001/store/gxvv5p6agx57gf6zkghnxmb57fh0hhb5-file1.txt922 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst923 Compression: zstd924 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf925 NarSize: 160926 References: 927 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf928 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)929 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):930 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}9312026/10/06 19:57:09 INFO Received uploads request method=POST path=/api/pending_closures932--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.61s)933=== CONT TestReadProxyOutlastsServerWriteTimeout9342026/10/06 19:57:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete935--- PASS: TestService_Rustfstest (0.61s)936=== CONT TestReadProxyHead937=== NAME TestNARDeduplicationMetadataUploadBug938 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3087719061/001/store/0r4hsn56gbgnl7n0r6fck4jkb2qndsxd-file2.txt9392026/10/06 19:57:09 INFO Aborted multipart uploads count=0 kept=09402026/10/06 19:57:09 INFO Received uploads request method=POST path=/api/pending_closures9412026/10/06 19:57:09 WARN Force mode enabled - objects will be deleted immediately without grace period9422026/10/06 19:57:09 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=09432026/10/06 19:57:09 INFO Vacuumed table table=pending_closures9442026/10/06 19:57:09 INFO Vacuumed table table=pending_objects9452026/10/06 19:57:09 INFO Vacuumed table table=multipart_uploads9462026/10/06 19:57:09 INFO Vacuumed table table=closures9472026/10/06 19:57:09 INFO Vacuumed table table=objects948--- PASS: TestSweepRechecksPendingAfterLocking (0.54s)949=== CONT TestReadProxyInvalidPath9502026/10/06 19:57:09 INFO Received push request method=POST path=/api/pushes9512026/10/06 19:57:09 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)9522026/10/06 19:57:09 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign9532026/10/06 19:57:09 WARN Failed to register uploaded object key=0r4hsn56gbgnl7n0r6fck4jkb2qndsxd.ls error="server returned 404: 404 page not found\n"9542026/10/06 19:57:09 INFO Signed narinfos id=2 count=19552026/10/06 19:57:09 INFO Uploading 1 narinfos9562026/10/06 19:57:09 INFO Received complete push request method=POST path=/api/pushes/2/complete9572026/10/06 19:57:09 WARN Failed to register uploaded object key=0r4hsn56gbgnl7n0r6fck4jkb2qndsxd.narinfo error="server returned 404: 404 page not found\n"9582026/10/06 19:57:09 INFO Completed push id=29592026/10/06 19:57:09 INFO Upload complete. (54ms)960=== NAME TestNARDeduplicationMetadataUploadBug961 metadata_upload_test.go:76: Retrieved narinfo from S3:962 StorePath: /build/TestNARDeduplicationMetadataUploadBug3087719061/001/store/0r4hsn56gbgnl7n0r6fck4jkb2qndsxd-file2.txt963 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst964 Compression: zstd965 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf966 NarSize: 160967 References: 968 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf9692026/10/06 19:57:09 INFO Aborted multipart uploads count=0 kept=0970 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)971 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):972 {"version":1,"root":{"type":"regular","size":44}}9732026/10/06 19:57:09 WARN Force mode enabled - objects will be deleted immediately without grace period9742026/10/06 19:57:09 INFO Received uploads request method=POST path=/api/pending_closures9752026/10/06 19:57:09 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=0976--- PASS: TestNARDeduplicationMetadataUploadBug (0.75s)977=== CONT TestReadProxyNarinfoAlreadyDecompressed9782026/10/06 19:57:09 INFO Aborted multipart uploads count=0 kept=09792026/10/06 19:57:09 INFO Vacuumed table table=pending_closures9802026/10/06 19:57:09 INFO Vacuumed table table=pending_objects9812026/10/06 19:57:09 INFO Vacuumed table table=multipart_uploads9822026/10/06 19:57:09 WARN Force mode enabled - objects will be deleted immediately without grace period9832026/10/06 19:57:09 INFO Vacuumed table table=closures9842026/10/06 19:57:09 INFO Vacuumed table table=objects985--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.60s)986=== CONT TestReadProxyNarStreaming9872026/10/06 19:57:09 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=09882026/10/06 19:57:09 INFO Vacuumed table table=pending_closures9892026/10/06 19:57:09 INFO Vacuumed table table=pending_objects9902026/10/06 19:57:09 INFO Vacuumed table table=multipart_uploads9912026/10/06 19:57:09 INFO Vacuumed table table=closures9922026/10/06 19:57:09 INFO Vacuumed table table=objects993--- PASS: TestGCSweepDeliversEachKeyOnce (0.55s)994=== CONT TestReadProxyContentNegotiation9952026/10/06 19:57:09 INFO Received uploads request method=POST path=/api/pending_closures9962026/10/06 19:57:09 INFO Aborted multipart uploads count=0 kept=09972026/10/06 19:57:09 WARN Force mode enabled - objects will be deleted immediately without grace period9982026/10/06 19:57:09 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=09992026/10/06 19:57:09 INFO Vacuumed table table=pending_closures10002026/10/06 19:57:09 INFO Vacuumed table table=pending_objects10012026/10/06 19:57:09 INFO Vacuumed table table=multipart_uploads10022026/10/06 19:57:09 INFO Vacuumed table table=closures1003--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.56s)1004=== CONT TestObjectStatsTrigger10052026/10/06 19:57:09 INFO Vacuumed table table=objects10062026/10/06 19:57:09 INFO Aborted multipart uploads count=0 kept=010072026/10/06 19:57:09 WARN Force mode enabled - objects will be deleted immediately without grace period10082026/10/06 19:57:09 WARN readiness check failed error="closed pool"1009--- PASS: TestService_readinessHandler (0.67s)1010=== CONT TestConcurrentPresentSharingKeysDoNotDeadlock10112026/10/06 19:57:09 INFO Aborted multipart uploads count=0 kept=010122026/10/06 19:57:09 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=010132026/10/06 19:57:09 INFO Vacuumed table table=pending_closures10142026/10/06 19:57:09 INFO Vacuumed table table=pending_objects10152026/10/06 19:57:09 INFO Vacuumed table table=multipart_uploads10162026/10/06 19:57:09 INFO Vacuumed table table=closures10172026/10/06 19:57:09 WARN Force mode enabled - objects will be deleted immediately without grace period10182026/10/06 19:57:09 INFO Vacuumed table table=objects1019--- PASS: TestSweepSkipsRowsLockedByPush (0.67s)1020=== CONT TestPresentNotReportedWhileGCDeletesClosure10212026/10/06 19:57:09 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."10222026/10/06 19:57:09 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1023--- PASS: TestFailedS3DeleteKeepsTombstone (0.68s)1024=== CONT TestPresentReportsOnlyClosureRoots1025--- PASS: TestGetExistingObjectsLocksRows (0.72s)1026=== CONT TestCreatePin_ReservedPins1027--- PASS: TestService_healthCheckHandler (0.73s)1028=== CONT TestOrphanedObjectsGCStressTest10292026/10/06 19:57:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10302026/10/06 19:57:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1031--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.76s)1032=== CONT TestOrphanedObjectsGC10332026/10/06 19:57:09 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NGJmYmQ1YzMtYmQ0Yy00Y2RlLThlMzUtMmRhZWQ0OWY5OGNkLjVlMzJhMTIxLTE3M2MtNDE5Ny1iMDc0LWMyODBiMzM4MjI1OXgxNzkxMzE2NjI5NTE3MzIwNzUw parts=1010342026/10/06 19:57:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10352026/10/06 19:57:09 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NGJmYmQ1YzMtYmQ0Yy00Y2RlLThlMzUtMmRhZWQ0OWY5OGNkLmQyMGU2ZDliLTZkMzctNDkzYi04YTI2LTkxOTk5NDg1YjM2MngxNzkxMzE2NjI5NTQzNDE3NjYy parts=1010362026/10/06 19:57:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10372026/10/06 19:57:09 INFO Completed upload id=110382026/10/06 19:57:09 INFO Completed upload id=110392026/10/06 19:57:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37005/oidc10402026/10/06 19:57:09 INFO Received uploads request method=POST path=/api/pending_closures10412026/10/06 19:57:09 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010422026/10/06 19:57:09 INFO Received uploads request method=POST path=/api/pending_closures1043--- PASS: TestReadRedirectNar (0.80s)1044=== CONT TestMultipartCleanup10452026/10/06 19:57:09 INFO Received uploads request method=POST path=/api/pending_closures10462026/10/06 19:57:09 INFO Starting cleanup of old closures method=DELETE path=/api/closures10472026/10/06 19:57:09 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10482026/10/06 19:57:09 WARN Found objects in DB but missing from S3, will re-upload count=11049--- PASS: TestService_verifyS3Integrity (0.97s)1050=== CONT TestPendingCleanupUsesOneCutoff10512026/10/06 19:57:10 INFO Aborted multipart uploads count=0 kept=010522026/10/06 19:57:10 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=010532026/10/06 19:57:10 INFO Received uploads request method=POST path=/api/pending_closures10542026/10/06 19:57:10 INFO Vacuumed table table=pending_closures10552026/10/06 19:57:10 INFO Vacuumed table table=pending_objects10562026/10/06 19:57:10 INFO Vacuumed table table=multipart_uploads10572026/10/06 19:57:10 INFO Vacuumed table table=closures10582026/10/06 19:57:10 INFO Vacuumed table table=objects10592026/10/06 19:57:10 INFO Received uploads request method=POST path=/api/pending_closures10602026/10/06 19:57:10 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001061--- PASS: TestService_createPendingClosureHandler (1.02s)1062=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded10632026/10/06 19:57:10 INFO Aborted multipart uploads count=0 kept=010642026/10/06 19:57:10 WARN Force mode enabled - objects will be deleted immediately without grace period10652026/10/06 19:57:10 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=010662026/10/06 19:57:10 INFO Vacuumed table table=pending_closures10672026/10/06 19:57:10 INFO Vacuumed table table=pending_objects10682026/10/06 19:57:10 INFO Vacuumed table table=multipart_uploads10692026/10/06 19:57:10 INFO Vacuumed table table=closures10702026/10/06 19:57:10 INFO Vacuumed table table=objects1071--- PASS: TestReadProxy404 (0.63s)1072=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1073--- PASS: TestReadProxyDisabled (0.62s)1074=== CONT TestCompletedNarNotReofferedAcrossClosures1075--- PASS: TestGCSweepSkipsPendingObjects (0.66s)1076=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1077--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.53s)1078=== CONT TestRedundantMultipartUpload1079--- PASS: TestReadProxyConditionalGet (0.52s)1080=== CONT TestPush_SignsNarinfosOfItsPendingObjects1081--- PASS: TestReadProxyHead (0.55s)1082=== CONT TestPush_RejectsBadRequests1083--- PASS: TestPushWaitsForSweepHoldingRow (1.02s)1084=== CONT TestPush_OverlappingRootsStoreOneRowPerKey1085--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (1.03s)1086=== CONT TestPush_RepeatedRootCommitsOnce1087--- PASS: TestReadProxyInvalidPath (0.50s)1088=== CONT TestPush_CompleteCommitsEveryRoot1089--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.49s)1090=== CONT TestClientSharedPathCommittedMidPush1091--- PASS: TestReadProxyNarStreaming (0.50s)1092=== CONT TestPushDedupSurvivesConcurrentGC1093--- PASS: TestObjectStatsTrigger (0.52s)1094=== CONT TestGCMetrics1095--- PASS: TestReadProxyContentNegotiation (0.57s)1096=== CONT TestGCBugBareHashReferences1097--- PASS: TestPresentReportsOnlyClosureRoots (0.54s)1098=== CONT TestGCAdvisoryLockBlocksConcurrentRun10992026/10/06 19:57:10 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11002026/10/06 19:57:10 WARN Refused reserved pin name=worker-x86_64-linux11012026/10/06 19:57:10 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11022026/10/06 19:57:10 INFO Received create pin request method=POST path=/api/pins/my-app11032026/10/06 19:57:10 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1104--- PASS: TestCreatePin_ReservedPins (0.61s)1105=== CONT TestLeadEndsOnShutdown11062026/10/06 19:57:10 INFO Received uploads request method=POST path=/api/pending_closures11072026/10/06 19:57:10 INFO Received uploads request method=POST path=/api/pending_closures11082026/10/06 19:57:10 INFO Received uploads request method=POST path=/api/pending_closures11092026/10/06 19:57:10 INFO Received cleanup request method=DELETE path=/api/pending_closures11102026/10/06 19:57:10 INFO Received uploads request method=POST path=/api/pending_closures1111--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.59s)1112=== CONT TestLeadIncumbentAnnouncesAtOnce11132026/10/06 19:57:10 INFO Received push request method=POST path=/api/pushes11142026/10/06 19:57:10 INFO Received complete push request method=POST path=/api/pushes/1/complete11152026/10/06 19:57:10 INFO Completed push id=111162026/10/06 19:57:10 INFO Received push request method=POST path=/api/pushes11172026/10/06 19:57:10 INFO Received uploads request method=POST path=/api/pending_closures11182026/10/06 19:57:10 INFO Received cleanup request method=DELETE path=/api/pending_closures11192026/10/06 19:57:10 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket45/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""11202026/10/06 19:57:10 INFO Aborted multipart uploads count=0 kept=111212026/10/06 19:57:10 INFO Received uploads request method=POST path=/api/pending_closures11222026/10/06 19:57:10 INFO Received cleanup request method=DELETE path=/api/pending_closures11232026/10/06 19:57:10 INFO Aborted multipart uploads count=1 kept=01124--- PASS: TestMultipartCleanup (0.72s)1125=== CONT TestLeadElectsOneAndHandsOver11262026/10/06 19:57:10 INFO Received uploads request method=POST path=/api/pending_closures11272026/10/06 19:57:10 INFO Aborted multipart uploads count=0 kept=011282026/10/06 19:57:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11292026/10/06 19:57:10 WARN Force mode enabled - objects will be deleted immediately without grace period11302026/10/06 19:57:10 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NGJmYmQ1YzMtYmQ0Yy00Y2RlLThlMzUtMmRhZWQ0OWY5OGNkLmNhODgwZTkwLTY5NDYtNDk5Mi05YWM4LWM4ZjFiZWJjMDIyYngxNzkxMzE2NjMwNzA0NzUxMzk311312026/10/06 19:57:10 INFO Received uploads request method=POST path=/api/pending_closures11322026/10/06 19:57:10 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NGJmYmQ1YzMtYmQ0Yy00Y2RlLThlMzUtMmRhZWQ0OWY5OGNkLmNhODgwZTkwLTY5NDYtNDk5Mi05YWM4LWM4ZjFiZWJjMDIyYngxNzkxMzE2NjMwNzA0NzUxMzk3 parts=11133--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.65s)1134=== CONT TestConnectWaitsForAPeerMigration11352026/10/06 19:57:10 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=011362026/10/06 19:57:10 INFO Received push request method=POST path=/api/pushes11372026/10/06 19:57:10 INFO Vacuumed table table=pending_closures11382026/10/06 19:57:10 INFO Vacuumed table table=pending_objects11392026/10/06 19:57:10 INFO Vacuumed table table=multipart_uploads11402026/10/06 19:57:10 INFO Vacuumed table table=closures11412026/10/06 19:57:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11422026/10/06 19:57:10 INFO Signed narinfos id=1 count=111432026/10/06 19:57:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11442026/10/06 19:57:10 INFO Vacuumed table table=objects11452026/10/06 19:57:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11462026/10/06 19:57:10 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"11472026/10/06 19:57:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11482026/10/06 19:57:10 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"11492026/10/06 19:57:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11502026/10/06 19:57:10 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=111512026/10/06 19:57:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11522026/10/06 19:57:10 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo11532026/10/06 19:57:10 INFO Received complete push request method=POST path=/api/pushes/2/complete1154--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.62s)1155=== CONT TestResolveDBConnectionString1156=== RUN TestResolveDBConnectionString/flag_wins1157=== PAUSE TestResolveDBConnectionString/flag_wins1158=== RUN TestResolveDBConnectionString/file_when_flag_empty1159=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1160=== RUN TestResolveDBConnectionString/missing_file_is_an_error1161=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1162=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1163=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1164=== RUN TestResolveDBConnectionString/nothing_configured1165=== PAUSE TestResolveDBConnectionString/nothing_configured1166=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock11672026/10/06 19:57:10 INFO Completed push id=21168--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.69s)1169=== CONT TestClientFallsBackToClosures1170=== RUN TestPush_RejectsBadRequests/no_objects1171=== PAUSE TestPush_RejectsBadRequests/no_objects1172=== RUN TestPush_RejectsBadRequests/bad_root1173=== PAUSE TestPush_RejectsBadRequests/bad_root1174=== RUN TestPush_RejectsBadRequests/root_not_in_objects1175=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1176=== RUN TestPush_RejectsBadRequests/no_roots1177=== PAUSE TestPush_RejectsBadRequests/no_roots1178=== CONT TestClientPushesUseOnePush11792026/10/06 19:57:10 INFO Received push request method=POST path=/api/pushes1180=== NAME TestOrphanedObjectsGC1181 orphaned_objects_gc_test.go:290: GC Test Summary:1182 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1183 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1184 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1185 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1186 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1187--- PASS: TestOrphanedObjectsGC (0.87s)1188=== CONT TestPinProtectsFromGC11892026/10/06 19:57:10 INFO Received push request method=POST path=/api/pushes11902026/10/06 19:57:10 INFO Received complete push request method=POST path=/api/pushes/1/complete11912026/10/06 19:57:10 INFO Completed push id=11192--- PASS: TestPush_RepeatedRootCommitsOnce (0.62s)1193=== CONT TestCacheConfigHandler1194=== RUN TestCacheConfigHandler/full_config,_no_issuer1195=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1196=== RUN TestCacheConfigHandler/no_cache_url_configured1197=== PAUSE TestCacheConfigHandler/no_cache_url_configured1198=== RUN TestCacheConfigHandler/no_signing_keys1199=== PAUSE TestCacheConfigHandler/no_signing_keys1200=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1201=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1202=== CONT TestClientWithDependencies1203--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.67s)1204=== CONT TestClientMultipleUploads1205--- PASS: TestPresentNotReportedWhileGCDeletesClosure (1.01s)1206=== CONT TestClientIntegration12072026/10/06 19:57:10 INFO Received push request method=POST path=/api/pushes12082026/10/06 19:57:10 INFO Received complete push request method=POST path=/api/pushes/1/complete12092026/10/06 19:57:10 INFO Completed push id=11210--- PASS: TestPush_CompleteCommitsEveryRoot (0.69s)1211=== CONT TestClientErrorHandling1212=== RUN TestClientErrorHandling/InvalidStorePath1213=== PAUSE TestClientErrorHandling/InvalidStorePath1214=== RUN TestClientErrorHandling/InvalidAuthToken1215=== PAUSE TestClientErrorHandling/InvalidAuthToken1216=== RUN TestClientErrorHandling/ServerNotAvailable1217=== PAUSE TestClientErrorHandling/ServerNotAvailable1218=== CONT TestClientCADerivations12192026/10/06 19:57:10 INFO Received uploads request method=POST path=/api/pending_closures12202026/10/06 19:57:10 INFO Aborted multipart uploads count=0 kept=012212026/10/06 19:57:10 WARN Force mode enabled - objects will be deleted immediately without grace period12222026/10/06 19:57:10 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=012232026/10/06 19:57:10 INFO Vacuumed table table=pending_closures12242026/10/06 19:57:10 INFO Vacuumed table table=pending_objects12252026/10/06 19:57:10 INFO Vacuumed table table=multipart_uploads12262026/10/06 19:57:10 INFO Vacuumed table table=closures12272026/10/06 19:57:10 INFO Vacuumed table table=objects1228--- PASS: TestGCMetrics (0.63s)1229=== CONT TestCacheStatsHandler12302026/10/06 19:57:11 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"1231--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.62s)1232=== CONT TestReadProxyNarinfo12332026/10/06 19:57:11 INFO Aborted multipart uploads count=0 kept=012342026/10/06 19:57:11 INFO lead: acquired remote=192.0.2.1:123412352026/10/06 19:57:11 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=012362026/10/06 19:57:11 INFO Vacuumed table table=pending_closures12372026/10/06 19:57:11 INFO Vacuumed table table=pending_objects12382026/10/06 19:57:11 INFO Vacuumed table table=multipart_uploads12392026/10/06 19:57:11 INFO Vacuumed table table=closures12402026/10/06 19:57:11 INFO Vacuumed table table=objects12412026/10/06 19:57:11 INFO Aborted multipart uploads count=0 kept=012422026/10/06 19:57:11 WARN Force mode enabled - objects will be deleted immediately without grace period12432026/10/06 19:57:11 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=012442026/10/06 19:57:11 INFO lead: acquired remote=192.0.2.1:123412452026/10/06 19:57:11 INFO lead: released remote=192.0.2.1:12341246--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.44s)1247=== CONT TestProxyHeadersOnlyTrustedOnSocket12482026/10/06 19:57:11 INFO Vacuumed table table=pending_closures12492026/10/06 19:57:11 INFO Received push request method=POST path=/api/pushes12502026/10/06 19:57:11 INFO Vacuumed table table=pending_objects12512026/10/06 19:57:11 INFO Vacuumed table table=multipart_uploads12522026/10/06 19:57:11 INFO Vacuumed table table=closures12532026/10/06 19:57:11 INFO Vacuumed table table=objects1254--- PASS: TestPushDedupSurvivesConcurrentGC (0.79s)12552026/10/06 19:57:11 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)1256=== CONT TestIsValidCachePath1257=== RUN TestIsValidCachePath/narinfo12582026/10/06 19:57:11 INFO Uploading jzs052fl8x8h5k99935wfpi2p0ynbn9c-top (224B)1259=== PAUSE TestIsValidCachePath/narinfo12602026/10/06 19:57:11 INFO Uploading chamax9c2ngqbjsjxz1qc41xff1mz9wn-shared-dep (136B)1261=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1262=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1263=== RUN TestIsValidCachePath/nar_zst1264=== PAUSE TestIsValidCachePath/nar_zst1265=== RUN TestIsValidCachePath/nar_xz1266=== PAUSE TestIsValidCachePath/nar_xz1267=== RUN TestIsValidCachePath/nar_bz21268=== PAUSE TestIsValidCachePath/nar_bz21269=== RUN TestIsValidCachePath/nar_uncompressed1270=== PAUSE TestIsValidCachePath/nar_uncompressed1271=== RUN TestIsValidCachePath/ls1272=== PAUSE TestIsValidCachePath/ls1273=== RUN TestIsValidCachePath/log1274=== PAUSE TestIsValidCachePath/log1275=== RUN TestIsValidCachePath/realisation1276=== PAUSE TestIsValidCachePath/realisation1277=== RUN TestIsValidCachePath/nix-cache-info1278=== PAUSE TestIsValidCachePath/nix-cache-info1279=== RUN TestIsValidCachePath/index.html1280=== PAUSE TestIsValidCachePath/index.html1281=== RUN TestIsValidCachePath/traversal_parent1282=== PAUSE TestIsValidCachePath/traversal_parent1283=== RUN TestIsValidCachePath/traversal_in_middle1284=== PAUSE TestIsValidCachePath/traversal_in_middle1285=== RUN TestIsValidCachePath/invalid_char_e1286=== PAUSE TestIsValidCachePath/invalid_char_e1287=== RUN TestIsValidCachePath/invalid_char_u1288=== PAUSE TestIsValidCachePath/invalid_char_u1289=== RUN TestIsValidCachePath/random_path1290=== PAUSE TestIsValidCachePath/random_path1291=== RUN TestIsValidCachePath/empty1292=== PAUSE TestIsValidCachePath/empty1293=== RUN TestIsValidCachePath/leading_slash1294=== PAUSE TestIsValidCachePath/leading_slash1295=== RUN TestIsValidCachePath/wrong_extension1296=== PAUSE TestIsValidCachePath/wrong_extension1297=== RUN TestIsValidCachePath/short_hash1298=== PAUSE TestIsValidCachePath/short_hash1299=== CONT TestService_NativeMTLS13002026/10/06 19:57:11 WARN Failed to register uploaded object key=nar/0nj2rp3gh754chbipwqp7zb9lj517kcinkwnf9kpghx1a8rrrkph.nar.zst error="server returned 404: 404 page not found\n"13012026/10/06 19:57:11 WARN Failed to register uploaded object key=jzs052fl8x8h5k99935wfpi2p0ynbn9c.ls error="server returned 404: 404 page not found\n"13022026/10/06 19:57:11 WARN Failed to register uploaded object key=chamax9c2ngqbjsjxz1qc41xff1mz9wn.ls error="server returned 404: 404 page not found\n"13032026/10/06 19:57:11 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13042026/10/06 19:57:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13052026/10/06 19:57:11 INFO Signed narinfos id=1 count=213062026/10/06 19:57:11 INFO Uploading 2 narinfos13072026/10/06 19:57:11 WARN Failed to register uploaded object key=chamax9c2ngqbjsjxz1qc41xff1mz9wn.narinfo error="server returned 404: 404 page not found\n"13082026/10/06 19:57:11 INFO Received complete push request method=POST path=/api/pushes/1/complete13092026/10/06 19:57:11 WARN Failed to register uploaded object key=jzs052fl8x8h5k99935wfpi2p0ynbn9c.narinfo error="server returned 404: 404 page not found\n"13102026/10/06 19:57:11 INFO lead: acquired remote=192.0.2.1:123413112026/10/06 19:57:11 INFO Completed push id=113122026/10/06 19:57:11 INFO Upload complete. (71ms)1313=== NAME TestClientSharedPathCommittedMidPush1314 client_integration_test.go:680: Retrieved narinfo from S3:1315 StorePath: /build/TestClientSharedPathCommittedMidPush1620254729/001/store/chamax9c2ngqbjsjxz1qc41xff1mz9wn-shared-dep1316 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1317 Compression: zstd1318 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821319 NarSize: 1361320 References: 1321 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1322 client_integration_test.go:680: Retrieved narinfo from S3:1323 StorePath: /build/TestClientSharedPathCommittedMidPush1620254729/001/store/jzs052fl8x8h5k99935wfpi2p0ynbn9c-top1324 URL: nar/0nj2rp3gh754chbipwqp7zb9lj517kcinkwnf9kpghx1a8rrrkph.nar.zst1325 Compression: zstd1326 NarHash: sha256:0nj2rp3gh754chbipwqp7zb9lj517kcinkwnf9kpghx1a8rrrkph1327 NarSize: 2241328 References: /build/TestClientSharedPathCommittedMidPush1620254729/001/store/chamax9c2ngqbjsjxz1qc41xff1mz9wn-shared-dep1329 CA: text:sha256:0caw4315wmmwizh1qa2fcaqf76nga2af16fcqi9h0vkxg4qkp9xf1330--- PASS: TestClientSharedPathCommittedMidPush (0.85s)1331=== CONT TestServerTLSConfig1332=== RUN TestServerTLSConfig/no_client_CA1333=== PAUSE TestServerTLSConfig/no_client_CA1334=== RUN TestServerTLSConfig/missing_CA_file1335=== PAUSE TestServerTLSConfig/missing_CA_file1336=== RUN TestServerTLSConfig/not_a_PEM_file1337=== PAUSE TestServerTLSConfig/not_a_PEM_file1338=== CONT TestMetricsInventory13392026/10/06 19:57:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13402026/10/06 19:57:11 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NGJmYmQ1YzMtYmQ0Yy00Y2RlLThlMzUtMmRhZWQ0OWY5OGNkLjRjZmZkM2MyLWQ5Y2EtNDg0Zi1hY2JiLTBhZDBiYTJkY2NkMHgxNzkxMzE2NjMwNjc2MTAwNDI2 parts=1213412026/10/06 19:57:11 INFO Received uploads request method=POST path=/api/pending_closures1342--- PASS: TestGCBugBareHashReferences (0.86s)1343=== CONT TestService_AuthMiddleware_OIDC1344--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.15s)1345=== CONT TestService_ReadScope_PublicByDefault13462026/10/06 19:57:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1347=== NAME TestPinProtectsFromGC1348 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC739976977/001/store/dhn0nj7r4v6z1027mz1sgksp35412fn2-pinned-file.txt1349 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC739976977/001/store/7882lk1wymphbaclvwcgvlk5hdd9zjcd-unpinned-file.txt1350=== NAME TestClientMultipleUploads1351 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads2275797742/001/store/405ah13r6hqbx8zc8asr39rw166wdr20-test-file-0.txt13522026/10/06 19:57:11 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NGJmYmQ1YzMtYmQ0Yy00Y2RlLThlMzUtMmRhZWQ0OWY5OGNkLjI2YWM3ZjhhLTM0NWQtNGM5ZC04ZDQ1LTliYjE5MTJiNDEyM3gxNzkxMzE2NjMwNzI5NDA2NTEw parts=1213532026/10/06 19:57:11 INFO Received uploads request method=POST path=/api/pending_closures13542026/10/06 19:57:11 INFO Received uploads request method=POST path=/api/pending_closures1355=== NAME TestClientWithDependencies1356 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2435678586/001/store/hb62nb8v8dryxb80ghkqjcg8hpj9d88q-test-script1357=== NAME TestClientIntegration1358 client_integration_test.go:286: Created store path: /build/TestClientIntegration731809851/002/store/lcw15034vfhnzypg4sax1f0vlh98c88r-test-file.txt1359--- PASS: TestCacheStatsHandler (0.33s)1360=== CONT TestReadProxyRangeRequest1361=== NAME TestClientMultipleUploads1362 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads2275797742/001/store/6b3x8v4k2f94vdambsc2y557qza6ivhh-test-file-1.txt13632026/10/06 19:57:11 INFO Received push request method=POST path=/api/pushes13642026/10/06 19:57:11 INFO Received push request method=POST path=/api/pushes13652026/10/06 19:57:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13662026/10/06 19:57:11 INFO Uploading dhn0nj7r4v6z1027mz1sgksp35412fn2-pinned-file.txt (128B)1367=== NAME TestClientWithDependencies1368 client_integration_test.go:615: Found 1 dependencies (including self)13692026/10/06 19:57:11 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13702026/10/06 19:57:11 INFO Uploading 5pjw5m0pv1lhal9rab8p18720f0030jn-shared-dep (136B)13712026/10/06 19:57:11 INFO Uploading 5znk7ln85ryjddihc0n59icz1gdad03i-b (216B)13722026/10/06 19:57:11 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"13732026/10/06 19:57:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13742026/10/06 19:57:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41041/oidc13752026/10/06 19:57:11 WARN Failed to register uploaded object key=dhn0nj7r4v6z1027mz1sgksp35412fn2.ls error="server returned 404: 404 page not found\n"13762026/10/06 19:57:11 INFO Signed narinfos id=1 count=113772026/10/06 19:57:11 INFO Uploading 1 narinfos13782026/10/06 19:57:11 WARN Failed to register uploaded object key=9rwzidzrg6f8rwap6z4p2hz0hry4q9gv.ls error="server returned 404: 404 page not found\n"13792026/10/06 19:57:11 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13802026/10/06 19:57:11 WARN Failed to register uploaded object key=5pjw5m0pv1lhal9rab8p18720f0030jn.ls error="server returned 404: 404 page not found\n"13812026/10/06 19:57:11 WARN Failed to register uploaded object key=nar/0vgjz02xvyg5dvgi571aks5arnf8w6sfjllmcqvs1847v7a7zqwv.nar.zst error="server returned 404: 404 page not found\n"13822026/10/06 19:57:11 WARN Failed to register uploaded object key=5znk7ln85ryjddihc0n59icz1gdad03i.ls error="server returned 404: 404 page not found\n"13832026/10/06 19:57:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13842026/10/06 19:57:11 INFO Signed narinfos id=1 count=313852026/10/06 19:57:11 INFO Uploading 3 narinfos13862026/10/06 19:57:11 INFO Received complete push request method=POST path=/api/pushes/1/complete13872026/10/06 19:57:11 WARN Failed to register uploaded object key=dhn0nj7r4v6z1027mz1sgksp35412fn2.narinfo error="server returned 404: 404 page not found\n"13882026/10/06 19:57:11 WARN Failed to register uploaded object key=5pjw5m0pv1lhal9rab8p18720f0030jn.narinfo error="server returned 404: 404 page not found\n"13892026/10/06 19:57:11 WARN Failed to register uploaded object key=5znk7ln85ryjddihc0n59icz1gdad03i.narinfo error="server returned 404: 404 page not found\n"13902026/10/06 19:57:11 INFO Received complete push request method=POST path=/api/pushes/1/complete13912026/10/06 19:57:11 WARN Failed to register uploaded object key=9rwzidzrg6f8rwap6z4p2hz0hry4q9gv.narinfo error="server returned 404: 404 page not found\n"13922026/10/06 19:57:11 INFO Completed push id=113932026/10/06 19:57:11 INFO Upload complete. (56ms)13942026/10/06 19:57:11 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket2754527184/001/proxy.sock13952026/10/06 19:57:11 INFO Starting HTTP server address=127.0.0.1:3289513962026/10/06 19:57:11 WARN mTLS auth: subject not in bound subjects subject="CN=someone"13972026/10/06 19:57:11 INFO Shutdown signal received, draining in-flight requests timeout=10s1398--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.30s)1399=== CONT TestService_RequireScope_OIDC14002026/10/06 19:57:11 INFO Completed push id=114012026/10/06 19:57:11 INFO Upload complete. (72ms)1402=== NAME TestClientMultipleUploads1403 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads2275797742/001/store/fn5d4wwczwspxns7xglnaz1kwmkslj65-test-file-2.txt1404=== NAME TestClientPushesUseOnePush1405 client_pushes_test.go:97: Retrieved narinfo from S3:1406 StorePath: /build/TestClientPushesUseOnePush4114699541/001/store/5pjw5m0pv1lhal9rab8p18720f0030jn-shared-dep1407 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1408 Compression: zstd1409 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821410 NarSize: 1361411 References: 1412 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n14132026/10/06 19:57:11 INFO Received uploads request method=POST path=/api/pending_closures1414 client_pushes_test.go:97: Retrieved narinfo from S3:1415 StorePath: /build/TestClientPushesUseOnePush4114699541/001/store/9rwzidzrg6f8rwap6z4p2hz0hry4q9gv-a1416 URL: nar/0vgjz02xvyg5dvgi571aks5arnf8w6sfjllmcqvs1847v7a7zqwv.nar.zst1417 Compression: zstd1418 NarHash: sha256:0vgjz02xvyg5dvgi571aks5arnf8w6sfjllmcqvs1847v7a7zqwv1419 NarSize: 2161420 References: /build/TestClientPushesUseOnePush4114699541/001/store/5pjw5m0pv1lhal9rab8p18720f0030jn-shared-dep1421 CA: text:sha256:03kngdzwqqb9yjr66d437vfi4ha4jirnx9g52sldd6qgph6j4klh1422 client_pushes_test.go:97: Retrieved narinfo from S3:1423 StorePath: /build/TestClientPushesUseOnePush4114699541/001/store/5znk7ln85ryjddihc0n59icz1gdad03i-b1424 URL: nar/0vgjz02xvyg5dvgi571aks5arnf8w6sfjllmcqvs1847v7a7zqwv.nar.zst1425 Compression: zstd1426 NarHash: sha256:0vgjz02xvyg5dvgi571aks5arnf8w6sfjllmcqvs1847v7a7zqwv1427 NarSize: 2161428 References: /build/TestClientPushesUseOnePush4114699541/001/store/5pjw5m0pv1lhal9rab8p18720f0030jn-shared-dep1429 CA: text:sha256:03kngdzwqqb9yjr66d437vfi4ha4jirnx9g52sldd6qgph6j4klh14302026/10/06 19:57:11 INFO Received uploads request method=POST path=/api/pending_closures1431--- PASS: TestClientPushesUseOnePush (0.61s)1432=== CONT TestReadRedirectUsesPublicS3URL14332026/10/06 19:57:11 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14342026/10/06 19:57:11 INFO Uploading 4sryyz97gscwrl5hnxggvppr5rnm6a03-shared-dep (136B)14352026/10/06 19:57:11 INFO Uploading q3dqvxqzsc0fqmra5zax7123kn81756z-b (216B)14362026/10/06 19:57:11 WARN Failed to register uploaded object key=4sryyz97gscwrl5hnxggvppr5rnm6a03.ls error="server returned 404: 404 page not found\n"14372026/10/06 19:57:11 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14382026/10/06 19:57:11 WARN Failed to register uploaded object key=nar/1dlkn6i6sm4hj9c4slr35yqr47h4klj8qvcz9dfr32y5nk58h47x.nar.zst error="server returned 404: 404 page not found\n"14392026/10/06 19:57:11 WARN Failed to register uploaded object key=6jywn3qn1snk0vlpcx0r3d0gg3i475dw.ls error="server returned 404: 404 page not found\n"14402026/10/06 19:57:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41935/oidc14412026/10/06 19:57:11 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14422026/10/06 19:57:11 WARN Failed to register uploaded object key=q3dqvxqzsc0fqmra5zax7123kn81756z.ls error="server returned 404: 404 page not found\n"14432026/10/06 19:57:11 INFO Signed narinfos id=1 count=214442026/10/06 19:57:11 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14452026/10/06 19:57:11 INFO Signed narinfos id=2 count=214462026/10/06 19:57:11 INFO Uploading 4 narinfos14472026/10/06 19:57:11 WARN mTLS auth: subject not in bound subjects subject="CN=reader"14482026/10/06 19:57:11 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1449--- PASS: TestService_NativeMTLS (0.31s)1450=== CONT TestService_AuthMiddleware_MTLSBoundSubjects14512026/10/06 19:57:11 INFO Received push request method=POST path=/api/pushes14522026/10/06 19:57:11 WARN Failed to register uploaded object key=q3dqvxqzsc0fqmra5zax7123kn81756z.narinfo error="server returned 404: 404 page not found\n"14532026/10/06 19:57:11 WARN Failed to register uploaded object key=4sryyz97gscwrl5hnxggvppr5rnm6a03.narinfo error="server returned 404: 404 page not found\n"14542026/10/06 19:57:11 WARN Failed to register uploaded object key=6jywn3qn1snk0vlpcx0r3d0gg3i475dw.narinfo error="server returned 404: 404 page not found\n"1455=== NAME TestClientCADerivations1456 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3542576667/001/store/kf8xasl73lq731n5i8alm0kw8x5bgrjk-ca-test14572026/10/06 19:57:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14582026/10/06 19:57:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14592026/10/06 19:57:11 INFO Uploading lcw15034vfhnzypg4sax1f0vlh98c88r-test-file.txt (152B)14602026/10/06 19:57:11 WARN Failed to register uploaded object key=4sryyz97gscwrl5hnxggvppr5rnm6a03.narinfo error="server returned 404: 404 page not found\n"14612026/10/06 19:57:11 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"14622026/10/06 19:57:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14632026/10/06 19:57:11 INFO Signed narinfos id=1 count=114642026/10/06 19:57:11 WARN Failed to register uploaded object key=lcw15034vfhnzypg4sax1f0vlh98c88r.ls error="server returned 404: 404 page not found\n"14652026/10/06 19:57:11 INFO Uploading 1 narinfos14662026/10/06 19:57:11 INFO Completed upload id=114672026/10/06 19:57:11 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14682026/10/06 19:57:11 INFO Received complete push request method=POST path=/api/pushes/1/complete14692026/10/06 19:57:11 WARN Failed to register uploaded object key=lcw15034vfhnzypg4sax1f0vlh98c88r.narinfo error="server returned 404: 404 page not found\n"14702026/10/06 19:57:11 INFO Completed upload id=214712026/10/06 19:57:11 INFO Upload complete. (77ms)1472=== NAME TestClientFallsBackToClosures1473 client_pushes_test.go:112: Retrieved narinfo from S3:1474 StorePath: /build/TestClientFallsBackToClosures2946952423/001/store/4sryyz97gscwrl5hnxggvppr5rnm6a03-shared-dep1475 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1476 Compression: zstd1477 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821478 NarSize: 1361479 References: 1480 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1481 client_pushes_test.go:112: Retrieved narinfo from S3:1482 StorePath: /build/TestClientFallsBackToClosures2946952423/001/store/6jywn3qn1snk0vlpcx0r3d0gg3i475dw-a1483 URL: nar/1dlkn6i6sm4hj9c4slr35yqr47h4klj8qvcz9dfr32y5nk58h47x.nar.zst1484 Compression: zstd1485 NarHash: sha256:1dlkn6i6sm4hj9c4slr35yqr47h4klj8qvcz9dfr32y5nk58h47x1486 NarSize: 2161487 References: /build/TestClientFallsBackToClosures2946952423/001/store/4sryyz97gscwrl5hnxggvppr5rnm6a03-shared-dep1488 CA: text:sha256:0m049q19kzpbs63b97arfzmdq20b6sgjgzxsffkpa1wlwcyapj4c1489 client_pushes_test.go:112: Retrieved narinfo from S3:1490 StorePath: /build/TestClientFallsBackToClosures2946952423/001/store/q3dqvxqzsc0fqmra5zax7123kn81756z-b1491 URL: nar/1dlkn6i6sm4hj9c4slr35yqr47h4klj8qvcz9dfr32y5nk58h47x.nar.zst1492 Compression: zstd1493 NarHash: sha256:1dlkn6i6sm4hj9c4slr35yqr47h4klj8qvcz9dfr32y5nk58h47x1494 NarSize: 2161495 References: /build/TestClientFallsBackToClosures2946952423/001/store/4sryyz97gscwrl5hnxggvppr5rnm6a03-shared-dep1496 CA: text:sha256:0m049q19kzpbs63b97arfzmdq20b6sgjgzxsffkpa1wlwcyapj4c14972026/10/06 19:57:11 INFO Completed push id=114982026/10/06 19:57:11 INFO Upload complete. (66ms)1499--- PASS: TestClientFallsBackToClosures (0.66s)1500=== CONT TestService_ReadAuthMiddleware15012026/10/06 19:57:11 INFO Received push request method=POST path=/api/pushes1502=== NAME TestClientCADerivations1503 client_ca_test.go:139: Found 1 dependencies (including self)15042026/10/06 19:57:11 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1505--- PASS: TestReadProxyNarinfo (0.40s)1506=== CONT TestReadRedirectKeepsNarinfoProxied15072026/10/06 19:57:11 INFO Received push request method=POST path=/api/pushes15082026/10/06 19:57:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15092026/10/06 19:57:11 INFO Uploading hb62nb8v8dryxb80ghkqjcg8hpj9d88q-test-script (136B)1510--- PASS: TestService_ReadScope_PublicByDefault (0.21s)1511=== CONT TestService_AuthMiddleware_MTLSProxyHeader15122026/10/06 19:57:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15132026/10/06 19:57:11 INFO Uploading 7882lk1wymphbaclvwcgvlk5hdd9zjcd-unpinned-file.txt (128B)1514--- PASS: TestMetricsInventory (0.33s)1515=== CONT TestProxyWriteTimeout/narinfo1516=== CONT TestProxyWriteTimeout/1_GiB_nar1517=== CONT TestProxyWriteTimeout/10_GiB_nar15182026/10/06 19:57:11 WARN Failed to register uploaded object key=hb62nb8v8dryxb80ghkqjcg8hpj9d88q.ls error="server returned 404: 404 page not found\n"1519=== CONT TestProxyWriteTimeout/unknown_size1520--- PASS: TestProxyWriteTimeout (0.16s)1521 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1522 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1523 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1524 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1525=== CONT TestGCEndsOnShutdown/before_the_run15262026/10/06 19:57:11 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15272026/10/06 19:57:11 WARN Failed to register uploaded object key=7882lk1wymphbaclvwcgvlk5hdd9zjcd.ls error="server returned 404: 404 page not found\n"15282026/10/06 19:57:11 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15292026/10/06 19:57:11 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15302026/10/06 19:57:11 INFO Signed narinfos id=2 count=115312026/10/06 19:57:11 INFO Uploading 1 narinfos15322026/10/06 19:57:11 WARN Failed to register uploaded object key=log/gf7x1ymh7x16j5vs98qzwm5iwp6ym4b7-test-script.drv error="server returned 404: 404 page not found\n"15332026/10/06 19:57:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15342026/10/06 19:57:11 INFO Signed narinfos id=1 count=115352026/10/06 19:57:11 INFO Uploading 1 narinfos15362026/10/06 19:57:11 INFO Received complete push request method=POST path=/api/pushes/2/complete15372026/10/06 19:57:11 WARN Failed to register uploaded object key=7882lk1wymphbaclvwcgvlk5hdd9zjcd.narinfo error="server returned 404: 404 page not found\n"15382026/10/06 19:57:11 INFO Received complete push request method=POST path=/api/pushes/1/complete15392026/10/06 19:57:11 INFO Received push request method=POST path=/api/pushes15402026/10/06 19:57:11 WARN Failed to register uploaded object key=hb62nb8v8dryxb80ghkqjcg8hpj9d88q.narinfo error="server returned 404: 404 page not found\n"15412026/10/06 19:57:11 INFO Completed push id=215422026/10/06 19:57:11 INFO Upload complete. (49ms)15432026/10/06 19:57:11 INFO All 1 paths already cached1544=== NAME TestClientIntegration1545 client_integration_test.go:312: Retrieved narinfo from S3:1546 StorePath: /build/TestClientIntegration731809851/002/store/lcw15034vfhnzypg4sax1f0vlh98c88r-test-file.txt1547 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1548 Compression: zstd1549 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11550 NarSize: 1521551 References: 1552 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk115532026/10/06 19:57:11 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15542026/10/06 19:57:11 INFO Uploading 6b3x8v4k2f94vdambsc2y557qza6ivhh-test-file-1.txt (160B)15552026/10/06 19:57:11 INFO Uploading fn5d4wwczwspxns7xglnaz1kwmkslj65-test-file-2.txt (160B)15562026/10/06 19:57:11 INFO Uploading 405ah13r6hqbx8zc8asr39rw166wdr20-test-file-0.txt (160B)1557 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1558 client_integration_test.go:313: Decompressed .ls content (64 bytes):1559 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1560 client_integration_test.go:316: Testing garbage collection...15612026/10/06 19:57:11 INFO Completed push id=115622026/10/06 19:57:11 INFO Upload complete. (77ms)15632026/10/06 19:57:11 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15642026/10/06 19:57:11 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15652026/10/06 19:57:11 WARN Failed to register uploaded object key=405ah13r6hqbx8zc8asr39rw166wdr20.ls error="server returned 404: 404 page not found\n"15662026/10/06 19:57:11 WARN Failed to register uploaded object key=fn5d4wwczwspxns7xglnaz1kwmkslj65.ls error="server returned 404: 404 page not found\n"15672026/10/06 19:57:11 WARN Failed to register uploaded object key=6b3x8v4k2f94vdambsc2y557qza6ivhh.ls error="server returned 404: 404 page not found\n"15682026/10/06 19:57:11 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15692026/10/06 19:57:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1570=== NAME TestClientWithDependencies1571 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2435678586/001/store) requires matching store prefix15722026/10/06 19:57:11 INFO Signed narinfos id=1 count=315732026/10/06 19:57:11 INFO Uploading 3 narinfos1574--- PASS: TestClientWithDependencies (0.62s)1575=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark15762026/10/06 19:57:11 WARN Failed to register uploaded object key=6b3x8v4k2f94vdambsc2y557qza6ivhh.narinfo error="server returned 404: 404 page not found\n"15772026/10/06 19:57:11 WARN Failed to register uploaded object key=fn5d4wwczwspxns7xglnaz1kwmkslj65.narinfo error="server returned 404: 404 page not found\n"15782026/10/06 19:57:11 INFO Received complete push request method=POST path=/api/pushes/1/complete15792026/10/06 19:57:11 WARN Failed to register uploaded object key=405ah13r6hqbx8zc8asr39rw166wdr20.narinfo error="server returned 404: 404 page not found\n"1580--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.71s)1581=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete15822026/10/06 19:57:11 INFO Completed push id=115832026/10/06 19:57:11 INFO Upload complete. (74ms)1584=== NAME TestClientMultipleUploads1585 client_integration_test.go:369: Uploaded 3 paths in 110.431575ms15862026/10/06 19:57:11 INFO Starting cleanup of old closures method=DELETE path=/api/closures15872026/10/06 19:57:11 INFO Garbage collection started1588--- PASS: TestClientMultipleUploads (0.62s)1589=== CONT TestPendingClosureWriteTimeout/empty1590=== CONT TestPendingClosureWriteTimeout/400_objects1591=== CONT TestPendingClosureWriteTimeout/670k_objects1592=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline15932026/10/06 19:57:11 INFO Starting cleanup of old closures method=DELETE path=/api/closures15942026/10/06 19:57:11 INFO Garbage collection started15952026/10/06 19:57:11 INFO Aborted multipart uploads count=0 kept=015962026/10/06 19:57:11 INFO Aborted multipart uploads count=0 kept=015972026/10/06 19:57:11 WARN Force mode enabled - objects will be deleted immediately without grace period15982026/10/06 19:57:11 WARN Force mode enabled - objects will be deleted immediately without grace period1599--- PASS: TestReadProxyRangeRequest (0.21s)1600=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16012026/10/06 19:57:11 INFO Received uploads request method=POST path=/1602=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16032026/10/06 19:57:11 INFO Received complete multipart upload request method=POST path=/1604=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16052026/10/06 19:57:11 INFO Received request for more parts method=POST path=/1606=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16072026/10/06 19:57:11 INFO Received uploads request method=POST path=/1608--- PASS: TestUploadHandlersRejectInvalidKeys (0.17s)1609 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1610 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1611 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1612 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1613=== CONT TestParseSingleRange/none1614=== CONT TestParseSingleRange/start_far_past_EOF1615=== CONT TestParseSingleRange/start_past_EOF1616=== CONT TestParseSingleRange/single_byte1617=== CONT TestParseSingleRange/suffix_exceeds_size1618=== CONT TestParseSingleRange/suffix1619=== CONT TestParseSingleRange/end_clamped_to_size1620=== CONT TestParseSingleRange/open-ended1621=== CONT TestParseSingleRange/closed1622=== CONT TestParseSingleRange/malformed_end_before_start1623=== CONT TestParseSingleRange/malformed_both_empty1624=== CONT TestParseSingleRange/malformed_no_dash1625=== CONT TestParseSingleRange/multi-range_ignored1626=== CONT TestParseSingleRange/unknown_unit1627--- PASS: TestParseSingleRange (0.18s)1628 --- PASS: TestParseSingleRange/none (0.00s)1629 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1630 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1631 --- PASS: TestParseSingleRange/single_byte (0.00s)1632 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1633 --- PASS: TestParseSingleRange/suffix (0.00s)1634 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1635 --- PASS: TestParseSingleRange/open-ended (0.00s)1636 --- PASS: TestParseSingleRange/closed (0.00s)1637 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1638 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1639 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1640 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1641 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1642=== CONT TestIsValidUploadKey/narinfo1643=== CONT TestIsValidUploadKey/unknown_type1644=== CONT TestIsValidUploadKey/empty_key1645=== CONT TestIsValidUploadKey/absolute1646=== CONT TestIsValidUploadKey/traversal_nar1647=== CONT TestIsValidUploadKey/traversal1648=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1649=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1650=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1651=== CONT TestIsValidUploadKey/index.html1652=== CONT TestIsValidUploadKey/nix-cache-info1653=== CONT TestIsValidUploadKey/realisation_plus_in_output1654=== CONT TestIsValidUploadKey/realisation1655=== CONT TestIsValidUploadKey/build_log_equals1656=== CONT TestIsValidUploadKey/listing1657=== CONT TestIsValidUploadKey/nar_plain1658=== CONT TestIsValidUploadKey/nar_xz1659=== CONT TestIsValidUploadKey/nar_zst1660=== CONT TestIsValidUploadKey/build_log_plus_in_name1661=== CONT TestIsValidUploadKey/build_log_question_mark1662=== CONT TestIsValidUploadKey/build_log_home-manager_file1663=== CONT TestIsValidUploadKey/build_log1664--- PASS: TestIsValidUploadKey (0.17s)1665 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1666 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1667 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1668 --- PASS: TestIsValidUploadKey/absolute (0.00s)1669 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1670 --- PASS: TestIsValidUploadKey/traversal (0.00s)1671 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1672 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1673 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1674 --- PASS: TestIsValidUploadKey/index.html (0.00s)1675 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1676 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1677 --- PASS: TestIsValidUploadKey/realisation (0.00s)1678 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1679 --- PASS: TestIsValidUploadKey/listing (0.00s)1680 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1681 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1682 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1683 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1684 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1685 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1686 --- PASS: TestIsValidUploadKey/build_log (0.00s)1687=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows16882026/10/06 19:57:11 INFO Received push request method=POST path=/api/pushes16892026/10/06 19:57:11 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=016902026/10/06 19:57:11 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=016912026/10/06 19:57:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16922026/10/06 19:57:11 INFO Uploading kf8xasl73lq731n5i8alm0kw8x5bgrjk-ca-test (144B)16932026/10/06 19:57:11 INFO Vacuumed table table=pending_closures16942026/10/06 19:57:11 INFO Vacuumed table table=pending_closures16952026/10/06 19:57:11 WARN Failed to register uploaded object key=log/6d1najnly2bykr66f2nxxiwcv35hhsjk-ca-test.drv error="server returned 404: 404 page not found\n"16962026/10/06 19:57:11 WARN Failed to register uploaded object key=kf8xasl73lq731n5i8alm0kw8x5bgrjk.ls error="server returned 404: 404 page not found\n"16972026/10/06 19:57:11 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16982026/10/06 19:57:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16992026/10/06 19:57:11 INFO Vacuumed table table=pending_objects17002026/10/06 19:57:11 INFO Vacuumed table table=multipart_uploads17012026/10/06 19:57:11 INFO Signed narinfos id=1 count=117022026/10/06 19:57:11 INFO Uploading 1 narinfos1703=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1704=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1705=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1706=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1707=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1708=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1709=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1710=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1711=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check17122026/10/06 19:57:11 INFO Vacuumed table table=pending_objects17132026/10/06 19:57:11 INFO Vacuumed table table=multipart_uploads17142026/10/06 19:57:11 INFO Received complete push request method=POST path=/api/pushes/1/complete17152026/10/06 19:57:11 WARN Failed to register uploaded object key=kf8xasl73lq731n5i8alm0kw8x5bgrjk.narinfo error="server returned 404: 404 page not found\n"17162026/10/06 19:57:11 INFO Vacuumed table table=closures17172026/10/06 19:57:11 INFO Vacuumed table table=closures17182026/10/06 19:57:11 INFO Vacuumed table table=objects17192026/10/06 19:57:11 INFO Vacuumed table table=objects17202026/10/06 19:57:11 INFO Completed push id=117212026/10/06 19:57:11 INFO Upload complete. (102ms)1722=== NAME TestClientCADerivations1723 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3542576667/001/store/kf8xasl73lq731n5i8alm0kw8x5bgrjk-ca-test1724 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1725 Compression: zstd1726 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1727 NarSize: 1441728 References: 1729 Deriver: /build/TestClientCADerivations3542576667/001/store/6d1najnly2bykr66f2nxxiwcv35hhsjk-ca-test.drv1730 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1731 client_ca_test.go:185: Checking for realisation files in S3...1732 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1733 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1734--- PASS: TestReadRedirectUsesPublicS3URL (0.24s)1735=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17362026/10/06 19:57:11 INFO Received uploads request method=POST path=/1737=== RUN TestService_RequireScope_OIDC/builder_may_write1738=== PAUSE TestService_RequireScope_OIDC/builder_may_write1739=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1740=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1741=== RUN TestService_RequireScope_OIDC/ops_may_admin1742=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1743=== RUN TestService_RequireScope_OIDC/ops_may_not_write1744=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1745=== RUN TestService_RequireScope_OIDC/reader_may_not_write1746=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1747=== RUN TestService_RequireScope_OIDC/static_token_may_admin1748=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1749=== RUN TestService_RequireScope_OIDC/static_token_may_write1750=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1751=== RUN TestService_RequireScope_OIDC/reader_may_read1752=== PAUSE TestService_RequireScope_OIDC/reader_may_read1753=== RUN TestService_RequireScope_OIDC/writer_implies_read1754=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1755=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1756=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1757=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1758=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1759=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1760=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1761=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1762=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1763=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1764=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1765=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17662026/10/06 19:57:11 INFO Received complete multipart upload request method=POST path=/17672026/10/06 19:57:11 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17682026/10/06 19:57:11 WARN mTLS auth: bound subjects configured but subject DN unavailable17692026/10/06 19:57:11 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1770--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.27s)1771=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17722026/10/06 19:57:11 INFO Received request for more parts method=POST path=/1773--- PASS: TestService_ReadAuthMiddleware (0.27s)1774=== CONT TestResolveDBConnectionString/flag_wins1775=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1776=== CONT TestResolveDBConnectionString/nothing_configured1777=== CONT TestResolveDBConnectionString/missing_file_is_an_error1778=== CONT TestResolveDBConnectionString/file_when_flag_empty1779=== CONT TestPush_RejectsBadRequests/no_objects17802026/10/06 19:57:11 INFO Received push request method=POST path=/api/pushes1781=== CONT TestPush_RejectsBadRequests/root_not_in_objects17822026/10/06 19:57:11 INFO Received push request method=POST path=/api/pushes1783=== CONT TestPush_RejectsBadRequests/no_roots17842026/10/06 19:57:11 INFO Received push request method=POST path=/api/pushes1785=== CONT TestPush_RejectsBadRequests/bad_root17862026/10/06 19:57:11 INFO Received push request method=POST path=/api/pushes1787=== CONT TestCacheConfigHandler/full_config,_no_issuer1788--- PASS: TestPush_RejectsBadRequests (0.57s)1789 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1790 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1791 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1792 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1793--- PASS: TestResolveDBConnectionString (0.00s)1794 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1795 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1796 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1797 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1798 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1799=== CONT TestCacheConfigHandler/no_signing_keys1800=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1801=== CONT TestCacheConfigHandler/no_cache_url_configured1802--- PASS: TestCacheConfigHandler (0.00s)1803 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1804 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1805 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1806 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1807=== NAME TestClientCADerivations1808 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1809 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1810 error: binary cache 's3://bucket72?endpoint=http://localhost:36271®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3542576667/001/store'1811 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11812=== CONT TestClientErrorHandling/InvalidStorePath1813--- PASS: TestClientCADerivations (0.77s)1814=== CONT TestClientErrorHandling/ServerNotAvailable1815=== CONT TestClientErrorHandling/InvalidAuthToken1816=== CONT TestIsValidCachePath/narinfo1817=== CONT TestIsValidCachePath/index.html1818=== CONT TestIsValidCachePath/short_hash1819=== CONT TestIsValidCachePath/wrong_extension1820=== CONT TestIsValidCachePath/invalid_char_e1821=== CONT TestIsValidCachePath/traversal_in_middle1822=== CONT TestIsValidCachePath/traversal_parent1823=== CONT TestIsValidCachePath/invalid_char_u1824=== CONT TestIsValidCachePath/leading_slash1825=== CONT TestIsValidCachePath/nar_uncompressed1826=== CONT TestIsValidCachePath/empty1827=== CONT TestIsValidCachePath/random_path1828=== CONT TestIsValidCachePath/nix-cache-info1829=== CONT TestIsValidCachePath/log1830=== CONT TestIsValidCachePath/ls1831=== CONT TestIsValidCachePath/realisation1832=== CONT TestIsValidCachePath/nar_xz1833=== CONT TestIsValidCachePath/nar_zst1834=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1835=== CONT TestIsValidCachePath/nar_bz21836=== CONT TestServerTLSConfig/no_client_CA1837=== CONT TestServerTLSConfig/not_a_PEM_file1838--- PASS: TestIsValidCachePath (0.00s)1839 --- PASS: TestIsValidCachePath/narinfo (0.00s)1840 --- PASS: TestIsValidCachePath/index.html (0.00s)1841 --- PASS: TestIsValidCachePath/short_hash (0.00s)1842 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1843 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1844 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1845 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1846 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1847 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1848 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1849 --- PASS: TestIsValidCachePath/empty (0.00s)1850 --- PASS: TestIsValidCachePath/random_path (0.00s)1851 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1852 --- PASS: TestIsValidCachePath/log (0.00s)1853 --- PASS: TestIsValidCachePath/ls (0.00s)1854 --- PASS: TestIsValidCachePath/realisation (0.00s)1855 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1856 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1857 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1858 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1859=== CONT TestServerTLSConfig/missing_CA_file1860--- PASS: TestServerTLSConfig (0.00s)1861 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1862 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1863 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1864=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1865=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18662026/10/06 19:57:11 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]1867=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1868=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1869=== CONT TestService_RequireScope_OIDC/builder_may_write1870=== CONT TestService_RequireScope_OIDC/reader_may_read1871=== CONT TestService_RequireScope_OIDC/static_token_may_write1872=== CONT TestService_RequireScope_OIDC/static_token_may_admin1873=== CONT TestService_RequireScope_OIDC/reader_may_not_write1874=== CONT TestService_RequireScope_OIDC/ops_may_not_write18752026/10/06 19:57:11 WARN Authentication failed token_preview=eyJhbGciOi...ETNUZhlqNg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1876=== CONT TestService_RequireScope_OIDC/ops_may_admin1877=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1878=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1879=== CONT TestService_RequireScope_OIDC/writer_implies_read18802026/10/06 19:57:11 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]1881=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1882=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1883=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1884=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1885--- PASS: TestService_AuthMiddleware_OIDC (0.32s)1886 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1887 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1888 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1889 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1890--- PASS: TestService_RequireScope_OIDC (0.29s)1891 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1892 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1893 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1894 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1895 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1896 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1897 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1898 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1899 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1900 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1901 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1902 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1903 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1904 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1905--- PASS: TestConcurrentPresentSharingKeysDoNotDeadlock (1.87s)1906--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.29s)1907--- PASS: TestReadRedirectKeepsNarinfoProxied (0.33s)19082026/10/06 19:57:12 INFO lead: released remote=192.0.2.1:12341909--- PASS: TestLeadEndsOnShutdown (1.58s)19102026/10/06 19:57:12 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19112026/10/06 19:57:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19122026/10/06 19:57:12 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NGJmYmQ1YzMtYmQ0Yy00Y2RlLThlMzUtMmRhZWQ0OWY5OGNkLjk2YTk0NTlkLTg2YTYtNGNjZS05MTMxLTUxZTNmZDJjMmZlZXgxNzkxMzE2NjMxMzEyNTk1OTg1 error="Get \"http://127.0.0.1:1/bucket51/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"19132026/10/06 19:57:12 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NGJmYmQ1YzMtYmQ0Yy00Y2RlLThlMzUtMmRhZWQ0OWY5OGNkLjRmNTdhNGNkLTY4MWQtNDhiMC1iNzJhLWU3ZmM0NWQ0Y2JmMngxNzkxMzE2NjMxMzA1MjM4MzAw parts=1219142026/10/06 19:57:12 INFO Received cleanup request method=DELETE path=/api/pending_closures19152026/10/06 19:57:12 INFO Aborted multipart uploads count=1 kept=01916--- PASS: TestRedundantMultipartUpload (2.09s)19172026/10/06 19:57:12 INFO Received uploads request method=POST path=/api/pending_closures19182026/10/06 19:57:12 INFO Aborted multipart uploads count=0 kept=019192026/10/06 19:57:12 WARN Force mode enabled - objects will be deleted immediately without grace period19202026/10/06 19:57:12 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=189.052067ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19212026/10/06 19:57:12 INFO Aborted multipart uploads count=0 kept=019222026/10/06 19:57:12 WARN Force mode enabled - objects will be deleted immediately without grace period19232026/10/06 19:57:12 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:36271/bucket90/?delete=\": context canceled"1924--- PASS: TestGCEndsOnShutdown (0.00s)1925 --- PASS: TestGCEndsOnShutdown/before_the_run (0.27s)1926 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.77s)1927 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.79s)19282026/10/06 19:57:12 INFO Received uploads request method=POST path=/api/pending_closures19292026/10/06 19:57:12 INFO Aborted multipart uploads count=0 kept=019302026/10/06 19:57:12 WARN Force mode enabled - objects will be deleted immediately without grace period19312026/10/06 19:57:12 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=019322026/10/06 19:57:12 INFO Vacuumed table table=pending_closures19332026/10/06 19:57:12 INFO Vacuumed table table=pending_objects19342026/10/06 19:57:12 INFO Vacuumed table table=multipart_uploads19352026/10/06 19:57:12 INFO Vacuumed table table=closures19362026/10/06 19:57:12 INFO lead: released remote=192.0.2.1:123419372026/10/06 19:57:12 INFO Vacuumed table table=objects19382026/10/06 19:57:12 INFO Received uploads request method=POST path=/api/pending_closures19392026/10/06 19:57:12 INFO Aborted multipart uploads count=0 kept=019402026/10/06 19:57:12 WARN Force mode enabled - objects will be deleted immediately without grace period19412026/10/06 19:57:12 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=019422026/10/06 19:57:12 INFO Vacuumed table table=pending_closures19432026/10/06 19:57:12 INFO Vacuumed table table=pending_objects19442026/10/06 19:57:12 INFO Vacuumed table table=multipart_uploads19452026/10/06 19:57:12 INFO Vacuumed table table=closures19462026/10/06 19:57:12 INFO Vacuumed table table=objects1947--- PASS: TestUploadHandlersRejectOversizedBody (0.26s)1948 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.05s)1949 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)1950 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.71s)1951--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1952 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.75s)1953 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.80s)19542026/10/06 19:57:12 INFO lead: acquired remote=192.0.2.1:123419552026/10/06 19:57:12 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=431.782914ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19562026/10/06 19:57:12 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1957=== NAME TestOrphanedObjectsGCStressTest1958 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains19592026/10/06 19:57:12 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1960 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1961 orphaned_objects_gc_test.go:509: Stress test completed successfully:1962 orphaned_objects_gc_test.go:510: - Active objects preserved: 201963 orphaned_objects_gc_test.go:511: - Objects deleted: 2101964 orphaned_objects_gc_test.go:512: - Total GC'd: 2101965--- PASS: TestOrphanedObjectsGCStressTest (2.92s)19662026/10/06 19:57:12 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=835.065357ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1967--- PASS: TestPendingClosureWriteTimeout (0.17s)1968 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1969 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1970 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1971 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.54s)19722026/10/06 19:57:13 WARN Rate limiter enabled after throttle name=s3-test rate=519732026/10/06 19:57:13 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1974=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1975 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101976 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001977--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.16s)19782026/10/06 19:57:13 INFO lead: released remote=192.0.2.1:12341979--- PASS: TestLeadElectsOneAndHandsOver (2.70s)19802026/10/06 19:57:13 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=019812026/10/06 19:57:13 INFO Received create pin request method=POST path=/api/pins/myapp19822026/10/06 19:57:13 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01983=== NAME TestClientIntegration1984 client_integration_test.go:323: Objects in database after GC:19852026/10/06 19:57:13 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC739976977/001/store/dhn0nj7r4v6z1027mz1sgksp35412fn2-pinned-file.txt narinfo_key=dhn0nj7r4v6z1027mz1sgksp35412fn2.narinfo19862026/10/06 19:57:13 INFO Starting cleanup of old closures method=DELETE path=/api/closures1987 client_integration_test.go:323: Successfully deleted all objects with GC --force19882026/10/06 19:57:13 INFO Garbage collection started19892026/10/06 19:57:13 INFO Aborted multipart uploads count=0 kept=01990--- PASS: TestClientIntegration (2.63s)19912026/10/06 19:57:13 WARN Force mode enabled - objects will be deleted immediately without grace period19922026/10/06 19:57:13 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=019932026/10/06 19:57:13 INFO Vacuumed table table=pending_closures19942026/10/06 19:57:13 INFO Vacuumed table table=pending_objects19952026/10/06 19:57:13 INFO Vacuumed table table=multipart_uploads19962026/10/06 19:57:13 INFO Vacuumed table table=closures19972026/10/06 19:57:13 INFO Vacuumed table table=objects19982026/10/06 19:57:13 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.619745783s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1999--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.74s)20002026/10/06 19:57:15 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20012026/10/06 19:57:15 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=185.985141ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2002=== NAME TestPinProtectsFromGC2003 client_integration_test.go:840: Pin successfully protected closure from garbage collection2004--- PASS: TestPinProtectsFromGC (4.70s)20052026/10/06 19:57:15 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=420.387928ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2006--- PASS: TestConnectWaitsForAPeerMigration (5.18s)20072026/10/06 19:57:16 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=780.96309ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20082026/10/06 19:57:16 INFO Aborted multipart uploads count=1 kept=020092026/10/06 19:57:16 INFO Received cleanup request method=DELETE path=/api/pending_closures20102026/10/06 19:57:16 INFO Aborted multipart uploads count=1 kept=02011--- PASS: TestPendingCleanupUsesOneCutoff (6.65s)20122026/10/06 19:57:16 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.497912172s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20132026/10/06 19:57:18 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"20142026/10/06 19:57:18 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20152026/10/06 19:57:18 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=187.479644ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20162026/10/06 19:57:18 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=427.348899ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20172026/10/06 19:57:19 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=756.392472ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20182026/10/06 19:57:19 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.518423449s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20192026/10/06 19:57:21 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20202026/10/06 19:57:21 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=186.871547ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20212026/10/06 19:57:21 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=402.298355ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20222026/10/06 19:57:22 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=800.133634ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20232026/10/06 19:57:22 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.64972162s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2024--- PASS: TestClientErrorHandling (0.00s)2025 --- PASS: TestClientErrorHandling/InvalidStorePath (0.66s)2026 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.74s)2027 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.79s)2028PASS2029{"timestamp":"2026-10-06T19:57:24.499762131Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:44428","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(390)"}20302026-10-06 19:57:24.873 UTC [130] LOG: received smart shutdown request20312026-10-06 19:57:24.878 UTC [130] LOG: background worker "logical replication launcher" (PID 140) exited with exit code 120322026-10-06 19:57:24.890 UTC [135] LOG: shutting down20332026-10-06 19:57:24.891 UTC [135] LOG: checkpoint starting: shutdown immediate20342026-10-06 19:57:26.682 UTC [135] LOG: checkpoint complete: wrote 11255 buffers (68.7%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 28 recycled; write=0.256 s, sync=1.472 s, total=1.792 s; sync files=32011, longest=0.004 s, average=0.001 s; distance=453587 kB, estimate=453587 kB; lsn=0/1D25A970, redo lsn=0/1D25A97020352026-10-06 19:57:26.747 UTC [130] LOG: database system is shut down2036Running OIDC tests...2037=== RUN TestAudienceForIssuer2038=== PAUSE TestAudienceForIssuer2039=== RUN TestGlobMatch2040=== PAUSE TestGlobMatch2041=== RUN TestValidateToken_ValidToken2042=== PAUSE TestValidateToken_ValidToken2043=== RUN TestValidateToken_WrongAudience2044=== PAUSE TestValidateToken_WrongAudience2045=== RUN TestValidateToken_Expired2046=== PAUSE TestValidateToken_Expired2047=== RUN TestValidateToken_BoundClaimsMismatch2048=== PAUSE TestValidateToken_BoundClaimsMismatch2049=== RUN TestValidateToken_BoundSubjectMismatch2050=== PAUSE TestValidateToken_BoundSubjectMismatch2051=== RUN TestValidateToken_MultipleProviders2052=== PAUSE TestValidateToken_MultipleProviders2053=== RUN TestValidateToken_NoMatchingProvider2054=== PAUSE TestValidateToken_NoMatchingProvider2055=== RUN TestValidateToken_KubernetesServiceAccount2056=== PAUSE TestValidateToken_KubernetesServiceAccount2057=== RUN TestNewValidator_KubernetesRequiresCA2058=== PAUSE TestNewValidator_KubernetesRequiresCA2059=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2060=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2061=== RUN TestPins_ReservedForMatchingRule2062=== PAUSE TestPins_ReservedForMatchingRule2063=== RUN TestPins_TopLevelShorthand2064=== PAUSE TestPins_TopLevelShorthand2065=== RUN TestPins_ConfigValidation2066=== PAUSE TestPins_ConfigValidation2067=== RUN TestScopes_LegacyProviderDefaultsToWrite2068=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2069=== RUN TestScopes_Rules2070=== PAUSE TestScopes_Rules2071=== RUN TestScopes_ConfigValidation2072=== PAUSE TestScopes_ConfigValidation2073=== CONT TestAudienceForIssuer2074=== CONT TestValidateToken_KubernetesServiceAccount2075--- PASS: TestAudienceForIssuer (0.00s)2076=== CONT TestValidateToken_Expired2077=== CONT TestValidateToken_WrongAudience2078=== CONT TestValidateToken_ValidToken2079=== CONT TestGlobMatch2080=== RUN TestGlobMatch/foo_foo2081=== PAUSE TestGlobMatch/foo_foo2082=== RUN TestGlobMatch/foo_bar2083=== PAUSE TestGlobMatch/foo_bar2084=== RUN TestGlobMatch/*_2085=== PAUSE TestGlobMatch/*_2086=== RUN TestGlobMatch/*_anything2087=== PAUSE TestGlobMatch/*_anything2088=== RUN TestGlobMatch/foo*_foo2089=== PAUSE TestGlobMatch/foo*_foo2090=== RUN TestGlobMatch/foo*_foobar2091=== PAUSE TestGlobMatch/foo*_foobar2092=== RUN TestGlobMatch/foo*_bar2093=== PAUSE TestGlobMatch/foo*_bar2094=== RUN TestGlobMatch/*bar_bar2095=== PAUSE TestGlobMatch/*bar_bar2096=== RUN TestGlobMatch/*bar_foobar2097=== PAUSE TestGlobMatch/*bar_foobar2098=== RUN TestGlobMatch/*bar_foo2099=== PAUSE TestGlobMatch/*bar_foo2100=== RUN TestGlobMatch/foo*bar_foobar2101=== PAUSE TestGlobMatch/foo*bar_foobar2102=== RUN TestGlobMatch/foo*bar_foo123bar2103=== PAUSE TestGlobMatch/foo*bar_foo123bar2104=== RUN TestGlobMatch/foo*bar_foobarbaz2105=== PAUSE TestGlobMatch/foo*bar_foobarbaz2106=== RUN TestGlobMatch/*/*_foo/bar2107=== PAUSE TestGlobMatch/*/*_foo/bar2108=== RUN TestGlobMatch/*/*_foo2109=== PAUSE TestGlobMatch/*/*_foo2110=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2111=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2112=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02113=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02114=== RUN TestGlobMatch/refs/*/main_refs/heads/main2115=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2116=== RUN TestGlobMatch/fo?_foo2117=== PAUSE TestGlobMatch/fo?_foo2118=== RUN TestGlobMatch/fo?_fo2119=== PAUSE TestGlobMatch/fo?_fo2120=== RUN TestGlobMatch/fo?_fooo2121=== PAUSE TestGlobMatch/fo?_fooo2122=== RUN TestGlobMatch/?oo_foo2123=== PAUSE TestGlobMatch/?oo_foo2124=== RUN TestGlobMatch/?oo_boo2125=== PAUSE TestGlobMatch/?oo_boo2126=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2127=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2128=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2129=== CONT TestScopes_Rules2130=== CONT TestValidateToken_BoundClaimsMismatch2131=== CONT TestValidateToken_NoMatchingProvider2132=== CONT TestScopes_ConfigValidation2133=== CONT TestValidateToken_MultipleProviders2134=== CONT TestPins_ReservedForMatchingRule2135=== CONT TestValidateToken_BoundSubjectMismatch2136=== CONT TestPins_TopLevelShorthand2137=== CONT TestNewValidator_KubernetesRequiresCA2138=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2139=== CONT TestScopes_LegacyProviderDefaultsToWrite2140=== CONT TestPins_ConfigValidation2141--- PASS: TestPins_ConfigValidation (0.00s)2142=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2143=== CONT TestGlobMatch/foo_foo2144--- PASS: TestScopes_ConfigValidation (0.00s)2145=== CONT TestGlobMatch/*/*_foo/bar2146=== CONT TestGlobMatch/fo?_foo2147=== CONT TestGlobMatch/*bar_foo2148=== CONT TestGlobMatch/*bar_foobar2149=== CONT TestGlobMatch/foo*_foo2150=== CONT TestGlobMatch/foo*_bar2151=== CONT TestGlobMatch/foo*_foobar2152=== CONT TestGlobMatch/?oo_boo2153=== CONT TestGlobMatch/refs/*/main_refs/heads/main2154=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02155=== CONT TestGlobMatch/*_2156=== CONT TestGlobMatch/*_anything2157=== CONT TestGlobMatch/foo_bar2158=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2159=== CONT TestGlobMatch/?oo_foo2160=== CONT TestGlobMatch/*/*_foo2161=== CONT TestGlobMatch/*bar_bar2162=== CONT TestGlobMatch/foo*bar_foobarbaz2163=== CONT TestGlobMatch/foo*bar_foo123bar2164=== CONT TestGlobMatch/fo?_fo2165=== CONT TestGlobMatch/foo*bar_foobar2166=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2167=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2168=== CONT TestGlobMatch/fo?_fooo2169--- PASS: TestGlobMatch (0.00s)2170 --- PASS: TestGlobMatch/foo_foo (0.00s)2171 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2172 --- PASS: TestGlobMatch/fo?_foo (0.00s)2173 --- PASS: TestGlobMatch/*bar_foo (0.00s)2174 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2175 --- PASS: TestGlobMatch/foo*_foo (0.00s)2176 --- PASS: TestGlobMatch/foo*_bar (0.00s)2177 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2178 --- PASS: TestGlobMatch/?oo_boo (0.00s)2179 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2180 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2181 --- PASS: TestGlobMatch/*_ (0.00s)2182 --- PASS: TestGlobMatch/*_anything (0.00s)2183 --- PASS: TestGlobMatch/foo_bar (0.00s)2184 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2185 --- PASS: TestGlobMatch/?oo_foo (0.00s)2186 --- PASS: TestGlobMatch/*/*_foo (0.00s)2187 --- PASS: TestGlobMatch/*bar_bar (0.00s)2188 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2189 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2190 --- PASS: TestGlobMatch/fo?_fo (0.00s)2191 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2192 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2193 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2194 --- PASS: TestGlobMatch/fo?_fooo (0.00s)21952026/10/06 19:57:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34353/oidc21962026/10/06 19:57:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35117/oidc2197--- PASS: TestPins_TopLevelShorthand (0.02s)2198--- PASS: TestValidateToken_WrongAudience (0.03s)21992026/10/06 19:57:29 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232200--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.04s)22012026/10/06 19:57:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39765/oidc2202--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.04s)22032026/10/06 19:57:29 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:38563/oidc2204--- PASS: TestValidateToken_NoMatchingProvider (0.05s)22052026/10/06 19:57:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46435/oidc2206--- PASS: TestValidateToken_BoundSubjectMismatch (0.06s)22072026/10/06 19:57:29 http: TLS handshake error from 127.0.0.1:58806: remote error: tls: bad certificate2208--- PASS: TestNewValidator_KubernetesRequiresCA (0.06s)22092026/10/06 19:57:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35029/oidc2210--- PASS: TestValidateToken_BoundClaimsMismatch (0.08s)22112026/10/06 19:57:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38921/oidc2212--- PASS: TestValidateToken_Expired (0.08s)22132026/10/06 19:57:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41891/oidc2214--- PASS: TestScopes_Rules (0.09s)22152026/10/06 19:57:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44799/oidc2216--- PASS: TestValidateToken_ValidToken (0.10s)22172026/10/06 19:57:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44227/oidc2218--- PASS: TestPins_ReservedForMatchingRule (0.10s)22192026/10/06 19:57:29 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:429172220--- PASS: TestValidateToken_KubernetesServiceAccount (0.13s)22212026/10/06 19:57:29 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:46585/oidc22222026/10/06 19:57:29 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:43593/oidc2223--- PASS: TestValidateToken_MultipleProviders (0.16s)2224PASS2225Running hook tests...2226=== RUN TestSendPathsEmpty2227=== PAUSE TestSendPathsEmpty2228=== RUN TestQueueEnqueueAndFetch2229=== PAUSE TestQueueEnqueueAndFetch2230=== RUN TestQueueDeduplication2231=== PAUSE TestQueueDeduplication2232=== RUN TestQueueRemove2233=== PAUSE TestQueueRemove2234=== RUN TestQueueFetchBatchLimit2235=== PAUSE TestQueueFetchBatchLimit2236=== RUN TestQueueRetryMovesToBack2237=== PAUSE TestQueueRetryMovesToBack2238=== RUN TestQueueFetchRemoveLifecycle2239=== PAUSE TestQueueFetchRemoveLifecycle2240=== RUN TestQueueConcurrentWriters2241=== PAUSE TestQueueConcurrentWriters2242=== RUN TestQueueRemoveLargeClosure2243=== PAUSE TestQueueRemoveLargeClosure2244=== RUN TestServerClientIntegration2245=== PAUSE TestServerClientIntegration2246=== RUN TestServerQueueError2247=== PAUSE TestServerQueueError2248=== RUN TestGetListenerSocketActivation2249 server_test.go:210: === RUN TestGetListenerSocketActivation2250 --- PASS: TestGetListenerSocketActivation (0.00s)2251 PASS2252 2253--- PASS: TestGetListenerSocketActivation (0.01s)2254=== RUN TestDrainIsolatesPoisonPath2255=== PAUSE TestDrainIsolatesPoisonPath2256=== RUN TestRunNotBlockedByPoisonHead2257=== PAUSE TestRunNotBlockedByPoisonHead2258=== RUN TestDrainGivesUpWhenServerDown2259=== PAUSE TestDrainGivesUpWhenServerDown2260=== RUN TestFailedPathPrunedByLaterClosure2261=== PAUSE TestFailedPathPrunedByLaterClosure2262=== RUN TestWorkerUploadsAndRemoves2263=== PAUSE TestWorkerUploadsAndRemoves2264=== RUN TestWorkerSkipsGCdPaths2265=== PAUSE TestWorkerSkipsGCdPaths2266=== RUN TestWorkerPrunesClosureDeps2267=== PAUSE TestWorkerPrunesClosureDeps2268=== RUN TestDrainTimeout2269=== PAUSE TestDrainTimeout2270=== CONT TestSendPathsEmpty2271=== CONT TestServerQueueError2272--- PASS: TestSendPathsEmpty (0.00s)2273=== CONT TestServerClientIntegration2274=== CONT TestQueueRemoveLargeClosure2275=== CONT TestQueueConcurrentWriters22762026/10/06 19:57:29 ERROR Failed to queue paths error="permission denied" count=12277=== CONT TestQueueFetchRemoveLifecycle2278=== CONT TestQueueRetryMovesToBack2279=== CONT TestQueueFetchBatchLimit2280=== CONT TestQueueRemove2281=== CONT TestQueueDeduplication2282--- PASS: TestServerQueueError (0.00s)2283=== CONT TestWorkerUploadsAndRemoves2284=== CONT TestDrainTimeout2285=== CONT TestQueueEnqueueAndFetch2286=== CONT TestWorkerPrunesClosureDeps2287=== CONT TestDrainGivesUpWhenServerDown2288=== CONT TestWorkerSkipsGCdPaths2289=== CONT TestFailedPathPrunedByLaterClosure2290=== CONT TestDrainIsolatesPoisonPath2291=== CONT TestRunNotBlockedByPoisonHead2292--- PASS: TestServerClientIntegration (0.00s)22932026/10/06 19:57:29 INFO Upload queue status pending=222942026/10/06 19:57:29 INFO Uploading batch count=222952026/10/06 19:57:29 INFO Uploading batch count=422962026/10/06 19:57:29 ERROR Upload failed error="upload failed" count=422972026/10/06 19:57:29 INFO Uploading batch count=222982026/10/06 19:57:29 INFO Uploading batch count=122992026/10/06 19:57:29 ERROR Upload failed error="upload failed" count=123002026/10/06 19:57:29 INFO Uploading batch count=223012026/10/06 19:57:29 INFO Upload queue status pending=223022026/10/06 19:57:29 ERROR Upload failed error="upload failed" count=223032026/10/06 19:57:29 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3657865872/002/a23042026/10/06 19:57:29 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath4094308363/002/bbb2305--- PASS: TestQueueFetchRemoveLifecycle (0.02s)23062026/10/06 19:57:29 INFO Uploading batch count=123072026/10/06 19:57:29 INFO Upload queue status pending=22308--- PASS: TestQueueFetchBatchLimit (0.02s)23092026/10/06 19:57:29 INFO Upload queue status pending=32310--- PASS: TestQueueEnqueueAndFetch (0.02s)23112026/10/06 19:57:29 INFO Uploading batch count=12312--- PASS: TestQueueDeduplication (0.02s)23132026/10/06 19:57:29 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths123384919/002/nonexistent23142026/10/06 19:57:29 INFO Uploading batch count=123152026/10/06 19:57:29 ERROR Upload failed error="upload failed" count=123162026/10/06 19:57:29 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3657865872/002/b23172026/10/06 19:57:29 INFO Uploading batch count=123182026/10/06 19:57:29 INFO Uploading batch count=12319--- PASS: TestQueueRemove (0.02s)2320--- PASS: TestQueueRetryMovesToBack (0.02s)23212026/10/06 19:57:29 INFO Uploading batch count=123222026/10/06 19:57:29 ERROR Upload failed error="upload failed" count=123232026/10/06 19:57:29 INFO Uploading batch count=223242026/10/06 19:57:29 ERROR Upload failed error="upload failed" count=223252026/10/06 19:57:29 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3657865872/002/c23262026/10/06 19:57:29 INFO Uploading batch count=123272026/10/06 19:57:29 ERROR Upload failed error="upload failed" count=123282026/10/06 19:57:29 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3657865872/002/d23292026/10/06 19:57:29 INFO Uploading batch count=123302026/10/06 19:57:29 ERROR Upload failed error="upload failed" count=12331--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)23322026/10/06 19:57:29 INFO Uploading batch count=223332026/10/06 19:57:29 ERROR Upload failed error="upload failed" count=223342026/10/06 19:57:29 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3657865872/002/e23352026/10/06 19:57:29 ERROR Drain finished with paths left in queue remaining=123362026/10/06 19:57:29 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3657865872/002/f23372026/10/06 19:57:29 ERROR Drain finished with paths left in queue remaining=102338--- PASS: TestDrainIsolatesPoisonPath (0.03s)2339--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2340--- PASS: TestWorkerPrunesClosureDeps (0.04s)2341--- PASS: TestWorkerUploadsAndRemoves (0.04s)2342--- PASS: TestWorkerSkipsGCdPaths (0.04s)2343--- PASS: TestQueueRemoveLargeClosure (0.06s)23442026/10/06 19:57:29 ERROR Upload failed error="context deadline exceeded" count=223452026/10/06 19:57:29 ERROR Drain finished with paths left in queue remaining=42346--- PASS: TestDrainTimeout (0.22s)2347--- PASS: TestQueueConcurrentWriters (0.28s)23482026/10/06 19:57:30 INFO Uploading batch count=123492026/10/06 19:57:30 INFO Uploading batch count=123502026/10/06 19:57:30 INFO Uploading batch count=123512026/10/06 19:57:30 ERROR Upload failed error="upload failed" count=123522026/10/06 19:57:30 INFO Uploading batch count=123532026/10/06 19:57:30 ERROR Upload failed error="upload failed" count=123542026/10/06 19:57:30 INFO Uploading batch count=123552026/10/06 19:57:30 ERROR Upload failed error="upload failed" count=123562026/10/06 19:57:30 INFO Uploading batch count=123572026/10/06 19:57:30 ERROR Upload failed error="upload failed" count=123582026/10/06 19:57:30 ERROR Drain finished with paths left in queue remaining=12359--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2360PASS2361Running signing tests...2362=== RUN TestExternalSigner2363=== PAUSE TestExternalSigner2364=== RUN TestExternalSignerWrongPublicKey2365=== PAUSE TestExternalSignerWrongPublicKey2366=== RUN TestExternalSignerErrors2367=== PAUSE TestExternalSignerErrors2368=== RUN TestExternalSignerRestartsAfterCrash2369=== PAUSE TestExternalSignerRestartsAfterCrash2370=== RUN TestExternalSignerProgramErrorKeepsProcess2371=== PAUSE TestExternalSignerProgramErrorKeepsProcess2372=== RUN TestExternalSignerClose2373=== PAUSE TestExternalSignerClose2374=== RUN TestExternalSignerRejectsInvalidPublicKey2375=== PAUSE TestExternalSignerRejectsInvalidPublicKey2376=== RUN TestExternalSignerCancellation2377=== PAUSE TestExternalSignerCancellation2378=== RUN TestGenerateFingerprint2379=== PAUSE TestGenerateFingerprint2380=== RUN TestParseSigningKey2381=== PAUSE TestParseSigningKey2382=== RUN TestSign2383=== PAUSE TestSign2384=== RUN TestSignBatch2385=== PAUSE TestSignBatch2386=== RUN TestNilKeyPublicKey2387=== PAUSE TestNilKeyPublicKey2388=== RUN TestSignErrors2389=== PAUSE TestSignErrors2390=== CONT TestExternalSigner2391=== CONT TestExternalSignerProgramErrorKeepsProcess2392=== CONT TestExternalSignerCancellation2393=== CONT TestExternalSignerRejectsInvalidPublicKey2394=== CONT TestExternalSignerClose2395=== CONT TestExternalSignerRestartsAfterCrash2396=== CONT TestSignBatch2397=== CONT TestSignErrors2398=== CONT TestNilKeyPublicKey2399=== CONT TestExternalSignerWrongPublicKey2400=== CONT TestParseSigningKey2401=== RUN TestParseSigningKey/valid_32-byte_key2402=== PAUSE TestParseSigningKey/valid_32-byte_key2403=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2404=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2405=== CONT TestSign2406=== RUN TestSignErrors/nil_key2407=== PAUSE TestSignErrors/nil_key2408=== RUN TestSignErrors/nil_narinfo2409=== PAUSE TestSignErrors/nil_narinfo2410=== CONT TestGenerateFingerprint2411=== CONT TestExternalSignerErrors2412=== RUN TestGenerateFingerprint/basic_with_references2413=== PAUSE TestGenerateFingerprint/basic_with_references2414=== RUN TestExternalSignerRejectsInvalidPublicKey/#002415=== RUN TestParseSigningKey/no_colon2416=== PAUSE TestParseSigningKey/no_colon2417--- PASS: TestNilKeyPublicKey (0.00s)2418=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002419=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2420=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2421=== RUN TestGenerateFingerprint/no_references2422=== PAUSE TestGenerateFingerprint/no_references2423--- PASS: TestSign (0.00s)2424--- PASS: TestSignBatch (0.00s)2425=== RUN TestExternalSignerErrors/exit_on_request2426=== RUN TestParseSigningKey/empty_name2427=== PAUSE TestParseSigningKey/empty_name2428=== RUN TestParseSigningKey/invalid_base642429=== PAUSE TestParseSigningKey/invalid_base642430=== RUN TestParseSigningKey/wrong_length2431=== PAUSE TestParseSigningKey/wrong_length2432=== RUN TestSignErrors/invalid_narinfo2433=== PAUSE TestSignErrors/invalid_narinfo2434=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2435=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2436=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2437=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2438=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2439=== PAUSE TestExternalSignerErrors/exit_on_request2440=== RUN TestExternalSignerErrors/missing_signatures2441=== PAUSE TestExternalSignerErrors/missing_signatures2442=== RUN TestExternalSignerErrors/too_few_signatures2443=== PAUSE TestExternalSignerErrors/too_few_signatures2444=== CONT TestParseSigningKey/valid_32-byte_key2445=== CONT TestParseSigningKey/wrong_length2446=== CONT TestParseSigningKey/invalid_base642447=== CONT TestParseSigningKey/empty_name2448=== CONT TestParseSigningKey/no_colon2449=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2450--- PASS: TestParseSigningKey (0.00s)2451 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2452 --- PASS: TestParseSigningKey/wrong_length (0.00s)2453 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2454 --- PASS: TestParseSigningKey/empty_name (0.00s)2455 --- PASS: TestParseSigningKey/no_colon (0.00s)2456 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2457=== RUN TestSignErrors/canceled2458=== PAUSE TestSignErrors/canceled2459=== CONT TestSignErrors/nil_key2460=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2461=== CONT TestSignErrors/invalid_narinfo2462=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2463=== RUN TestExternalSignerErrors/exit_at_startup2464=== CONT TestSignErrors/nil_narinfo2465--- PASS: TestExternalSignerClose (0.00s)2466=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2467=== CONT TestSignErrors/canceled2468--- PASS: TestSignErrors (0.00s)2469 --- PASS: TestSignErrors/nil_key (0.00s)2470 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2471 --- PASS: TestSignErrors/nil_narinfo (0.00s)2472 --- PASS: TestSignErrors/canceled (0.00s)2473=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2474=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2475=== CONT TestExternalSignerRejectsInvalidPublicKey/#002476=== PAUSE TestExternalSignerErrors/exit_at_startup2477=== RUN TestExternalSignerErrors/wrong_signature_name2478=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2479=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2480=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2481=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2482--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2483 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2484 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2485 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2486 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2487 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2488=== RUN TestGenerateFingerprint/invalid_nar_hash_length2489=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2490=== RUN TestGenerateFingerprint/invalid_store_path_prefix2491=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2492=== RUN TestGenerateFingerprint/invalid_reference_prefix2493=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2494=== CONT TestGenerateFingerprint/basic_with_references2495=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2496=== PAUSE TestExternalSignerErrors/wrong_signature_name2497=== RUN TestExternalSignerErrors/invalid_signature_base642498=== CONT TestGenerateFingerprint/invalid_nar_hash_length2499=== CONT TestGenerateFingerprint/invalid_reference_prefix2500=== CONT TestGenerateFingerprint/invalid_store_path_prefix2501=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2502=== CONT TestGenerateFingerprint/no_references2503--- PASS: TestGenerateFingerprint (0.00s)2504 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2505 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2506 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2507 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2508 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2509 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2510 --- PASS: TestGenerateFingerprint/no_references (0.00s)2511=== PAUSE TestExternalSignerErrors/invalid_signature_base642512=== RUN TestExternalSignerErrors/invalid_JSON2513=== PAUSE TestExternalSignerErrors/invalid_JSON2514=== RUN TestExternalSignerErrors/wrong_shape2515=== PAUSE TestExternalSignerErrors/wrong_shape2516=== RUN TestExternalSignerErrors/null2517=== PAUSE TestExternalSignerErrors/null2518=== RUN TestExternalSignerErrors/wrong_signatures_shape2519=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2520=== RUN TestExternalSignerErrors/unrequested_key2521=== PAUSE TestExternalSignerErrors/unrequested_key2522=== RUN TestExternalSignerErrors/wrong_signature_length2523=== PAUSE TestExternalSignerErrors/wrong_signature_length2524=== RUN TestExternalSignerErrors/program_error2525=== PAUSE TestExternalSignerErrors/program_error2526=== RUN TestExternalSignerErrors/wrong_id2527=== PAUSE TestExternalSignerErrors/wrong_id2528=== RUN TestExternalSignerErrors/null_signatures2529=== PAUSE TestExternalSignerErrors/null_signatures2530--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.01s)2531--- PASS: TestExternalSignerWrongPublicKey (0.00s)2532=== RUN TestExternalSignerErrors/missing_signature_name2533=== PAUSE TestExternalSignerErrors/missing_signature_name2534=== CONT TestExternalSignerErrors/exit_on_request2535=== CONT TestExternalSignerErrors/wrong_shape2536=== CONT TestExternalSignerErrors/unrequested_key2537=== CONT TestExternalSignerErrors/null2538=== CONT TestExternalSignerErrors/missing_signature_name2539=== CONT TestExternalSignerErrors/null_signatures2540=== CONT TestExternalSignerErrors/wrong_id2541=== CONT TestExternalSignerErrors/program_error2542=== CONT TestExternalSignerErrors/wrong_signature_name2543=== CONT TestExternalSignerErrors/wrong_signature_length2544=== CONT TestExternalSignerErrors/wrong_signatures_shape2545=== CONT TestExternalSignerErrors/too_few_signatures2546=== CONT TestExternalSignerErrors/invalid_JSON2547=== CONT TestExternalSignerErrors/exit_at_startup2548=== CONT TestExternalSignerErrors/missing_signatures2549=== CONT TestExternalSignerErrors/invalid_signature_base642550--- PASS: TestExternalSigner (0.01s)2551--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2552--- PASS: TestExternalSignerErrors (0.00s)2553 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2554 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)2555 --- PASS: TestExternalSignerErrors/unrequested_key (0.00s)2556 --- PASS: TestExternalSignerErrors/program_error (0.00s)2557 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.00s)2558 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2559 --- PASS: TestExternalSignerErrors/null (0.01s)2560 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2561 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2562 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2563 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2564 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2565 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2566 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2567 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2568 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2569--- PASS: TestExternalSignerCancellation (0.02s)2570PASS2571Running OpenBao signer tests...2572=== RUN TestSign2573=== PAUSE TestSign2574=== RUN TestSignErrors2575=== PAUSE TestSignErrors2576=== RUN TestServe2577=== PAUSE TestServe2578=== RUN TestServeRejectsGarbage2579=== PAUSE TestServeRejectsGarbage2580=== CONT TestSign2581=== CONT TestServe2582=== CONT TestSignErrors2583=== CONT TestServeRejectsGarbage2584=== RUN TestSignErrors/http_error2585=== PAUSE TestSignErrors/http_error2586--- PASS: TestServeRejectsGarbage (0.00s)2587=== RUN TestSignErrors/invalid_json2588=== PAUSE TestSignErrors/invalid_json2589--- PASS: TestServe (0.00s)2590=== RUN TestSignErrors/no_prefix2591=== PAUSE TestSignErrors/no_prefix2592=== RUN TestSignErrors/invalid_base642593=== PAUSE TestSignErrors/invalid_base642594=== CONT TestSignErrors/http_error2595=== CONT TestSignErrors/invalid_base642596=== CONT TestSignErrors/no_prefix2597=== CONT TestSignErrors/invalid_json2598--- PASS: TestSign (0.00s)2599--- PASS: TestSignErrors (0.00s)2600 --- PASS: TestSignErrors/no_prefix (0.00s)2601 --- PASS: TestSignErrors/invalid_json (0.00s)2602 --- PASS: TestSignErrors/http_error (0.00s)2603 --- PASS: TestSignErrors/invalid_base64 (0.00s)2604PASS