nixbot

builds

succeeded niks3-go-unit-tests checks.aarch64-linux.go-unit-tests · build #385 · raw

1tribuchet: building on eliza2Running 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 TestScriptTokenScriptFails100=== CONT TestDoServerRequestAttachesToken101=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess102=== CONT TestRateLimiterFeedback103=== RUN TestRateLimiterFeedback/429_enables_limiter104=== PAUSE TestRateLimiterFeedback/429_enables_limiter105=== RUN TestRateLimiterFeedback/503_enables_limiter106=== PAUSE TestRateLimiterFeedback/503_enables_limiter107=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter108=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter109=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter110=== CONT TestPathInfoCACompatibility111=== RUN TestPathInfoCACompatibility/null_ca_field112=== PAUSE TestPathInfoCACompatibility/null_ca_field113=== RUN TestPathInfoCACompatibility/old_string_format_-_text114=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text1152026/10/06 21:19:20 WARN Rate limiter enabled after throttle name=server-test rate=5116=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive117=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive118=== RUN TestPathInfoCACompatibility/new_structured_format_-_text119=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text120=== CONT TestParsePathInfoJSONMultiplePaths121=== CONT TestParsePathInfoJSON122=== CONT TestPathInfoHashCompatibility123=== CONT TestGetStorePathHash124=== CONT TestConvertHashToNix32125=== CONT TestEncodeNixBase32WithRealHash126=== CONT TestEncodeNixBase32127=== CONT TestDumpPathWriterError128=== CONT TestDumpPathSingleFile129=== CONT TestResolveStorePath130=== CONT TestScriptTokenBadJSON131=== CONT TestScriptTokenEmptyToken132=== CONT TestScriptTokenCachesUntilRefresh133=== CONT TestDumpPathMatchesNix134=== CONT TestScriptTokenNoExpiryRerunsEveryCall135=== CONT TestUploadMultipart_SupersededByPeer136=== CONT TestFileTokenEmpty137=== CONT TestPartSizeForNAR138=== CONT TestScriptTokenEmptyCommand139=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter140=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)141=== RUN TestParsePathInfoJSON/Nix_format142--- PASS: TestScriptTokenScriptFails (0.00s)143=== CONT TestFileTokenReadsAndCaches144=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)145=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon146=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon147=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths148=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths149=== RUN TestUploadMultipart_SupersededByPeer/exists150--- PASS: TestEncodeNixBase32WithRealHash (0.00s)151--- PASS: TestScriptTokenEmptyCommand (0.00s)152=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method153=== CONT TestUploadMultipart_PartsInParallel154=== CONT TestStaticToken155=== PAUSE TestUploadMultipart_SupersededByPeer/exists156=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI157=== CONT TestFileTokenMissing158--- PASS: TestFileTokenEmpty (0.00s)159=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method160=== PAUSE TestParsePathInfoJSON/Nix_format161=== RUN TestParsePathInfoJSON/Lix_format162=== RUN TestGetStorePathHash/valid_store_path163=== CONT TestSetClientTLSDoesNotMutateDefaultTransport164=== PAUSE TestGetStorePathHash/valid_store_path165=== CONT TestSetClientTLSErrors166=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun167=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths168=== RUN TestPartSizeForNAR/zero_stays_at_minimum169=== RUN TestUploadMultipart_SupersededByPeer/missing170=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI171=== RUN TestEncodeNixBase32/test_string_hash172--- PASS: TestFileTokenReadsAndCaches (0.00s)173=== CONT TestCaseHackSuffix174=== PAUSE TestParsePathInfoJSON/Lix_format175=== CONT TestFilterOversizedClosures176=== RUN TestConvertHashToNix32/SRI_format_to_Nix32177=== RUN TestGetStorePathHash/basename_without_hyphen_should_error178=== RUN TestSetClientTLSErrors/missing_cert_file179=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica180=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths181=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error182=== CONT TestClientSignaturesByStorePath183=== CONT TestRegisterUploadedObjectReusesConnections184=== CONT TestStreamPushReportsSignatures185=== CONT TestStreamPushReportsEveryPath186=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32187=== RUN TestConvertHashToNix32/already_Nix32_format188=== CONT TestStreamPushGivesUpOnDeadServer189=== PAUSE TestConvertHashToNix32/already_Nix32_format190=== RUN TestConvertHashToNix32/invalid_format191=== PAUSE TestConvertHashToNix32/invalid_format192=== PAUSE TestSetClientTLSErrors/missing_cert_file193=== RUN TestSetClientTLSErrors/missing_key_file194=== PAUSE TestSetClientTLSErrors/missing_key_file195=== RUN TestSetClientTLSErrors/missing_ca_file196=== PAUSE TestSetClientTLSErrors/missing_ca_file197=== RUN TestSetClientTLSErrors/invalid_ca_file198=== PAUSE TestSetClientTLSErrors/invalid_ca_file199=== CONT TestShellSplit200=== CONT TestShellSplitErrors201=== CONT TestDoWithRetry_BodyReplayedViaGetBody202=== PAUSE TestUploadMultipart_SupersededByPeer/missing203=== CONT TestStreamPushRequestLine204=== PAUSE TestEncodeNixBase32/test_string_hash205=== RUN TestEncodeNixBase32/empty_input206=== PAUSE TestEncodeNixBase32/empty_input207=== CONT TestStreamPushIsolatesFailures208--- PASS: TestStaticToken (0.00s)209--- PASS: TestFileTokenMissing (0.00s)210--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)211--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)212--- PASS: TestClientSignaturesByStorePath (0.00s)213--- PASS: TestResolveStorePath (0.03s)214--- PASS: TestDoServerRequestAttachesToken (0.03s)215=== CONT TestStreamPushBatchesUnderLoad2162026/10/06 21:19:20 ERROR Upload failed error="connection refused" count=202172026/10/06 21:19:20 ERROR Server seems unavailable, giving up on batch untried=172182026/10/06 21:19:20 ERROR Upload failed error="bad path" count=3219--- PASS: TestStreamPushReportsEveryPath (0.00s)220--- PASS: TestStreamPushIsolatesFailures (0.00s)221--- PASS: TestShellSplit (0.00s)222--- PASS: TestShellSplitErrors (0.00s)223--- PASS: TestScriptTokenBadJSON (0.03s)224--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)225--- PASS: TestScriptTokenEmptyToken (0.03s)226=== CONT TestRateLimiterFeedback/503_enables_limiter2272026/10/06 21:19:20 INFO Garbage collection started2282026/10/06 21:19:20 INFO Garbage collection started229=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter2302026/10/06 21:19:20 WARN Rate limiter enabled after throttle name=server-test rate=5231=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter2322026/10/06 21:19:20 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:41557233--- PASS: TestDumpPathSingleFile (0.03s)2342026/10/06 21:19:20 ERROR Upload failed error=boom count=1235=== CONT TestPathInfoCACompatibility/null_ca_field236=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum237=== RUN TestPartSizeForNAR/small_stays_at_minimum238=== PAUSE TestPartSizeForNAR/small_stays_at_minimum239=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum240=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum241=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts2422026/10/06 21:19:20 WARN Rate limiter backed off name=server-test rate=5243=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts2442026/10/06 21:19:20 WARN Rate limiter enabled after throttle name=server-test rate=5245=== RUN TestPartSizeForNAR/1_TiB246=== PAUSE TestPartSizeForNAR/1_TiB2472026/10/06 21:19:20 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:40725248=== RUN TestPartSizeForNAR/5_TiB_S3_max_object2492026/10/06 21:19:20 ERROR Upload failed error=boom count=1250=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object2512026/10/06 21:19:20 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:41557252=== RUN TestPartSizeForNAR/capped_at_5_GiB253=== PAUSE TestPartSizeForNAR/capped_at_5_GiB254=== RUN TestParsePathInfoJSON/empty_input255=== PAUSE TestParsePathInfoJSON/empty_input2562026/10/06 21:19:20 WARN Rate limiter backed off name=server-test rate=5257=== RUN TestParsePathInfoJSON/whitespace_only258=== PAUSE TestParsePathInfoJSON/whitespace_only259=== RUN TestParsePathInfoJSON/invalid_JSON260=== PAUSE TestParsePathInfoJSON/invalid_JSON261=== CONT TestRateLimiterFeedback/429_enables_limiter262=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method263=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error264=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512265=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths266=== CONT TestSetClientTLSErrors/missing_cert_file267--- PASS: TestStreamPushReportsSignatures (0.01s)268=== CONT TestConvertHashToNix32/invalid_format269=== CONT TestSetClientTLSErrors/invalid_ca_file270=== CONT TestSetClientTLSErrors/missing_ca_file2712026/10/06 21:19:20 INFO Garbage collection progress phase=running_on_another_replica failed_uploads_deleted=0 old_closures_deleted=0 objects_marked=0 objects_deleted=0 objects_failed=0272=== CONT TestSetClientTLSErrors/missing_key_file273=== CONT TestEncodeNixBase32/test_string_hash274=== CONT TestUploadMultipart_SupersededByPeer/missing2752026/10/06 21:19:20 WARN Rate limiter enabled after throttle name=server-test rate=52762026/10/06 21:19:20 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:33385277=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512278=== CONT TestEncodeNixBase32/empty_input279=== CONT TestParsePathInfoJSON/Nix_format280=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum2812026/10/06 21:19:20 WARN Rate limiter backed off name=server-test rate=5282=== CONT TestPartSizeForNAR/capped_at_5_GiB283=== CONT TestPartSizeForNAR/1_TiB284=== CONT TestPartSizeForNAR/5_TiB_S3_max_object285=== CONT TestParsePathInfoJSON/whitespace_only286=== CONT TestPartSizeForNAR/small_stays_at_minimum287=== CONT TestParsePathInfoJSON/empty_input288=== CONT TestParsePathInfoJSON/Lix_format289=== CONT TestParsePathInfoJSON/invalid_JSON290=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts291=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)292--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)293=== CONT TestPartSizeForNAR/zero_stays_at_minimum294=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512295=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI296=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon297=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive298=== CONT TestConvertHashToNix32/SRI_format_to_Nix32299=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths300=== CONT TestPathInfoCACompatibility/new_structured_format_-_text301=== CONT TestPathInfoCACompatibility/old_string_format_-_text302--- PASS: TestPathInfoCACompatibility (0.00s)303 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)304 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)305 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)306 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)307 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)308--- PASS: TestParsePathInfoJSONMultiplePaths (0.03s)309 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)310 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)311=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error312=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error313=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error314=== CONT TestGetStorePathHash/valid_store_path315=== CONT TestUploadMultipart_SupersededByPeer/exists316--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)317--- PASS: TestSetClientTLSErrors (0.02s)318 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)319 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)320 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)321 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)322=== CONT TestConvertHashToNix32/already_Nix32_format323--- PASS: TestConvertHashToNix32 (0.03s)324 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)325 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)326 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)327=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error328=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error329=== CONT TestGetStorePathHash/basename_without_hyphen_should_error330--- PASS: TestGetStorePathHash (0.03s)331 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)332 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)333 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)334 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)335=== RUN TestFilterOversizedClosures/no_limit_keeps_everything336=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything337=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped338=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped339=== RUN TestFilterOversizedClosures/all_closures_skipped340=== PAUSE TestFilterOversizedClosures/all_closures_skipped341=== CONT TestFilterOversizedClosures/no_limit_keeps_everything342=== CONT TestFilterOversizedClosures/all_closures_skipped3432026/10/06 21:19:20 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50344=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3452026/10/06 21:19:20 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000346--- PASS: TestFilterOversizedClosures (0.01s)347 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)348 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)349 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)350--- PASS: TestEncodeNixBase32 (0.03s)351 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)352 --- PASS: TestEncodeNixBase32/empty_input (0.00s)353--- PASS: TestRateLimiterFeedback (0.00s)354 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)355 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)356 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)357 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)358--- PASS: TestPartSizeForNAR (0.03s)359 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)360 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)361 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)362 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)363 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)364 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)365 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)366--- PASS: TestParsePathInfoJSON (0.03s)367 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)368 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)369 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)370 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)371 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)372--- PASS: TestPathInfoHashCompatibility (0.03s)373 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)374 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)375 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)376 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)3772026/10/06 21:19:20 WARN Garbage collection finished on another replica. Its statistics are not available here378--- PASS: TestUploadMultipart_SupersededByPeer (0.03s)379 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)380 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)381--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)382--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.03s)383=== CONT TestSetClientTLS384=== RUN TestSetClientTLS/rejects_connection_without_client_cert385=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert386=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA387=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA388=== RUN TestSetClientTLS/preserves_debug_logging_transport389=== PAUSE TestSetClientTLS/preserves_debug_logging_transport390=== CONT TestSetClientTLS/rejects_connection_without_client_cert391=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA392=== CONT TestSetClientTLS/preserves_debug_logging_transport393--- PASS: TestCaseHackSuffix (0.04s)394--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)3952026/10/06 21:19:20 http: TLS handshake error from 127.0.0.1:52458: remote error: tls: bad certificate396--- PASS: TestSetClientTLS (0.02s)397 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)398 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)399 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)400--- PASS: TestStreamPushRequestLine (0.04s)401--- PASS: TestDumpPathWriterError (0.07s)402--- PASS: TestDumpPathMatchesNix (0.11s)403--- PASS: TestStreamPushBatchesUnderLoad (0.10s)404--- PASS: TestUploadMultipart_PartsInParallel (0.66s)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/postgres2165378813/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/postgres2165378813/data -l logfile start434435/build/postgres2165378813:5432 - no response4362026-10-06 21:19:22.514 UTC [128] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-06 21:19:22.514 UTC [128] LOG: listening on Unix socket "/build/postgres2165378813/.s.PGSQL.5432"4382026-10-06 21:19:22.519 UTC [135] LOG: database system was shut down at 2026-10-06 21:19:22 UTC4392026-10-06 21:19:22.522 UTC [128] LOG: database system is ready to accept connections440/build/postgres2165378813:5432 - accepting connections441{"timestamp":"2026-10-06T21:19:22.712709682Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"6216dc8a-9560-41f7-b3bd-711f818b1ad9","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(197)"}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 TestDeleteClosuresRacingPins479=== PAUSE TestDeleteClosuresRacingPins480=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock481=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock482=== RUN TestResolveDBConnectionString483=== PAUSE TestResolveDBConnectionString484=== RUN TestConnectWaitsForAPeerMigration485=== PAUSE TestConnectWaitsForAPeerMigration486=== RUN TestLeadElectsOneAndHandsOver487=== PAUSE TestLeadElectsOneAndHandsOver488=== RUN TestLeadIncumbentWinsAfterRestart4892026/10/06 21:19:22 INFO lead: acquired remote=192.0.2.1:12344902026/10/06 21:19:23 INFO lead: released remote=192.0.2.1:12344912026/10/06 21:19:23 INFO lead: acquired remote=192.0.2.1:12344922026/10/06 21:19:24 INFO lead: released remote=192.0.2.1:1234493--- PASS: TestLeadIncumbentWinsAfterRestart (1.88s)494=== RUN TestLeadIncumbentAnnouncesAtOnce495=== PAUSE TestLeadIncumbentAnnouncesAtOnce496=== RUN TestLeadEndsOnShutdown497=== PAUSE TestLeadEndsOnShutdown498=== RUN TestLeadEndsWhenItsConnectionHangs4992026/10/06 21:19:24 INFO lead: acquired remote=192.0.2.1:12345002026-10-06 21:19:26.201 UTC [382] FATAL: terminating connection due to administrator command5012026/10/06 21:19:26 INFO lead: acquired remote=192.0.2.1:12345022026/10/06 21:19:27 WARN lead: lock connection lost error="timeout: context deadline exceeded"5032026/10/06 21:19:27 INFO lead: released remote=192.0.2.1:12345042026/10/06 21:19:27 INFO lead: released remote=192.0.2.1:1234505--- PASS: TestLeadEndsWhenItsConnectionHangs (3.11s)506=== RUN TestGCAdvisoryLockBlocksConcurrentRun507=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun508=== RUN TestGCBugBareHashReferences509=== PAUSE TestGCBugBareHashReferences510=== RUN TestGCMetrics511=== PAUSE TestGCMetrics512=== RUN TestPushDedupSurvivesConcurrentGC513=== PAUSE TestPushDedupSurvivesConcurrentGC514=== RUN TestDeduplicatedObjectsRecordedAsPending515=== PAUSE TestDeduplicatedObjectsRecordedAsPending516=== RUN TestGCSweepSkipsPendingObjects517=== PAUSE TestGCSweepSkipsPendingObjects518=== RUN TestTombstonedObjectOfferedWithoutWaiting519=== PAUSE TestTombstonedObjectOfferedWithoutWaiting520=== RUN TestGCSweepDeliversEachKeyOnce521=== PAUSE TestGCSweepDeliversEachKeyOnce522=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection524=== RUN TestForceGCDuringPushOffersSweptObject525=== PAUSE TestForceGCDuringPushOffersSweptObject526=== RUN TestFailedS3DeleteKeepsTombstone527=== PAUSE TestFailedS3DeleteKeepsTombstone528=== RUN TestSweepSkipsRowsLockedByPush529=== PAUSE TestSweepSkipsRowsLockedByPush530=== RUN TestRegisterCompletedObjectNeedsPendingRow531=== PAUSE TestRegisterCompletedObjectNeedsPendingRow532=== RUN TestGetExistingObjectsLocksRows533=== PAUSE TestGetExistingObjectsLocksRows534=== RUN TestSweepRechecksPendingAfterLocking535=== PAUSE TestSweepRechecksPendingAfterLocking536=== RUN TestPushWaitsForSweepHoldingRow537=== PAUSE TestPushWaitsForSweepHoldingRow538=== RUN TestCommitRacingPendingCleanupKeepsObjects539=== PAUSE TestCommitRacingPendingCleanupKeepsObjects540=== RUN TestGCEndsOnShutdown541=== PAUSE TestGCEndsOnShutdown542=== RUN TestGCTaskStore_StartNew543=== PAUSE TestGCTaskStore_StartNew544=== RUN TestGCTaskStore_DeduplicateSameParams545=== PAUSE TestGCTaskStore_DeduplicateSameParams546=== RUN TestGCTaskStore_ConflictDifferentParams547=== PAUSE TestGCTaskStore_ConflictDifferentParams548=== RUN TestGCTaskStore_GetEmpty549=== PAUSE TestGCTaskStore_GetEmpty550=== RUN TestGCTaskStore_GetReturnsLatest551=== PAUSE TestGCTaskStore_GetReturnsLatest552=== RUN TestGCTaskStore_CompletedAllowsNewTask553=== PAUSE TestGCTaskStore_CompletedAllowsNewTask554=== RUN TestGCTaskStore_PhaseUpdates555=== PAUSE TestGCTaskStore_PhaseUpdates556=== RUN TestGCTaskStore_Fail557=== PAUSE TestGCTaskStore_Fail558=== RUN TestGracefulShutdownDrainsInflight559=== PAUSE TestGracefulShutdownDrainsInflight560=== RUN TestService_healthCheckHandler561=== PAUSE TestService_healthCheckHandler562=== RUN TestService_readinessHandler563=== PAUSE TestService_readinessHandler564=== RUN TestGenerateLandingPage565=== PAUSE TestGenerateLandingPage566=== RUN TestCacheConfigHandlerMaxNarSize567=== PAUSE TestCacheConfigHandlerMaxNarSize568=== RUN TestCreatePendingClosureRejectsOversizedNAR569=== PAUSE TestCreatePendingClosureRejectsOversizedNAR570=== RUN TestNARDeduplicationMetadataUploadBug571=== PAUSE TestNARDeduplicationMetadataUploadBug572=== RUN TestMetricsInventory573=== PAUSE TestMetricsInventory574=== RUN TestService_NativeMTLS575=== PAUSE TestService_NativeMTLS576=== RUN TestServerTLSConfig577=== PAUSE TestServerTLSConfig578=== RUN TestMultipartCleanup579=== PAUSE TestMultipartCleanup580=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded581=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded582=== RUN TestPendingCleanupUsesOneCutoff583=== PAUSE TestPendingCleanupUsesOneCutoff584=== RUN TestObjectStatsTrigger585=== PAUSE TestObjectStatsTrigger586=== RUN TestOrphanedObjectsGC587=== PAUSE TestOrphanedObjectsGC588=== RUN TestOrphanedObjectsGCStressTest589=== PAUSE TestOrphanedObjectsGCStressTest590=== RUN TestCreatePin_ReservedPins591=== PAUSE TestCreatePin_ReservedPins592=== RUN TestPresentReportsOnlyClosureRoots593=== PAUSE TestPresentReportsOnlyClosureRoots594=== RUN TestPresentRefreshesOnlyStaleClosures595=== PAUSE TestPresentRefreshesOnlyStaleClosures596=== RUN TestPresentNotReportedWhileGCDeletesClosure597=== PAUSE TestPresentNotReportedWhileGCDeletesClosure598=== RUN TestParseSingleRange599=== PAUSE TestParseSingleRange600=== RUN TestProxyHeadersOnlyTrustedOnSocket601=== PAUSE TestProxyHeadersOnlyTrustedOnSocket602=== RUN TestIsValidCachePath603=== PAUSE TestIsValidCachePath604=== RUN TestReadProxyNarinfo605=== PAUSE TestReadProxyNarinfo606=== RUN TestReadProxyNarinfoAlreadyDecompressed607=== PAUSE TestReadProxyNarinfoAlreadyDecompressed608=== RUN TestReadProxyContentNegotiation609=== PAUSE TestReadProxyContentNegotiation610=== RUN TestReadProxyNarStreaming611=== PAUSE TestReadProxyNarStreaming612=== RUN TestReadProxy404613=== PAUSE TestReadProxy404614=== RUN TestReadProxyInvalidPath615=== PAUSE TestReadProxyInvalidPath616=== RUN TestReadProxyHead617=== PAUSE TestReadProxyHead618=== RUN TestReadProxyOutlastsServerWriteTimeout619=== PAUSE TestReadProxyOutlastsServerWriteTimeout620=== RUN TestReadProxyConditionalGet621=== PAUSE TestReadProxyConditionalGet622=== RUN TestReadProxyRootRedirectsToIndexHTML623=== PAUSE TestReadProxyRootRedirectsToIndexHTML624=== RUN TestReadProxyDisabled625=== PAUSE TestReadProxyDisabled626=== RUN TestReadRedirectNar627=== PAUSE TestReadRedirectNar628=== RUN TestReadRedirectKeepsNarinfoProxied629=== PAUSE TestReadRedirectKeepsNarinfoProxied630=== RUN TestReadProxyRangeRequest631=== PAUSE TestReadProxyRangeRequest632=== RUN TestReadRedirectUsesPublicS3URL633=== PAUSE TestReadRedirectUsesPublicS3URL634=== RUN TestPush_OverlappingRootsStoreOneRowPerKey635=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey636=== RUN TestPush_CompleteCommitsEveryRoot637=== PAUSE TestPush_CompleteCommitsEveryRoot638=== RUN TestPush_RepeatedRootCommitsOnce639=== PAUSE TestPush_RepeatedRootCommitsOnce640=== RUN TestPush_CompleteWaitsForCleanupOfThePush641=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush642=== RUN TestPush_RootsAreLockedInByteOrder643=== PAUSE TestPush_RootsAreLockedInByteOrder644=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit645=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit646=== RUN TestPush_RejectsBadRequests647=== PAUSE TestPush_RejectsBadRequests648=== RUN TestPush_SignsNarinfosOfItsPendingObjects649=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects650=== RUN TestRedundantMultipartUpload651=== PAUSE TestRedundantMultipartUpload652=== RUN TestCompleteMultipartUpload_ErrorButObjectExists653=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists654=== RUN TestCompletedNarNotReofferedAcrossClosures655=== PAUSE TestCompletedNarNotReofferedAcrossClosures656=== RUN TestPresignedUploadRegisteredBeforeCommit657=== PAUSE TestPresignedUploadRegisteredBeforeCommit658=== RUN TestService_Rustfstest659=== PAUSE TestService_Rustfstest660=== RUN TestParseSize661=== PAUSE TestParseSize662=== RUN TestSkippedUploadsHandler663=== PAUSE TestSkippedUploadsHandler664=== RUN TestSystemdListenerNotActivated665--- PASS: TestSystemdListenerNotActivated (0.00s)666=== RUN TestWatchdogBeatsWhenHealthy667--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)668=== RUN TestWatchdogSkipsWhenUnhealthy6692026/10/06 21:19:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6702026/10/06 21:19:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6712026/10/06 21:19:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6722026/10/06 21:19:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6732026/10/06 21:19:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6742026/10/06 21:19:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6752026/10/06 21:19:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6762026/10/06 21:19:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6772026/10/06 21:19:28 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6782026/10/06 21:19:28 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"679--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)680=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle681=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle682=== RUN TestProxyWriteTimeout683=== PAUSE TestProxyWriteTimeout684=== RUN TestPendingClosureWriteTimeout685=== PAUSE TestPendingClosureWriteTimeout686=== RUN TestIsValidUploadKey687=== PAUSE TestIsValidUploadKey688=== RUN TestUploadHandlersRejectInvalidKeys689=== PAUSE TestUploadHandlersRejectInvalidKeys690=== RUN TestUploadHandlersRejectOversizedBody691=== PAUSE TestUploadHandlersRejectOversizedBody692=== RUN TestService_cleanupPendingClosuresHandler693=== PAUSE TestService_cleanupPendingClosuresHandler694=== RUN TestService_createPendingClosureHandler695=== PAUSE TestService_createPendingClosureHandler696=== RUN TestService_verifyS3Integrity697=== PAUSE TestService_verifyS3Integrity698=== RUN TestCompleteMultipartUnregistered699=== PAUSE TestCompleteMultipartUnregistered700=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT701=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT702=== CONT TestProxyWriteTimeout703=== RUN TestProxyWriteTimeout/narinfo704=== PAUSE TestProxyWriteTimeout/narinfo705=== RUN TestProxyWriteTimeout/1_GiB_nar706=== PAUSE TestProxyWriteTimeout/1_GiB_nar707=== RUN TestProxyWriteTimeout/10_GiB_nar708=== CONT TestService_AuthMiddleware709=== CONT TestService_cleanupPendingClosuresHandler710=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle711=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT712=== CONT TestSkippedUploadsHandler713=== CONT TestCompleteMultipartUnregistered714=== CONT TestParseSize715--- PASS: TestParseSize (0.00s)716=== CONT TestService_verifyS3Integrity717=== CONT TestService_Rustfstest718=== CONT TestService_createPendingClosureHandler719=== CONT TestPresignedUploadRegisteredBeforeCommit720=== CONT TestCompletedNarNotReofferedAcrossClosures721=== CONT TestUploadHandlersRejectInvalidKeys722=== CONT TestCompleteMultipartUpload_ErrorButObjectExists723=== CONT TestUploadHandlersRejectOversizedBody724=== CONT TestRedundantMultipartUpload725=== CONT TestPush_SignsNarinfosOfItsPendingObjects726=== CONT TestGCTaskStore_CompletedAllowsNewTask727=== CONT TestGCTaskStore_GetReturnsLatest728=== CONT TestPush_RejectsBadRequests729=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit730=== CONT TestGCTaskStore_GetEmpty731=== CONT TestPush_RootsAreLockedInByteOrder732=== PAUSE TestProxyWriteTimeout/10_GiB_nar733=== CONT TestGCTaskStore_ConflictDifferentParams734--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)735=== CONT TestGCTaskStore_DeduplicateSameParams7362026/10/06 21:19:28 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000737--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)738=== CONT TestPush_CompleteWaitsForCleanupOfThePush739=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info740=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info741=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal742=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal743=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key744=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key745=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key746=== RUN TestProxyWriteTimeout/unknown_size747--- PASS: TestGCTaskStore_GetEmpty (0.00s)748=== CONT TestGCTaskStore_StartNew749--- PASS: TestGCTaskStore_StartNew (0.00s)750=== CONT TestPush_RepeatedRootCommitsOnce751--- PASS: TestSkippedUploadsHandler (0.01s)752=== CONT TestGCEndsOnShutdown753=== RUN TestGCEndsOnShutdown/before_the_run754=== PAUSE TestGCEndsOnShutdown/before_the_run755=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete756--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)757--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)758=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key759=== CONT TestPush_OverlappingRootsStoreOneRowPerKey760=== PAUSE TestProxyWriteTimeout/unknown_size761=== CONT TestCommitRacingPendingCleanupKeepsObjects762=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete763=== CONT TestPushWaitsForSweepHoldingRow764=== CONT TestPush_CompleteCommitsEveryRoot765=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark766=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark767=== CONT TestReadRedirectUsesPublicS3URL768=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure769=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure770=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart771=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart772=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts773=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts774=== CONT TestSweepRechecksPendingAfterLocking7752026/10/06 21:19:28 INFO Received uploads request method=POST path=/api/pending_closures7762026/10/06 21:19:28 INFO Received cleanup request method=DELETE path=/api/pending_closures7772026/10/06 21:19:28 INFO Aborted multipart uploads count=0 kept=07782026/10/06 21:19:28 INFO Received uploads request method=POST path=/api/pending_closures7792026/10/06 21:19:28 INFO Received cleanup request method=DELETE path=/api/pending_closures7802026/10/06 21:19:28 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"781--- PASS: TestService_AuthMiddleware (0.38s)782=== CONT TestReadProxyRangeRequest7832026/10/06 21:19:28 INFO Aborted multipart uploads count=1 kept=07842026/10/06 21:19:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7852026-10-06 21:19:28.408 UTC [449] ERROR: Closure does not exist: id=17862026-10-06 21:19:28.408 UTC [449] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE7872026-10-06 21:19:28.408 UTC [449] STATEMENT: -- name: CommitPendingClosure :exec788 SELECT commit_pending_closure($1::bigint)789 790--- PASS: TestService_cleanupPendingClosuresHandler (0.38s)791=== CONT TestGetExistingObjectsLocksRows7922026/10/06 21:19:28 INFO Received uploads request method=POST path=/api/pending_closures793--- PASS: TestService_Rustfstest (0.41s)794=== CONT TestReadRedirectKeepsNarinfoProxied7952026/10/06 21:19:28 INFO Received push request method=POST path=/api/pushes7962026/10/06 21:19:28 INFO Received uploads request method=POST path=/api/pending_closures797--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.46s)798=== CONT TestRegisterCompletedObjectNeedsPendingRow7992026/10/06 21:19:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete800=== RUN TestPush_RejectsBadRequests/root_not_in_objects801=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects802=== RUN TestPush_RejectsBadRequests/no_roots803=== PAUSE TestPush_RejectsBadRequests/no_roots804=== RUN TestPush_RejectsBadRequests/no_objects805=== PAUSE TestPush_RejectsBadRequests/no_objects806=== RUN TestPush_RejectsBadRequests/bad_root807=== PAUSE TestPush_RejectsBadRequests/bad_root808=== CONT TestReadRedirectNar8092026/10/06 21:19:28 INFO Received uploads request method=POST path=/api/pending_closures8102026/10/06 21:19:28 INFO Received uploads request method=POST path=/api/pending_closures8112026/10/06 21:19:28 INFO Received uploads request method=POST path=/api/pending_closures8122026/10/06 21:19:28 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst8132026/10/06 21:19:28 INFO Received uploads request method=POST path=/api/pending_closures814--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.53s)815=== CONT TestReadProxyDisabled8162026/10/06 21:19:28 INFO Received push request method=POST path=/api/pushes8172026/10/06 21:19:28 INFO Received complete push request method=POST path=/api/pushes/1/complete818--- PASS: TestPush_RepeatedRootCommitsOnce (0.55s)819=== CONT TestSweepSkipsRowsLockedByPush820--- PASS: TestReadRedirectKeepsNarinfoProxied (0.15s)821=== CONT TestReadProxyRootRedirectsToIndexHTML8222026/10/06 21:19:28 INFO Received uploads request method=POST path=/api/pending_closures8232026/10/06 21:19:28 INFO Received uploads request method=POST path=/api/pending_closures8242026/10/06 21:19:28 INFO Received uploads request method=POST path=/api/pending_closures8252026/10/06 21:19:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8262026/10/06 21:19:28 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst827--- PASS: TestCompleteMultipartUnregistered (0.59s)828=== CONT TestFailedS3DeleteKeepsTombstone8292026/10/06 21:19:28 INFO Received push request method=POST path=/api/pushes8302026/10/06 21:19:28 INFO Received uploads request method=POST path=/api/pending_closures8312026/10/06 21:19:28 INFO Received push request method=POST path=/api/pushes8322026-10-06 21:19:28.684 UTC [518] ERROR: could not obtain lock on row in relation "closures"8332026-10-06 21:19:28.684 UTC [518] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8342026-10-06 21:19:28.684 UTC [518] ERROR: could not obtain lock on row in relation "closures"8352026-10-06 21:19:28.684 UTC [518] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8362026/10/06 21:19:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8372026-10-06 21:19:28.685 UTC [518] ERROR: could not obtain lock on row in relation "closures"8382026-10-06 21:19:28.685 UTC [518] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8392026-10-06 21:19:28.685 UTC [518] ERROR: could not obtain lock on row in relation "closures"8402026-10-06 21:19:28.685 UTC [518] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8412026-10-06 21:19:28.685 UTC [518] ERROR: could not obtain lock on row in relation "closures"8422026-10-06 21:19:28.685 UTC [518] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT843--- PASS: TestPush_RootsAreLockedInByteOrder (0.66s)844=== CONT TestReadProxyConditionalGet845--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.65s)846=== CONT TestForceGCDuringPushOffersSweptObject847=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows848=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows849=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check850=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check851=== CONT TestReadProxyOutlastsServerWriteTimeout8522026/10/06 21:19:28 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NTU0ZmY4ZWItOTMwOC00YjU2LTgxNGMtZDMxYzJlMTk1M2NmLjllMWJlOWFhLWY0ZjUtNDE0Yi05MWY5LWI4YjVjYmU4OGMzZXgxNzkxMzIxNTY4Mzc5MDM3NjQ3 parts=108532026/10/06 21:19:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8542026/10/06 21:19:28 INFO Completed upload id=18552026/10/06 21:19:28 INFO Received uploads request method=POST path=/api/pending_closures8562026/10/06 21:19:28 INFO Received uploads request method=POST path=/api/pending_closures8572026/10/06 21:19:28 INFO Received uploads request method=POST path=/api/pending_closures8582026/10/06 21:19:28 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo8592026/10/06 21:19:28 WARN Found objects in DB but missing from S3, will re-upload count=1860--- PASS: TestService_verifyS3Integrity (0.68s)861=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection8622026/10/06 21:19:28 INFO Received push request method=POST path=/api/pushes8632026/10/06 21:19:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8642026/10/06 21:19:28 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NTU0ZmY4ZWItOTMwOC00YjU2LTgxNGMtZDMxYzJlMTk1M2NmLmYyMjEzMTJiLTg2NDEtNDkwNy1iNGU5LTBlYmY2NjMzZjBjNXgxNzkxMzIxNTY4NzEwMzMwMDI48652026/10/06 21:19:28 INFO Received complete push request method=POST path=/api/pushes/1/complete8662026/10/06 21:19:28 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NTU0ZmY4ZWItOTMwOC00YjU2LTgxNGMtZDMxYzJlMTk1M2NmLmYyMjEzMTJiLTg2NDEtNDkwNy1iNGU5LTBlYmY2NjMzZjBjNXgxNzkxMzIxNTY4NzEwMzMwMDI4 parts=1867--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.72s)868=== CONT TestReadProxyHead8692026/10/06 21:19:28 INFO Received push request method=POST path=/api/pushes8702026/10/06 21:19:28 INFO Received push request method=POST path=/api/pushes8712026-10-06 21:19:28.782 UTC [485] ERROR: Push does not exist: id=18722026-10-06 21:19:28.782 UTC [485] CONTEXT: PL/pgSQL function commit_push(bigint) line 10 at RAISE8732026-10-06 21:19:28.782 UTC [485] STATEMENT: SELECT commit_push($1)874--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.75s)875=== CONT TestGCSweepDeliversEachKeyOnce8762026/10/06 21:19:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8772026/10/06 21:19:28 INFO Signed narinfos id=1 count=18782026/10/06 21:19:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8792026/10/06 21:19:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8802026/10/06 21:19:28 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"8812026/10/06 21:19:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8822026/10/06 21:19:28 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"8832026/10/06 21:19:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8842026/10/06 21:19:28 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=18852026/10/06 21:19:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8862026/10/06 21:19:28 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo887--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.76s)888=== CONT TestReadProxyInvalidPath8892026/10/06 21:19:28 INFO Received push request method=POST path=/api/pushes8902026/10/06 21:19:28 INFO Aborted multipart uploads count=0 kept=08912026/10/06 21:19:28 WARN Force mode enabled - objects will be deleted immediately without grace period8922026/10/06 21:19:28 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=08932026/10/06 21:19:28 INFO Vacuumed table table=pending_closures8942026/10/06 21:19:28 INFO Vacuumed table table=pending_objects8952026/10/06 21:19:28 INFO Vacuumed table table=multipart_uploads8962026/10/06 21:19:28 INFO Vacuumed table table=closures8972026/10/06 21:19:28 INFO Vacuumed table table=objects8982026/10/06 21:19:28 INFO Aborted multipart uploads count=0 kept=08992026/10/06 21:19:28 INFO Received complete push request method=POST path=/api/pushes/1/complete9002026/10/06 21:19:28 WARN Force mode enabled - objects will be deleted immediately without grace period901--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.73s)902=== CONT TestReadProxy4049032026/10/06 21:19:28 INFO Received uploads request method=POST path=/api/pending_closures904--- PASS: TestPush_CompleteCommitsEveryRoot (0.73s)905=== CONT TestTombstonedObjectOfferedWithoutWaiting9062026/10/06 21:19:28 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=09072026/10/06 21:19:28 INFO Vacuumed table table=pending_closures9082026/10/06 21:19:28 INFO Vacuumed table table=pending_objects9092026/10/06 21:19:28 INFO Vacuumed table table=multipart_uploads9102026/10/06 21:19:28 INFO Vacuumed table table=closures9112026/10/06 21:19:28 INFO Vacuumed table table=objects9122026/10/06 21:19:28 INFO Received complete push request method=POST path=/api/pushes/2/complete913--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.81s)914=== CONT TestReadProxyNarStreaming915--- PASS: TestReadRedirectUsesPublicS3URL (0.77s)916=== CONT TestGCSweepSkipsPendingObjects9172026/10/06 21:19:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9182026/10/06 21:19:28 INFO Aborted multipart uploads count=0 kept=09192026/10/06 21:19:28 WARN Force mode enabled - objects will be deleted immediately without grace period9202026/10/06 21:19:28 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NTU0ZmY4ZWItOTMwOC00YjU2LTgxNGMtZDMxYzJlMTk1M2NmLmVlMGQ0ZGI2LTRlOWUtNGNlZS1iMDk5LTNhNTQxNjljMWYyN3gxNzkxMzIxNTY4NTI0ODAzMDQz parts=12921--- PASS: TestGetExistingObjectsLocksRows (0.50s)922=== CONT TestReadProxyContentNegotiation9232026/10/06 21:19:28 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09242026/10/06 21:19:28 INFO Received uploads request method=POST path=/api/pending_closures9252026/10/06 21:19:28 INFO Vacuumed table table=pending_closures9262026/10/06 21:19:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9272026/10/06 21:19:28 INFO Vacuumed table table=pending_objects9282026/10/06 21:19:28 INFO Vacuumed table table=multipart_uploads9292026/10/06 21:19:28 INFO Vacuumed table table=closures9302026/10/06 21:19:28 INFO Received uploads request method=POST path=/api/pending_closures9312026/10/06 21:19:28 INFO Vacuumed table table=objects932--- PASS: TestSweepRechecksPendingAfterLocking (0.74s)933=== CONT TestDeduplicatedObjectsRecordedAsPending934--- PASS: TestReadProxyRangeRequest (0.53s)935=== CONT TestReadProxyNarinfoAlreadyDecompressed9362026/10/06 21:19:28 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NTU0ZmY4ZWItOTMwOC00YjU2LTgxNGMtZDMxYzJlMTk1M2NmLmM5ZGU5M2VlLWNmZWEtNGU3Zi1hNWI4LWVkOWJmNGFhZmM4ZngxNzkxMzIxNTY4NjA5NDAyMzQ0 parts=109372026/10/06 21:19:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9382026/10/06 21:19:28 INFO Completed upload id=19392026/10/06 21:19:28 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009402026/10/06 21:19:28 INFO Received uploads request method=POST path=/api/pending_closures9412026/10/06 21:19:28 INFO Starting cleanup of old closures method=DELETE path=/api/closures942--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.46s)943=== CONT TestPushDedupSurvivesConcurrentGC9442026/10/06 21:19:28 INFO Aborted multipart uploads count=0 kept=09452026/10/06 21:19:28 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09462026/10/06 21:19:28 INFO Vacuumed table table=pending_closures9472026/10/06 21:19:28 INFO Vacuumed table table=pending_objects9482026/10/06 21:19:28 INFO Vacuumed table table=multipart_uploads9492026/10/06 21:19:28 INFO Vacuumed table table=closures9502026/10/06 21:19:28 INFO Vacuumed table table=objects951--- PASS: TestReadRedirectNar (0.49s)952=== CONT TestReadProxyNarinfo9532026/10/06 21:19:28 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000954--- PASS: TestService_createPendingClosureHandler (0.97s)955=== CONT TestGCMetrics956--- PASS: TestReadProxyDisabled (0.44s)957=== CONT TestIsValidCachePath958=== RUN TestIsValidCachePath/narinfo959=== PAUSE TestIsValidCachePath/narinfo960=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars961=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars962=== RUN TestIsValidCachePath/nar_zst963=== PAUSE TestIsValidCachePath/nar_zst964=== RUN TestIsValidCachePath/nar_xz965=== PAUSE TestIsValidCachePath/nar_xz966=== RUN TestIsValidCachePath/nar_bz2967=== PAUSE TestIsValidCachePath/nar_bz2968=== RUN TestIsValidCachePath/nar_uncompressed969=== PAUSE TestIsValidCachePath/nar_uncompressed970=== RUN TestIsValidCachePath/ls971=== PAUSE TestIsValidCachePath/ls972=== RUN TestIsValidCachePath/log973=== PAUSE TestIsValidCachePath/log974=== RUN TestIsValidCachePath/realisation975=== PAUSE TestIsValidCachePath/realisation976=== RUN TestIsValidCachePath/nix-cache-info977=== PAUSE TestIsValidCachePath/nix-cache-info978=== RUN TestIsValidCachePath/index.html979=== PAUSE TestIsValidCachePath/index.html980=== RUN TestIsValidCachePath/traversal_parent981=== PAUSE TestIsValidCachePath/traversal_parent982=== RUN TestIsValidCachePath/traversal_in_middle983=== PAUSE TestIsValidCachePath/traversal_in_middle984=== RUN TestIsValidCachePath/invalid_char_e985=== PAUSE TestIsValidCachePath/invalid_char_e986=== RUN TestIsValidCachePath/invalid_char_u987=== PAUSE TestIsValidCachePath/invalid_char_u988=== RUN TestIsValidCachePath/random_path989=== PAUSE TestIsValidCachePath/random_path990=== RUN TestIsValidCachePath/empty991=== PAUSE TestIsValidCachePath/empty992=== RUN TestIsValidCachePath/leading_slash993=== PAUSE TestIsValidCachePath/leading_slash994=== RUN TestIsValidCachePath/wrong_extension995=== PAUSE TestIsValidCachePath/wrong_extension996=== RUN TestIsValidCachePath/short_hash997=== PAUSE TestIsValidCachePath/short_hash998=== CONT TestGCBugBareHashReferences9992026/10/06 21:19:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10002026/10/06 21:19:29 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NTU0ZmY4ZWItOTMwOC00YjU2LTgxNGMtZDMxYzJlMTk1M2NmLmM3OWZjYmY1LTQzMDctNDkxYi05ODM1LTdjZmRjZWE3MmRjN3gxNzkxMzIxNTY4NjY4Mzk3NzYx parts=1210012026/10/06 21:19:29 INFO Received uploads request method=POST path=/api/pending_closures10022026/10/06 21:19:29 INFO Aborted multipart uploads count=0 kept=01003--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.02s)1004=== CONT TestProxyHeadersOnlyTrustedOnSocket1005--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.46s)1006=== CONT TestGCAdvisoryLockBlocksConcurrentRun10072026/10/06 21:19:29 WARN Force mode enabled - objects will be deleted immediately without grace period10082026/10/06 21:19:29 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010092026/10/06 21:19:29 INFO Vacuumed table table=pending_closures10102026/10/06 21:19:29 INFO Vacuumed table table=pending_objects10112026/10/06 21:19:29 INFO Vacuumed table table=multipart_uploads10122026/10/06 21:19:29 INFO Vacuumed table table=closures10132026/10/06 21:19:29 INFO Vacuumed table table=objects10142026/10/06 21:19:29 INFO Aborted multipart uploads count=0 kept=010152026/10/06 21:19:29 WARN Force mode enabled - objects will be deleted immediately without grace period10162026/10/06 21:19:29 INFO Received uploads request method=POST path=/api/pending_closures10172026/10/06 21:19:29 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=1 objects-failed-to-delete=010182026/10/06 21:19:29 INFO Vacuumed table table=pending_closures10192026/10/06 21:19:29 INFO Vacuumed table table=pending_objects10202026/10/06 21:19:29 INFO Vacuumed table table=multipart_uploads10212026/10/06 21:19:29 INFO Vacuumed table table=closures10222026/10/06 21:19:29 INFO Vacuumed table table=objects1023--- PASS: TestSweepSkipsRowsLockedByPush (0.50s)1024=== CONT TestParseSingleRange1025=== RUN TestParseSingleRange/none1026=== PAUSE TestParseSingleRange/none1027=== RUN TestParseSingleRange/unknown_unit1028=== PAUSE TestParseSingleRange/unknown_unit1029=== RUN TestParseSingleRange/multi-range_ignored1030=== PAUSE TestParseSingleRange/multi-range_ignored1031=== RUN TestParseSingleRange/malformed_no_dash1032=== PAUSE TestParseSingleRange/malformed_no_dash1033=== RUN TestParseSingleRange/malformed_both_empty1034=== PAUSE TestParseSingleRange/malformed_both_empty1035=== RUN TestParseSingleRange/malformed_end_before_start1036=== PAUSE TestParseSingleRange/malformed_end_before_start1037=== RUN TestParseSingleRange/closed1038=== PAUSE TestParseSingleRange/closed1039=== RUN TestParseSingleRange/open-ended1040=== PAUSE TestParseSingleRange/open-ended1041=== RUN TestParseSingleRange/end_clamped_to_size1042=== PAUSE TestParseSingleRange/end_clamped_to_size1043=== RUN TestParseSingleRange/suffix1044=== PAUSE TestParseSingleRange/suffix1045=== RUN TestParseSingleRange/suffix_exceeds_size1046=== PAUSE TestParseSingleRange/suffix_exceeds_size1047=== RUN TestParseSingleRange/single_byte1048=== PAUSE TestParseSingleRange/single_byte1049=== RUN TestParseSingleRange/start_past_EOF1050=== PAUSE TestParseSingleRange/start_past_EOF1051=== RUN TestParseSingleRange/start_far_past_EOF1052=== PAUSE TestParseSingleRange/start_far_past_EOF1053=== CONT TestLeadEndsOnShutdown1054--- PASS: TestReadProxyConditionalGet (0.41s)1055=== CONT TestService_NativeMTLS10562026/10/06 21:19:29 INFO Received uploads request method=POST path=/api/pending_closures10572026/10/06 21:19:29 INFO Aborted multipart uploads count=0 kept=010582026/10/06 21:19:29 WARN Force mode enabled - objects will be deleted immediately without grace period1059--- PASS: TestReadProxyHead (0.41s)1060=== CONT TestLeadIncumbentAnnouncesAtOnce10612026/10/06 21:19:29 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."10622026/10/06 21:19:29 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1063--- PASS: TestFailedS3DeleteKeepsTombstone (0.54s)1064=== CONT TestMetricsInventory1065--- PASS: TestReadProxyInvalidPath (0.41s)1066=== CONT TestLeadElectsOneAndHandsOver10672026/10/06 21:19:29 INFO Aborted multipart uploads count=0 kept=010682026/10/06 21:19:29 WARN Force mode enabled - objects will be deleted immediately without grace period10692026/10/06 21:19:29 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=010702026/10/06 21:19:29 INFO Vacuumed table table=pending_closures10712026/10/06 21:19:29 INFO Vacuumed table table=pending_objects10722026/10/06 21:19:29 INFO Vacuumed table table=multipart_uploads10732026/10/06 21:19:29 INFO Vacuumed table table=closures10742026/10/06 21:19:29 INFO Vacuumed table table=objects1075--- PASS: TestGCSweepDeliversEachKeyOnce (0.45s)1076=== CONT TestNARDeduplicationMetadataUploadBug10772026/10/06 21:19:29 INFO Received uploads request method=POST path=/api/pending_closures1078--- PASS: TestReadProxy404 (0.42s)1079=== CONT TestCreatePendingClosureRejectsOversizedNAR10802026/10/06 21:19:29 INFO Received uploads request method=POST path=/api/pending_closures1081--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1082=== CONT TestConnectWaitsForAPeerMigration1083--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.42s)1084=== CONT TestCacheConfigHandlerMaxNarSize1085--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1086=== CONT TestResolveDBConnectionString1087=== RUN TestResolveDBConnectionString/flag_wins1088=== PAUSE TestResolveDBConnectionString/flag_wins1089=== RUN TestResolveDBConnectionString/file_when_flag_empty1090=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1091=== RUN TestResolveDBConnectionString/missing_file_is_an_error1092=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1093=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1094=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1095=== RUN TestResolveDBConnectionString/nothing_configured1096=== PAUSE TestResolveDBConnectionString/nothing_configured1097=== CONT TestGenerateLandingPage1098--- PASS: TestGenerateLandingPage (0.00s)1099=== CONT TestService_readinessHandler1100--- PASS: TestReadProxyNarStreaming (0.42s)1101=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock11022026/10/06 21:19:29 INFO Received uploads request method=POST path=/api/pending_closures11032026/10/06 21:19:29 INFO Aborted multipart uploads count=0 kept=011042026/10/06 21:19:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11052026/10/06 21:19:29 WARN Force mode enabled - objects will be deleted immediately without grace period11062026/10/06 21:19:29 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011072026/10/06 21:19:29 INFO Vacuumed table table=pending_closures11082026/10/06 21:19:29 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NTU0ZmY4ZWItOTMwOC00YjU2LTgxNGMtZDMxYzJlMTk1M2NmLmEzYjM2OWI5LWUxYjUtNDU1Ni1hOGRiLWViNjQ0N2M5MmIyZHgxNzkxMzIxNTY4OTI3Nzk2NDcz error="Get \"http://127.0.0.1:1/bucket10/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"11092026/10/06 21:19:29 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NTU0ZmY4ZWItOTMwOC00YjU2LTgxNGMtZDMxYzJlMTk1M2NmLmU2OWVlN2ExLTVkODktNGRhNS04ZDkwLTEyYTg2ODcyZTBjNHgxNzkxMzIxNTY4OTEzMDg1MDQ0 parts=1211102026/10/06 21:19:29 INFO Vacuumed table table=pending_objects11112026/10/06 21:19:29 INFO Vacuumed table table=multipart_uploads11122026/10/06 21:19:29 INFO Vacuumed table table=closures11132026/10/06 21:19:29 INFO Received cleanup request method=DELETE path=/api/pending_closures11142026/10/06 21:19:29 INFO Vacuumed table table=objects11152026/10/06 21:19:29 INFO Aborted multipart uploads count=1 kept=011162026/10/06 21:19:29 INFO Received uploads request method=POST path=/api/pending_closures1117--- PASS: TestPushWaitsForSweepHoldingRow (1.23s)1118=== CONT TestService_healthCheckHandler1119--- PASS: TestGCSweepSkipsPendingObjects (0.46s)1120=== CONT TestDeleteClosuresRacingPins1121--- PASS: TestRedundantMultipartUpload (1.29s)1122=== CONT TestGracefulShutdownDrainsInflight11232026/10/06 21:19:29 INFO Starting HTTP server address=127.0.0.1:3994711242026/10/06 21:19:29 INFO Shutdown signal received, draining in-flight requests timeout=10s1125--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.41s)1126=== CONT TestGCTaskStore_Fail1127--- PASS: TestGCTaskStore_Fail (0.00s)1128=== CONT TestClientFallsBackToClosures1129--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.63s)1130=== CONT TestGCTaskStore_PhaseUpdates1131--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1132=== CONT TestClientPushesUseOnePush1133--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.41s)1134=== CONT TestServerTLSConfig1135=== RUN TestServerTLSConfig/no_client_CA1136=== PAUSE TestServerTLSConfig/no_client_CA1137=== RUN TestServerTLSConfig/missing_CA_file1138=== PAUSE TestServerTLSConfig/missing_CA_file1139=== RUN TestServerTLSConfig/not_a_PEM_file1140=== PAUSE TestServerTLSConfig/not_a_PEM_file1141=== CONT TestCacheConfigHandler1142=== RUN TestCacheConfigHandler/full_config,_no_issuer1143=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1144=== RUN TestCacheConfigHandler/no_cache_url_configured1145=== PAUSE TestCacheConfigHandler/no_cache_url_configured1146=== RUN TestCacheConfigHandler/no_signing_keys1147=== PAUSE TestCacheConfigHandler/no_signing_keys1148=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1149=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1150=== CONT TestCacheStatsHandler1151--- PASS: TestReadProxyContentNegotiation (0.45s)1152=== CONT TestPresentNotReportedWhileGCDeletesClosure1153=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1154=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1155=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1156=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1157=== CONT TestService_ReadScope_PublicByDefault11582026/10/06 21:19:29 INFO Received uploads request method=POST path=/api/pending_closures1159--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1160=== CONT TestPinProtectsFromGC11612026/10/06 21:19:29 INFO Aborted multipart uploads count=0 kept=011622026/10/06 21:19:29 WARN Force mode enabled - objects will be deleted immediately without grace period11632026/10/06 21:19:29 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011642026/10/06 21:19:29 INFO Vacuumed table table=pending_closures11652026/10/06 21:19:29 INFO Vacuumed table table=pending_objects11662026/10/06 21:19:29 INFO Vacuumed table table=multipart_uploads11672026/10/06 21:19:29 INFO Vacuumed table table=closures11682026/10/06 21:19:29 INFO Vacuumed table table=objects1169--- PASS: TestGCMetrics (0.43s)1170=== CONT TestPresentRefreshesOnlyStaleClosures11712026/10/06 21:19:29 INFO Starting HTTP server address=127.0.0.1:3968111722026/10/06 21:19:29 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket662759975/001/proxy.sock11732026/10/06 21:19:29 WARN mTLS auth: subject not in bound subjects subject="CN=someone"11742026/10/06 21:19:29 INFO Shutdown signal received, draining in-flight requests timeout=10s11752026/10/06 21:19:29 INFO Aborted multipart uploads count=0 kept=01176--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.41s)1177=== CONT TestService_RequireScope_OIDC11782026/10/06 21:19:29 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011792026/10/06 21:19:29 INFO Vacuumed table table=pending_closures11802026/10/06 21:19:29 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1181--- PASS: TestReadProxyNarinfo (0.49s)1182=== CONT TestClientSharedPathCommittedMidPush11832026/10/06 21:19:29 INFO Vacuumed table table=pending_objects11842026/10/06 21:19:29 INFO Vacuumed table table=multipart_uploads11852026/10/06 21:19:29 INFO Vacuumed table table=closures11862026/10/06 21:19:29 INFO Vacuumed table table=objects11872026/10/06 21:19:29 INFO Aborted multipart uploads count=0 kept=011882026/10/06 21:19:29 WARN Force mode enabled - objects will be deleted immediately without grace period11892026/10/06 21:19:29 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011902026/10/06 21:19:29 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=nixbld database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"11912026/10/06 21:19:29 INFO Vacuumed table table=pending_closures1192--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.43s)1193=== CONT TestService_AuthMiddleware_OIDC11942026/10/06 21:19:29 INFO Vacuumed table table=pending_objects11952026/10/06 21:19:29 INFO Vacuumed table table=multipart_uploads11962026/10/06 21:19:29 INFO Vacuumed table table=closures11972026/10/06 21:19:29 INFO Vacuumed table table=objects1198--- PASS: TestPushDedupSurvivesConcurrentGC (0.54s)1199=== CONT TestClientWithDependencies12002026/10/06 21:19:29 INFO lead: acquired remote=192.0.2.1:123412012026/10/06 21:19:29 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12022026/10/06 21:19:29 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1203--- PASS: TestService_NativeMTLS (0.42s)1204=== CONT TestPresentReportsOnlyClosureRoots12052026/10/06 21:19:29 INFO lead: acquired remote=192.0.2.1:123412062026/10/06 21:19:29 INFO lead: released remote=192.0.2.1:12341207--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.37s)1208=== CONT TestClientMultipleUploads1209--- PASS: TestMetricsInventory (0.41s)1210=== CONT TestService_ReadAuthMiddleware12112026/10/06 21:19:29 INFO lead: acquired remote=192.0.2.1:123412122026/10/06 21:19:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37569/oidc12132026/10/06 21:19:29 WARN readiness check failed error="closed pool"1214--- PASS: TestService_readinessHandler (0.37s)1215=== CONT TestCreatePin_ReservedPins1216=== NAME TestNARDeduplicationMetadataUploadBug1217 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug226045750/001/store/rlfv5sb9jf8ld3ics6qcmav32rfwivcz-file1.txt1218--- PASS: TestGCBugBareHashReferences (0.65s)1219=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1220--- PASS: TestService_healthCheckHandler (0.35s)1221=== CONT TestOrphanedObjectsGCStressTest12222026/10/06 21:19:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43221/oidc12232026/10/06 21:19:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35299/oidc12242026/10/06 21:19:29 INFO Received push request method=POST path=/api/pushes12252026/10/06 21:19:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12262026/10/06 21:19:29 INFO Uploading rlfv5sb9jf8ld3ics6qcmav32rfwivcz-file1.txt (160B)12272026/10/06 21:19:29 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12282026/10/06 21:19:29 WARN Failed to register uploaded object key=rlfv5sb9jf8ld3ics6qcmav32rfwivcz.ls error="server returned 404: 404 page not found\n"12292026/10/06 21:19:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12302026/10/06 21:19:29 INFO Signed narinfos id=1 count=112312026/10/06 21:19:29 INFO Uploading 1 narinfos1232--- PASS: TestCacheStatsHandler (0.38s)1233=== CONT TestService_AuthMiddleware_MTLSProxyHeader12342026/10/06 21:19:29 INFO Received complete push request method=POST path=/api/pushes/1/complete12352026/10/06 21:19:29 WARN Failed to register uploaded object key=rlfv5sb9jf8ld3ics6qcmav32rfwivcz.narinfo error="server returned 404: 404 page not found\n"12362026/10/06 21:19:29 INFO Upload complete. (73ms)1237=== NAME TestNARDeduplicationMetadataUploadBug1238 metadata_upload_test.go:54: Retrieved narinfo from S3:1239 StorePath: /build/TestNARDeduplicationMetadataUploadBug226045750/001/store/rlfv5sb9jf8ld3ics6qcmav32rfwivcz-file1.txt1240 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1241 Compression: zstd1242 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1243 NarSize: 1601244 References: 1245 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1246 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1247 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1248 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1249--- PASS: TestService_ReadScope_PublicByDefault (0.40s)1250=== CONT TestClientIntegration1251=== NAME TestNARDeduplicationMetadataUploadBug1252 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug226045750/001/store/x1l1lj4wwprrk5lqf151zb5pz7bx2l4x-file2.txt1253--- PASS: TestPresentRefreshesOnlyStaleClosures (0.39s)1254=== CONT TestOrphanedObjectsGC12552026/10/06 21:19:29 INFO Received push request method=POST path=/api/pushes12562026/10/06 21:19:29 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12572026/10/06 21:19:29 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12582026/10/06 21:19:29 WARN Failed to register uploaded object key=x1l1lj4wwprrk5lqf151zb5pz7bx2l4x.ls error="server returned 404: 404 page not found\n"12592026/10/06 21:19:29 INFO Signed narinfos id=2 count=112602026/10/06 21:19:29 INFO Uploading 1 narinfos1261=== NAME TestPinProtectsFromGC1262 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC4113095903/001/store/xqw9w6lqv7rlv66yxf5izmzspzcwgzpy-pinned-file.txt1263 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC4113095903/001/store/766dr62iipabli6395sd2672jv634vqc-unpinned-file.txt12642026/10/06 21:19:29 INFO Received complete push request method=POST path=/api/pushes/2/complete12652026/10/06 21:19:29 WARN Failed to register uploaded object key=x1l1lj4wwprrk5lqf151zb5pz7bx2l4x.narinfo error="server returned 404: 404 page not found\n"12662026/10/06 21:19:29 INFO Upload complete. (51ms)1267=== NAME TestNARDeduplicationMetadataUploadBug1268 metadata_upload_test.go:76: Retrieved narinfo from S3:1269 StorePath: /build/TestNARDeduplicationMetadataUploadBug226045750/001/store/x1l1lj4wwprrk5lqf151zb5pz7bx2l4x-file2.txt1270 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1271 Compression: zstd1272 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1273 NarSize: 1601274 References: 1275 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1276 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1277 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1278 {"version":1,"root":{"type":"regular","size":44}}1279--- PASS: TestNARDeduplicationMetadataUploadBug (0.65s)1280=== CONT TestClientErrorHandling1281=== RUN TestClientErrorHandling/InvalidStorePath1282=== PAUSE TestClientErrorHandling/InvalidStorePath1283=== RUN TestClientErrorHandling/InvalidAuthToken1284=== PAUSE TestClientErrorHandling/InvalidAuthToken1285=== RUN TestClientErrorHandling/ServerNotAvailable1286=== PAUSE TestClientErrorHandling/ServerNotAvailable1287=== CONT TestObjectStatsTrigger12882026/10/06 21:19:29 INFO Received uploads request method=POST path=/api/pending_closures1289--- PASS: TestPresentReportsOnlyClosureRoots (0.38s)1290=== CONT TestClientCADerivations12912026/10/06 21:19:29 INFO Received uploads request method=POST path=/api/pending_closures12922026/10/06 21:19:29 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12932026/10/06 21:19:29 INFO Uploading 560wrr580rl170yxr4b2y2qbkr07plqi-a (216B)12942026/10/06 21:19:29 INFO Uploading g782zlhqrvdd9wwssbvrd8abqb8j1zaj-shared-dep (136B)12952026/10/06 21:19:29 WARN Failed to register uploaded object key=13f2mblv22cvkc9958f878zn9kdnhcs9.ls error="server returned 404: 404 page not found\n"12962026/10/06 21:19:29 WARN Failed to register uploaded object key=nar/02f14198lfj18c7441lpp2llmlyxhvfgdcvbjk02h1lx6yqx67g1.nar.zst error="server returned 404: 404 page not found\n"12972026/10/06 21:19:29 WARN Failed to register uploaded object key=g782zlhqrvdd9wwssbvrd8abqb8j1zaj.ls error="server returned 404: 404 page not found\n"12982026/10/06 21:19:29 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12992026/10/06 21:19:29 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13002026/10/06 21:19:29 WARN Failed to register uploaded object key=560wrr580rl170yxr4b2y2qbkr07plqi.ls error="server returned 404: 404 page not found\n"13012026/10/06 21:19:29 INFO Signed narinfos id=1 count=213022026/10/06 21:19:29 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13032026/10/06 21:19:29 INFO Signed narinfos id=2 count=213042026/10/06 21:19:29 INFO Uploading 4 narinfos13052026/10/06 21:19:29 WARN Failed to register uploaded object key=g782zlhqrvdd9wwssbvrd8abqb8j1zaj.narinfo error="server returned 404: 404 page not found\n"13062026/10/06 21:19:29 WARN Failed to register uploaded object key=560wrr580rl170yxr4b2y2qbkr07plqi.narinfo error="server returned 404: 404 page not found\n"13072026/10/06 21:19:29 WARN Failed to register uploaded object key=13f2mblv22cvkc9958f878zn9kdnhcs9.narinfo error="server returned 404: 404 page not found\n"13082026/10/06 21:19:29 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13092026/10/06 21:19:29 WARN Failed to register uploaded object key=g782zlhqrvdd9wwssbvrd8abqb8j1zaj.narinfo error="server returned 404: 404 page not found\n"13102026/10/06 21:19:29 INFO Completed upload id=113112026/10/06 21:19:29 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13122026/10/06 21:19:29 INFO Completed upload id=213132026/10/06 21:19:29 INFO Upload complete. (65ms)1314=== NAME TestClientFallsBackToClosures1315 client_pushes_test.go:112: Retrieved narinfo from S3:1316 StorePath: /build/TestClientFallsBackToClosures3919271484/001/store/g782zlhqrvdd9wwssbvrd8abqb8j1zaj-shared-dep1317 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1318 Compression: zstd1319 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821320 NarSize: 1361321 References: 1322 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n13232026/10/06 21:19:29 INFO Received push request method=POST path=/api/pushes1324--- PASS: TestService_ReadAuthMiddleware (0.35s)1325=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1326=== NAME TestClientFallsBackToClosures1327 client_pushes_test.go:112: Retrieved narinfo from S3:1328 StorePath: /build/TestClientFallsBackToClosures3919271484/001/store/560wrr580rl170yxr4b2y2qbkr07plqi-a1329 URL: nar/02f14198lfj18c7441lpp2llmlyxhvfgdcvbjk02h1lx6yqx67g1.nar.zst1330 Compression: zstd1331 NarHash: sha256:02f14198lfj18c7441lpp2llmlyxhvfgdcvbjk02h1lx6yqx67g11332 NarSize: 2161333 References: /build/TestClientFallsBackToClosures3919271484/001/store/g782zlhqrvdd9wwssbvrd8abqb8j1zaj-shared-dep1334 CA: text:sha256:1i2jp23z5rzs11w62kvmw2spjkzwd81c3c8gjsr6c9aa6lx90v601335 client_pushes_test.go:112: Retrieved narinfo from S3:1336 StorePath: /build/TestClientFallsBackToClosures3919271484/001/store/13f2mblv22cvkc9958f878zn9kdnhcs9-b1337 URL: nar/02f14198lfj18c7441lpp2llmlyxhvfgdcvbjk02h1lx6yqx67g1.nar.zst1338 Compression: zstd1339 NarHash: sha256:02f14198lfj18c7441lpp2llmlyxhvfgdcvbjk02h1lx6yqx67g11340 NarSize: 2161341 References: /build/TestClientFallsBackToClosures3919271484/001/store/g782zlhqrvdd9wwssbvrd8abqb8j1zaj-shared-dep1342 CA: text:sha256:1i2jp23z5rzs11w62kvmw2spjkzwd81c3c8gjsr6c9aa6lx90v6013432026/10/06 21:19:29 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13442026/10/06 21:19:29 INFO Uploading sccj13s9nr82dpx3l517lrwb24fyfm40-b (216B)13452026/10/06 21:19:29 INFO Uploading gxxzf2dvhcsykvl715spjk6dfk9sdlgd-shared-dep (136B)1346--- PASS: TestClientFallsBackToClosures (0.60s)1347=== CONT TestPendingCleanupUsesOneCutoff13482026/10/06 21:19:29 WARN Failed to register uploaded object key=kd6x5lamajikbnm195bkmwc3g0pjc6l8.ls error="server returned 404: 404 page not found\n"13492026/10/06 21:19:29 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13502026/10/06 21:19:29 WARN Failed to register uploaded object key=gxxzf2dvhcsykvl715spjk6dfk9sdlgd.ls error="server returned 404: 404 page not found\n"13512026/10/06 21:19:29 WARN Failed to register uploaded object key=nar/1sa45f71w0mjg0sscwas46habrz4508knk664gq7xmcdxbv2kyny.nar.zst error="server returned 404: 404 page not found\n"13522026/10/06 21:19:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13532026/10/06 21:19:29 WARN Failed to register uploaded object key=sccj13s9nr82dpx3l517lrwb24fyfm40.ls error="server returned 404: 404 page not found\n"13542026/10/06 21:19:29 INFO Signed narinfos id=1 count=313552026/10/06 21:19:29 INFO Uploading 3 narinfos13562026/10/06 21:19:29 WARN Failed to register uploaded object key=sccj13s9nr82dpx3l517lrwb24fyfm40.narinfo error="server returned 404: 404 page not found\n"13572026/10/06 21:19:29 WARN Failed to register uploaded object key=gxxzf2dvhcsykvl715spjk6dfk9sdlgd.narinfo error="server returned 404: 404 page not found\n"13582026/10/06 21:19:29 INFO Received complete push request method=POST path=/api/pushes/1/complete13592026/10/06 21:19:29 WARN Failed to register uploaded object key=kd6x5lamajikbnm195bkmwc3g0pjc6l8.narinfo error="server returned 404: 404 page not found\n"13602026/10/06 21:19:29 INFO Received push request method=POST path=/api/pushes13612026/10/06 21:19:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13622026/10/06 21:19:29 INFO Upload complete. (60ms)13632026/10/06 21:19:29 INFO Uploading xqw9w6lqv7rlv66yxf5izmzspzcwgzpy-pinned-file.txt (128B)1364=== NAME TestClientMultipleUploads1365 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads3166274890/001/store/mn3islspjs08jrh4g3m004vzn3rfdssk-test-file-0.txt1366=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1367=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1368=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1369=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1370=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1371=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1372=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1373=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1374=== CONT TestMultipartCleanup1375=== NAME TestClientPushesUseOnePush1376 client_pushes_test.go:97: Retrieved narinfo from S3:1377 StorePath: /build/TestClientPushesUseOnePush4155942095/001/store/gxxzf2dvhcsykvl715spjk6dfk9sdlgd-shared-dep1378 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1379 Compression: zstd1380 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821381 NarSize: 1361382 References: 1383 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1384 client_pushes_test.go:97: Retrieved narinfo from S3:1385 StorePath: /build/TestClientPushesUseOnePush4155942095/001/store/kd6x5lamajikbnm195bkmwc3g0pjc6l8-a1386 URL: nar/1sa45f71w0mjg0sscwas46habrz4508knk664gq7xmcdxbv2kyny.nar.zst1387 Compression: zstd1388 NarHash: sha256:1sa45f71w0mjg0sscwas46habrz4508knk664gq7xmcdxbv2kyny1389 NarSize: 2161390 References: /build/TestClientPushesUseOnePush4155942095/001/store/gxxzf2dvhcsykvl715spjk6dfk9sdlgd-shared-dep1391 CA: text:sha256:1ka98igbwqxq2yzxzd51xbs94aqd3h4ijdf7gddhfz0gkdp74pky13922026/10/06 21:19:29 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"1393=== NAME TestClientWithDependencies1394 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2072514366/001/store/zcxr23b6wyl2jcf6lqcj96xpixrf37jn-test-script13952026/10/06 21:19:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13962026/10/06 21:19:29 WARN Failed to register uploaded object key=xqw9w6lqv7rlv66yxf5izmzspzcwgzpy.ls error="server returned 404: 404 page not found\n"13972026/10/06 21:19:29 INFO Signed narinfos id=1 count=11398=== NAME TestClientPushesUseOnePush1399 client_pushes_test.go:97: Retrieved narinfo from S3:1400 StorePath: /build/TestClientPushesUseOnePush4155942095/001/store/sccj13s9nr82dpx3l517lrwb24fyfm40-b1401 URL: nar/1sa45f71w0mjg0sscwas46habrz4508knk664gq7xmcdxbv2kyny.nar.zst1402 Compression: zstd1403 NarHash: sha256:1sa45f71w0mjg0sscwas46habrz4508knk664gq7xmcdxbv2kyny1404 NarSize: 2161405 References: /build/TestClientPushesUseOnePush4155942095/001/store/gxxzf2dvhcsykvl715spjk6dfk9sdlgd-shared-dep1406 CA: text:sha256:1ka98igbwqxq2yzxzd51xbs94aqd3h4ijdf7gddhfz0gkdp74pky14072026/10/06 21:19:29 INFO Uploading 1 narinfos14082026/10/06 21:19:29 INFO Received complete push request method=POST path=/api/pushes/1/complete14092026/10/06 21:19:29 WARN Failed to register uploaded object key=xqw9w6lqv7rlv66yxf5izmzspzcwgzpy.narinfo error="server returned 404: 404 page not found\n"1410--- PASS: TestClientPushesUseOnePush (0.64s)1411=== CONT TestIsValidUploadKey1412=== RUN TestIsValidUploadKey/narinfo1413=== PAUSE TestIsValidUploadKey/narinfo1414=== RUN TestIsValidUploadKey/nar_zst1415=== PAUSE TestIsValidUploadKey/nar_zst1416=== RUN TestIsValidUploadKey/nar_xz1417=== PAUSE TestIsValidUploadKey/nar_xz1418=== RUN TestIsValidUploadKey/nar_plain1419=== PAUSE TestIsValidUploadKey/nar_plain1420=== RUN TestIsValidUploadKey/listing1421=== PAUSE TestIsValidUploadKey/listing1422=== RUN TestIsValidUploadKey/build_log1423=== PAUSE TestIsValidUploadKey/build_log1424=== RUN TestIsValidUploadKey/build_log_home-manager_file1425=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1426=== RUN TestIsValidUploadKey/build_log_plus_in_name1427=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1428=== RUN TestIsValidUploadKey/build_log_question_mark1429=== PAUSE TestIsValidUploadKey/build_log_question_mark1430=== RUN TestIsValidUploadKey/build_log_equals1431=== PAUSE TestIsValidUploadKey/build_log_equals1432=== RUN TestIsValidUploadKey/realisation1433=== PAUSE TestIsValidUploadKey/realisation1434=== RUN TestIsValidUploadKey/realisation_plus_in_output1435=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1436=== RUN TestIsValidUploadKey/nix-cache-info1437=== PAUSE TestIsValidUploadKey/nix-cache-info1438=== RUN TestIsValidUploadKey/index.html1439=== PAUSE TestIsValidUploadKey/index.html1440=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1441=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1442=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1443=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1444=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1445=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1446=== RUN TestIsValidUploadKey/traversal1447=== PAUSE TestIsValidUploadKey/traversal1448=== RUN TestIsValidUploadKey/traversal_nar1449=== PAUSE TestIsValidUploadKey/traversal_nar1450=== RUN TestIsValidUploadKey/absolute1451=== PAUSE TestIsValidUploadKey/absolute1452=== RUN TestIsValidUploadKey/empty_key1453=== PAUSE TestIsValidUploadKey/empty_key1454=== RUN TestIsValidUploadKey/unknown_type1455=== PAUSE TestIsValidUploadKey/unknown_type1456=== CONT TestPendingClosureWriteTimeout1457=== RUN TestPendingClosureWriteTimeout/empty1458=== PAUSE TestPendingClosureWriteTimeout/empty1459=== RUN TestPendingClosureWriteTimeout/400_objects1460=== PAUSE TestPendingClosureWriteTimeout/400_objects1461=== RUN TestPendingClosureWriteTimeout/670k_objects1462=== PAUSE TestPendingClosureWriteTimeout/670k_objects1463=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1464=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1465=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info14662026/10/06 21:19:29 INFO Received uploads request method=POST path=/1467=== NAME TestClientMultipleUploads1468 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads3166274890/001/store/qnk9zmmi93kpl4bifsrx9v4nfqyxzh3s-test-file-1.txt1469=== CONT TestProxyWriteTimeout/narinfo1470=== CONT TestProxyWriteTimeout/unknown_size1471=== CONT TestProxyWriteTimeout/10_GiB_nar1472=== CONT TestProxyWriteTimeout/1_GiB_nar1473--- PASS: TestProxyWriteTimeout (0.02s)1474 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1475 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1476 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1477 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1478=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key14792026/10/06 21:19:29 INFO Received complete multipart upload request method=POST path=/1480=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key14812026/10/06 21:19:29 INFO Received request for more parts method=POST path=/1482=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal14832026/10/06 21:19:29 INFO Received uploads request method=POST path=/1484--- PASS: TestUploadHandlersRejectInvalidKeys (0.02s)1485 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1486 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1487 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1488 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1489=== CONT TestGCEndsOnShutdown/before_the_run14902026/10/06 21:19:29 INFO Received push request method=POST path=/api/pushes1491=== NAME TestClientWithDependencies1492 client_integration_test.go:615: Found 1 dependencies (including self)14932026/10/06 21:19:29 INFO Upload complete. (81ms)14942026/10/06 21:19:29 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)14952026/10/06 21:19:29 INFO Uploading br8aqzcp2m6qcqp45884mkz4dcdlrngm-shared-dep (136B)14962026/10/06 21:19:29 INFO Uploading byrxmv17iy42am40w90k4g0x3znpc1a2-top (224B)14972026/10/06 21:19:29 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"14982026/10/06 21:19:29 WARN mTLS auth: bound subjects configured but subject DN unavailable14992026/10/06 21:19:29 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1500--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.34s)1501=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark15022026/10/06 21:19:29 WARN Failed to register uploaded object key=nar/1rxvajgchbb8wgj2v0f9lwnn7lhcvjfjkff7v0d399qblj0fnbcw.nar.zst error="server returned 404: 404 page not found\n"15032026/10/06 21:19:29 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15042026/10/06 21:19:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15052026/10/06 21:19:29 WARN Failed to register uploaded object key=byrxmv17iy42am40w90k4g0x3znpc1a2.ls error="server returned 404: 404 page not found\n"15062026/10/06 21:19:29 WARN Failed to register uploaded object key=br8aqzcp2m6qcqp45884mkz4dcdlrngm.ls error="server returned 404: 404 page not found\n"15072026/10/06 21:19:29 INFO Signed narinfos id=1 count=215082026/10/06 21:19:29 INFO Uploading 2 narinfos15092026/10/06 21:19:30 INFO Received complete push request method=POST path=/api/pushes/1/complete15102026/10/06 21:19:30 WARN Failed to register uploaded object key=byrxmv17iy42am40w90k4g0x3znpc1a2.narinfo error="server returned 404: 404 page not found\n"15112026/10/06 21:19:30 WARN Failed to register uploaded object key=br8aqzcp2m6qcqp45884mkz4dcdlrngm.narinfo error="server returned 404: 404 page not found\n"15122026/10/06 21:19:30 INFO Upload complete. (64ms)1513=== NAME TestClientSharedPathCommittedMidPush1514 client_integration_test.go:680: Retrieved narinfo from S3:1515 StorePath: /build/TestClientSharedPathCommittedMidPush2163957759/001/store/br8aqzcp2m6qcqp45884mkz4dcdlrngm-shared-dep1516 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1517 Compression: zstd1518 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821519 NarSize: 1361520 References: 1521 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1522=== NAME TestClientMultipleUploads1523 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads3166274890/001/store/50zjracipl8vw7yg54qrpdz8rbbrvr4v-test-file-2.txt1524=== NAME TestClientSharedPathCommittedMidPush1525 client_integration_test.go:680: Retrieved narinfo from S3:1526 StorePath: /build/TestClientSharedPathCommittedMidPush2163957759/001/store/byrxmv17iy42am40w90k4g0x3znpc1a2-top1527 URL: nar/1rxvajgchbb8wgj2v0f9lwnn7lhcvjfjkff7v0d399qblj0fnbcw.nar.zst1528 Compression: zstd1529 NarHash: sha256:1rxvajgchbb8wgj2v0f9lwnn7lhcvjfjkff7v0d399qblj0fnbcw1530 NarSize: 2241531 References: /build/TestClientSharedPathCommittedMidPush2163957759/001/store/br8aqzcp2m6qcqp45884mkz4dcdlrngm-shared-dep1532 CA: text:sha256:0qbhd5zvgbnrs7qpa1l794vv1r0js42g2j14fkzbzmcniya98wc31533--- PASS: TestClientSharedPathCommittedMidPush (0.55s)1534=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete15352026/10/06 21:19:30 INFO Received push request method=POST path=/api/pushes15362026/10/06 21:19:30 INFO Received push request method=POST path=/api/pushes15372026/10/06 21:19:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15382026/10/06 21:19:30 INFO Uploading zcxr23b6wyl2jcf6lqcj96xpixrf37jn-test-script (136B)15392026/10/06 21:19:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15402026/10/06 21:19:30 INFO Uploading 766dr62iipabli6395sd2672jv634vqc-unpinned-file.txt (128B)1541=== RUN TestService_RequireScope_OIDC/builder_may_write1542=== PAUSE TestService_RequireScope_OIDC/builder_may_write1543=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1544=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1545=== RUN TestService_RequireScope_OIDC/ops_may_admin1546=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1547=== RUN TestService_RequireScope_OIDC/ops_may_not_write1548=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1549=== RUN TestService_RequireScope_OIDC/reader_may_not_write1550=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1551=== RUN TestService_RequireScope_OIDC/static_token_may_admin1552=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1553=== RUN TestService_RequireScope_OIDC/static_token_may_write1554=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1555=== RUN TestService_RequireScope_OIDC/reader_may_read1556=== PAUSE TestService_RequireScope_OIDC/reader_may_read1557=== RUN TestService_RequireScope_OIDC/writer_implies_read1558=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1559=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1560=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1561=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1562=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1563=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1564=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1565=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1566=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1567=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1568=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1569=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure15702026/10/06 21:19:30 INFO Received uploads request method=POST path=/15712026/10/06 21:19:30 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15722026/10/06 21:19:30 WARN Failed to register uploaded object key=zcxr23b6wyl2jcf6lqcj96xpixrf37jn.ls error="server returned 404: 404 page not found\n"15732026/10/06 21:19:30 WARN Failed to register uploaded object key=log/hmmag3f8qxiajhvwq07qk2l1xd56mpfb-test-script.drv error="server returned 404: 404 page not found\n"15742026/10/06 21:19:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15752026/10/06 21:19:30 INFO Signed narinfos id=1 count=115762026/10/06 21:19:30 INFO Uploading 1 narinfos15772026/10/06 21:19:30 WARN Failed to register uploaded object key=766dr62iipabli6395sd2672jv634vqc.ls error="server returned 404: 404 page not found\n"15782026/10/06 21:19:30 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15792026/10/06 21:19:30 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15802026/10/06 21:19:30 INFO Signed narinfos id=2 count=115812026/10/06 21:19:30 INFO Uploading 1 narinfos1582--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.80s)1583=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart15842026/10/06 21:19:30 INFO Received complete multipart upload request method=POST path=/15852026/10/06 21:19:30 INFO Received complete push request method=POST path=/api/pushes/1/complete15862026/10/06 21:19:30 WARN Failed to register uploaded object key=zcxr23b6wyl2jcf6lqcj96xpixrf37jn.narinfo error="server returned 404: 404 page not found\n"15872026/10/06 21:19:30 INFO Received complete push request method=POST path=/api/pushes/2/complete15882026/10/06 21:19:30 WARN Failed to register uploaded object key=766dr62iipabli6395sd2672jv634vqc.narinfo error="server returned 404: 404 page not found\n"15892026/10/06 21:19:30 INFO Upload complete. (50ms)15902026/10/06 21:19:30 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15912026/10/06 21:19:30 WARN Refused reserved pin name=worker-x86_64-linux15922026/10/06 21:19:30 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15932026/10/06 21:19:30 INFO Received create pin request method=POST path=/api/pins/my-app15942026/10/06 21:19:30 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15952026/10/06 21:19:30 INFO Upload complete. (57ms)1596--- PASS: TestCreatePin_ReservedPins (0.46s)1597=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts15982026/10/06 21:19:30 INFO Received request for more parts method=POST path=/1599=== NAME TestClientWithDependencies1600 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2072514366/001/store) requires matching store prefix1601--- PASS: TestClientWithDependencies (0.59s)1602=== CONT TestPush_RejectsBadRequests/root_not_in_objects16032026/10/06 21:19:30 INFO Received push request method=POST path=/api/pushes1604=== CONT TestPush_RejectsBadRequests/no_objects16052026/10/06 21:19:30 INFO Received push request method=POST path=/api/pushes1606=== CONT TestPush_RejectsBadRequests/no_roots16072026/10/06 21:19:30 INFO Received push request method=POST path=/api/pushes1608=== CONT TestPush_RejectsBadRequests/bad_root16092026/10/06 21:19:30 INFO Received push request method=POST path=/api/pushes1610=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1611--- PASS: TestPush_RejectsBadRequests (0.47s)1612 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1613 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1614 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1615 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)16162026/10/06 21:19:30 INFO Received push request method=POST path=/api/pushes1617--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.35s)1618=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check16192026/10/06 21:19:30 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)16202026/10/06 21:19:30 INFO Uploading mn3islspjs08jrh4g3m004vzn3rfdssk-test-file-0.txt (160B)16212026/10/06 21:19:30 INFO Uploading 50zjracipl8vw7yg54qrpdz8rbbrvr4v-test-file-2.txt (160B)16222026/10/06 21:19:30 INFO Uploading qnk9zmmi93kpl4bifsrx9v4nfqyxzh3s-test-file-1.txt (160B)16232026/10/06 21:19:30 WARN Failed to register uploaded object key=qnk9zmmi93kpl4bifsrx9v4nfqyxzh3s.ls error="server returned 404: 404 page not found\n"16242026/10/06 21:19:30 WARN Failed to register uploaded object key=mn3islspjs08jrh4g3m004vzn3rfdssk.ls error="server returned 404: 404 page not found\n"16252026/10/06 21:19:30 WARN Failed to register uploaded object key=50zjracipl8vw7yg54qrpdz8rbbrvr4v.ls error="server returned 404: 404 page not found\n"16262026/10/06 21:19:30 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"16272026/10/06 21:19:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16282026/10/06 21:19:30 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"16292026/10/06 21:19:30 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"16302026/10/06 21:19:30 INFO Signed narinfos id=1 count=316312026/10/06 21:19:30 INFO Uploading 3 narinfos16322026/10/06 21:19:30 WARN Failed to register uploaded object key=mn3islspjs08jrh4g3m004vzn3rfdssk.narinfo error="server returned 404: 404 page not found\n"16332026/10/06 21:19:30 INFO Received complete push request method=POST path=/api/pushes/1/complete16342026/10/06 21:19:30 WARN Failed to register uploaded object key=50zjracipl8vw7yg54qrpdz8rbbrvr4v.narinfo error="server returned 404: 404 page not found\n"16352026/10/06 21:19:30 WARN Failed to register uploaded object key=qnk9zmmi93kpl4bifsrx9v4nfqyxzh3s.narinfo error="server returned 404: 404 page not found\n"16362026/10/06 21:19:30 INFO Upload complete. (60ms)1637=== NAME TestClientMultipleUploads1638 client_integration_test.go:369: Uploaded 3 paths in 90.407072ms16392026/10/06 21:19:30 INFO Starting cleanup of old closures method=DELETE path=/api/closures16402026/10/06 21:19:30 INFO Garbage collection started1641--- PASS: TestClientMultipleUploads (0.58s)1642=== CONT TestIsValidCachePath/narinfo1643=== CONT TestIsValidCachePath/wrong_extension1644=== CONT TestIsValidCachePath/leading_slash1645=== CONT TestIsValidCachePath/empty1646=== CONT TestIsValidCachePath/random_path1647=== CONT TestIsValidCachePath/short_hash1648=== CONT TestIsValidCachePath/invalid_char_u1649=== CONT TestIsValidCachePath/invalid_char_e1650=== CONT TestIsValidCachePath/traversal_in_middle1651=== CONT TestIsValidCachePath/nar_uncompressed1652=== CONT TestIsValidCachePath/nar_bz21653=== CONT TestIsValidCachePath/nar_xz1654=== CONT TestIsValidCachePath/nar_zst1655=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1656=== CONT TestIsValidCachePath/nix-cache-info1657=== CONT TestIsValidCachePath/traversal_parent1658=== CONT TestIsValidCachePath/index.html1659=== CONT TestIsValidCachePath/realisation1660=== CONT TestIsValidCachePath/log1661=== CONT TestIsValidCachePath/ls1662--- PASS: TestIsValidCachePath (0.00s)1663 --- PASS: TestIsValidCachePath/narinfo (0.00s)1664 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1665 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1666 --- PASS: TestIsValidCachePath/empty (0.00s)1667 --- PASS: TestIsValidCachePath/random_path (0.00s)1668 --- PASS: TestIsValidCachePath/short_hash (0.00s)1669 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1670 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1671 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1672 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1673 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1674 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1675 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1676 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1677 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1678 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1679 --- PASS: TestIsValidCachePath/index.html (0.00s)1680 --- PASS: TestIsValidCachePath/realisation (0.00s)1681 --- PASS: TestIsValidCachePath/log (0.00s)1682 --- PASS: TestIsValidCachePath/ls (0.00s)1683=== CONT TestParseSingleRange/none1684=== CONT TestParseSingleRange/single_byte1685=== CONT TestParseSingleRange/suffix_exceeds_size1686=== CONT TestParseSingleRange/suffix1687=== CONT TestParseSingleRange/end_clamped_to_size1688=== CONT TestParseSingleRange/open-ended1689=== CONT TestParseSingleRange/closed1690=== CONT TestParseSingleRange/malformed_end_before_start1691=== CONT TestParseSingleRange/malformed_both_empty1692=== CONT TestParseSingleRange/malformed_no_dash1693=== CONT TestParseSingleRange/multi-range_ignored1694=== CONT TestParseSingleRange/unknown_unit1695=== CONT TestParseSingleRange/start_far_past_EOF1696=== CONT TestParseSingleRange/start_past_EOF1697--- PASS: TestParseSingleRange (0.00s)1698 --- PASS: TestParseSingleRange/none (0.00s)1699 --- PASS: TestParseSingleRange/single_byte (0.00s)1700 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1701 --- PASS: TestParseSingleRange/suffix (0.00s)1702 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1703 --- PASS: TestParseSingleRange/open-ended (0.00s)1704 --- PASS: TestParseSingleRange/closed (0.00s)1705 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1706 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1707 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1708 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1709 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1710 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1711 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1712=== CONT TestResolveDBConnectionString/flag_wins1713=== CONT TestResolveDBConnectionString/missing_file_is_an_error1714=== CONT TestResolveDBConnectionString/file_when_flag_empty1715=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1716=== CONT TestResolveDBConnectionString/nothing_configured1717=== CONT TestServerTLSConfig/no_client_CA1718=== CONT TestServerTLSConfig/not_a_PEM_file1719--- PASS: TestResolveDBConnectionString (0.00s)1720 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1721 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1722 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1723 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1724 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1725=== CONT TestServerTLSConfig/missing_CA_file1726--- PASS: TestServerTLSConfig (0.00s)1727 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1728 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1729 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1730=== CONT TestCacheConfigHandler/full_config,_no_issuer1731=== CONT TestCacheConfigHandler/no_signing_keys1732=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1733=== CONT TestCacheConfigHandler/no_cache_url_configured1734--- PASS: TestCacheConfigHandler (0.00s)1735 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1736 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1737 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1738 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1739=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale17402026/10/06 21:19:30 INFO Aborted multipart uploads count=0 kept=017412026/10/06 21:19:30 WARN Force mode enabled - objects will be deleted immediately without grace period1742=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1743=== CONT TestClientErrorHandling/InvalidStorePath17442026/10/06 21:19:30 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=017452026/10/06 21:19:30 INFO Vacuumed table table=pending_closures1746=== NAME TestClientIntegration1747 client_integration_test.go:286: Created store path: /build/TestClientIntegration1235714936/002/store/q0kc0llbk1ibgq0jh47iayvd4hrjn86k-test-file.txt17482026/10/06 21:19:30 INFO Vacuumed table table=pending_objects17492026/10/06 21:19:30 INFO Vacuumed table table=multipart_uploads17502026/10/06 21:19:30 INFO Vacuumed table table=closures17512026/10/06 21:19:30 INFO Vacuumed table table=objects17522026/10/06 21:19:30 INFO Received uploads request method=POST path=/api/pending_closures1753--- PASS: TestObjectStatsTrigger (0.30s)1754=== CONT TestClientErrorHandling/ServerNotAvailable1755--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.28s)1756=== CONT TestClientErrorHandling/InvalidAuthToken17572026/10/06 21:19:30 INFO Received uploads request method=POST path=/api/pending_closures17582026/10/06 21:19:30 INFO Received push request method=POST path=/api/pushes17592026/10/06 21:19:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17602026/10/06 21:19:30 INFO Uploading q0kc0llbk1ibgq0jh47iayvd4hrjn86k-test-file.txt (152B)17612026/10/06 21:19:30 INFO Received uploads request method=POST path=/api/pending_closures17622026/10/06 21:19:30 WARN Failed to register uploaded object key=q0kc0llbk1ibgq0jh47iayvd4hrjn86k.ls error="server returned 404: 404 page not found\n"17632026/10/06 21:19:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17642026/10/06 21:19:30 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17652026/10/06 21:19:30 INFO Signed narinfos id=1 count=117662026/10/06 21:19:30 INFO Uploading 1 narinfos17672026/10/06 21:19:30 INFO Received complete push request method=POST path=/api/pushes/1/complete17682026/10/06 21:19:30 WARN Failed to register uploaded object key=q0kc0llbk1ibgq0jh47iayvd4hrjn86k.narinfo error="server returned 404: 404 page not found\n"17692026/10/06 21:19:30 INFO Received cleanup request method=DELETE path=/api/pending_closures17702026/10/06 21:19:30 INFO Upload complete. (55ms)1771=== NAME TestClientCADerivations1772 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2857194436/001/store/h774iyppi1wznsq15z2zvlc8g7gn0cv5-ca-test17732026/10/06 21:19:30 INFO Received uploads request method=POST path=/api/pending_closures17742026/10/06 21:19:30 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/present1775=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1776=== NAME TestClientCADerivations1777 client_ca_test.go:139: Found 1 dependencies (including self)17782026/10/06 21:19:30 INFO All 1 paths already cached1779=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected17802026/10/06 21:19:30 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]1781=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1782=== NAME TestClientIntegration1783 client_integration_test.go:312: Retrieved narinfo from S3:1784 StorePath: /build/TestClientIntegration1235714936/002/store/q0kc0llbk1ibgq0jh47iayvd4hrjn86k-test-file.txt1785 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1786 Compression: zstd1787 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11788 NarSize: 1521789 References: 1790 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk117912026/10/06 21:19:30 WARN Authentication failed token_preview=eyJhbGciOi...OyZE1UkaEA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1792=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1793=== CONT TestIsValidUploadKey/narinfo1794=== CONT TestIsValidUploadKey/realisation_plus_in_output1795=== CONT TestIsValidUploadKey/unknown_type1796=== CONT TestIsValidUploadKey/empty_key1797=== CONT TestIsValidUploadKey/absolute1798=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1799=== CONT TestIsValidUploadKey/index.html1800=== CONT TestIsValidUploadKey/nix-cache-info1801=== CONT TestIsValidUploadKey/build_log_home-manager_file1802=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1803=== CONT TestIsValidUploadKey/realisation1804=== CONT TestIsValidUploadKey/traversal_nar1805=== CONT TestIsValidUploadKey/build_log_equals1806=== CONT TestIsValidUploadKey/traversal1807=== NAME TestClientIntegration1808 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1809=== CONT TestIsValidUploadKey/build_log_question_mark1810=== CONT TestIsValidUploadKey/build_log_plus_in_name1811=== CONT TestIsValidUploadKey/nar_plain1812=== NAME TestClientIntegration1813 client_integration_test.go:313: Decompressed .ls content (64 bytes):1814 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1815--- PASS: TestService_AuthMiddleware_OIDC (0.46s)1816 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1817 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1818 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1819 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1820=== NAME TestClientIntegration1821 client_integration_test.go:316: Testing garbage collection...1822=== CONT TestIsValidUploadKey/build_log1823=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1824=== CONT TestIsValidUploadKey/listing1825=== CONT TestIsValidUploadKey/nar_xz1826=== CONT TestIsValidUploadKey/nar_zst1827=== CONT TestPendingClosureWriteTimeout/empty1828=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1829--- PASS: TestIsValidUploadKey (0.00s)1830 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1831 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1832 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1833 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1834 --- PASS: TestIsValidUploadKey/absolute (0.00s)1835 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1836 --- PASS: TestIsValidUploadKey/index.html (0.00s)1837 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1838 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1839 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1840 --- PASS: TestIsValidUploadKey/realisation (0.00s)1841 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1842 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1843 --- PASS: TestIsValidUploadKey/traversal (0.00s)1844 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1845 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1846 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1847 --- PASS: TestIsValidUploadKey/build_log (0.00s)1848 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1849 --- PASS: TestIsValidUploadKey/listing (0.00s)1850 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1851 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)18522026/10/06 21:19:30 INFO Aborted multipart uploads count=0 kept=018532026/10/06 21:19:30 WARN Force mode enabled - objects will be deleted immediately without grace period18542026/10/06 21:19:30 INFO Starting cleanup of old closures method=DELETE path=/api/closures18552026/10/06 21:19:30 INFO Garbage collection started18562026-10-06 21:19:30.307 UTC [1578] ERROR: canceling statement due to user request18572026-10-06 21:19:30.307 UTC [1578] CONTEXT: PL/pgSQL expression "d_count <> 0 OR d_bytes <> 0"1858 PL/pgSQL function object_stats_apply() line 16 at IF18592026-10-06 21:19:30.307 UTC [1578] STATEMENT: -- name: MarkStaleObjects :execrows1860 WITH RECURSIVE ct AS (1861 SELECT timezone('UTC', now()) AS now1862 ),1863 closure_reach AS (1864 -- Start with all closure keys1865 SELECT o.key, o.refs1866 FROM objects o1867 INNER JOIN closures c ON o.key = c.key1868 UNION1869 -- Recursively add all referenced objects1870 SELECT o.key, o.refs1871 FROM objects o1872 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1873 ),1874 reachable_objects AS (1875 SELECT DISTINCT key FROM closure_reach1876 ),1877 stale_objects AS (1878 SELECT o.key1879 FROM objects AS o, ct1880 WHERE1881 NOT EXISTS (1882 SELECT 11883 FROM reachable_objects ro1884 WHERE ro.key = o.key1885 )1886 AND NOT EXISTS (1887 SELECT 11888 FROM pending_objects AS po1889 WHERE po.key = o.key1890 )1891 AND o.deleted_at IS NULL -- Only mark fresh objects1892 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure1893 FOR UPDATE1894 )1895 UPDATE objects1896 SET1897 deleted_at = ct.now,1898 first_deleted_at = COALESCE(first_deleted_at, ct.now)1899 FROM stale_objects, ct1900 WHERE objects.key = stale_objects.key1901 19022026/10/06 21:19:30 INFO Aborted multipart uploads count=0 kept=01903=== CONT TestPendingClosureWriteTimeout/670k_objects1904=== CONT TestPendingClosureWriteTimeout/400_objects1905=== CONT TestService_RequireScope_OIDC/builder_may_write1906=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1907=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc19082026/10/06 21:19:30 WARN Force mode enabled - objects will be deleted immediately without grace period1909=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1910=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19112026/10/06 21:19:30 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]1912=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1913=== CONT TestService_RequireScope_OIDC/writer_implies_read1914=== CONT TestService_RequireScope_OIDC/ops_may_not_write1915=== CONT TestService_RequireScope_OIDC/reader_may_not_write19162026/10/06 21:19:30 INFO Aborted multipart uploads count=0 kept=01917=== CONT TestService_RequireScope_OIDC/ops_may_admin1918=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1919=== CONT TestService_RequireScope_OIDC/reader_may_read1920=== CONT TestService_RequireScope_OIDC/static_token_may_admin1921=== CONT TestService_RequireScope_OIDC/static_token_may_write1922--- PASS: TestService_RequireScope_OIDC (0.61s)1923 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1924 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1925 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1926 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1927 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1928 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1929 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1930 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1931 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1932 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1933 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1934 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1935 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1936 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)19372026/10/06 21:19:30 WARN Force mode enabled - objects will be deleted immediately without grace period19382026/10/06 21:19:30 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:39943/bucket91/?delete=\": context canceled"1939--- PASS: TestGCEndsOnShutdown (0.06s)1940 --- PASS: TestGCEndsOnShutdown/before_the_run (0.28s)1941 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.32s)1942 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.30s)19432026/10/06 21:19:30 INFO Received uploads request method=POST path=/api/pending_closures19442026/10/06 21:19:30 INFO Aborted multipart uploads count=0 kept=019452026/10/06 21:19:30 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=019462026/10/06 21:19:30 WARN Force mode enabled - objects will be deleted immediately without grace period19472026/10/06 21:19:30 INFO Vacuumed table table=pending_closures19482026/10/06 21:19:30 INFO Vacuumed table table=pending_objects19492026/10/06 21:19:30 INFO Vacuumed table table=multipart_uploads19502026/10/06 21:19:30 INFO Vacuumed table table=closures19512026/10/06 21:19:30 INFO Received uploads request method=POST path=/api/pending_closures19522026/10/06 21:19:30 INFO Vacuumed table table=objects19532026/10/06 21:19:30 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=019542026/10/06 21:19:30 INFO Vacuumed table table=pending_closures19552026/10/06 21:19:30 INFO Vacuumed table table=pending_objects19562026/10/06 21:19:30 INFO Vacuumed table table=multipart_uploads19572026/10/06 21:19:30 INFO Vacuumed table table=closures19582026/10/06 21:19:30 INFO Vacuumed table table=objects19592026/10/06 21:19:30 INFO Aborted multipart uploads count=0 kept=019602026/10/06 21:19:30 WARN Force mode enabled - objects will be deleted immediately without grace period19612026/10/06 21:19:30 INFO Received cleanup request method=DELETE path=/api/pending_closures19622026/10/06 21:19:30 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket88/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""19632026/10/06 21:19:30 INFO Aborted multipart uploads count=0 kept=119642026/10/06 21:19:30 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=019652026/10/06 21:19:30 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=188.629387ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19662026/10/06 21:19:30 INFO Vacuumed table table=pending_closures19672026/10/06 21:19:30 INFO Received cleanup request method=DELETE path=/api/pending_closures19682026/10/06 21:19:30 INFO Vacuumed table table=pending_objects19692026/10/06 21:19:30 INFO Vacuumed table table=multipart_uploads19702026/10/06 21:19:30 INFO Vacuumed table table=closures19712026/10/06 21:19:30 INFO Vacuumed table table=objects19722026/10/06 21:19:30 INFO Aborted multipart uploads count=1 kept=01973--- PASS: TestMultipartCleanup (0.42s)19742026/10/06 21:19:30 INFO Received push request method=POST path=/api/pushes19752026/10/06 21:19:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19762026/10/06 21:19:30 INFO Uploading h774iyppi1wznsq15z2zvlc8g7gn0cv5-ca-test (144B)1977--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1978 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.28s)1979 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.30s)19802026/10/06 21:19:30 WARN Failed to register uploaded object key=log/7pag9vqzslcyajp847sz5gqr323kphas-ca-test.drv error="server returned 404: 404 page not found\n"19812026/10/06 21:19:30 WARN Failed to register uploaded object key=h774iyppi1wznsq15z2zvlc8g7gn0cv5.ls error="server returned 404: 404 page not found\n"19822026/10/06 21:19:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19832026/10/06 21:19:30 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"19842026/10/06 21:19:30 INFO Signed narinfos id=1 count=119852026/10/06 21:19:30 INFO Uploading 1 narinfos19862026/10/06 21:19:30 INFO Received complete push request method=POST path=/api/pushes/1/complete19872026/10/06 21:19:30 WARN Failed to register uploaded object key=h774iyppi1wznsq15z2zvlc8g7gn0cv5.narinfo error="server returned 404: 404 page not found\n"19882026/10/06 21:19:30 INFO Upload complete. (92ms)1989=== NAME TestClientCADerivations1990 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2857194436/001/store/h774iyppi1wznsq15z2zvlc8g7gn0cv5-ca-test1991 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1992 Compression: zstd1993 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1994 NarSize: 1441995 References: 1996 Deriver: /build/TestClientCADerivations2857194436/001/store/7pag9vqzslcyajp847sz5gqr323kphas-ca-test.drv1997 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1998 client_ca_test.go:185: Checking for realisation files in S3...1999 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2000 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache2001=== NAME TestOrphanedObjectsGC2002 orphaned_objects_gc_test.go:287: GC Test Summary:2003 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A2004 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B2005 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)2006 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)2007 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects2008--- PASS: TestOrphanedObjectsGC (0.60s)20092026/10/06 21:19:30 INFO Received uploads request method=POST path=/api/pending_closures2010=== NAME TestClientCADerivations2011 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2012 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2013 error: binary cache 's3://bucket84?endpoint=http://localhost:39943&region=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2857194436/001/store'2014 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 120152026/10/06 21:19:30 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20162026/10/06 21:19:30 INFO lead: released remote=192.0.2.1:12342017--- PASS: TestLeadEndsOnShutdown (1.47s)20182026/10/06 21:19:30 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=416.65493ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2019--- PASS: TestClientCADerivations (0.67s)20202026/10/06 21:19:30 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20212026/10/06 21:19:30 INFO lead: released remote=192.0.2.1:123420222026/10/06 21:19:30 INFO lead: acquired remote=192.0.2.1:12342023--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2024 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.74s)2025 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.75s)2026--- PASS: TestDeleteClosuresRacingPins (1.61s)20272026/10/06 21:19:30 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=801.606224ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2028--- PASS: TestUploadHandlersRejectOversizedBody (0.15s)2029 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)2030 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)2031 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.04s)2032--- PASS: TestPendingClosureWriteTimeout (0.00s)2033 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2034 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2035 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2036 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (0.96s)2037=== NAME TestOrphanedObjectsGCStressTest2038 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2039 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion2040 orphaned_objects_gc_test.go:503: Stress test completed successfully:2041 orphaned_objects_gc_test.go:504: - Active objects preserved: 202042 orphaned_objects_gc_test.go:505: - Objects deleted: 2102043 orphaned_objects_gc_test.go:506: - Total GC'd: 2102044--- PASS: TestOrphanedObjectsGCStressTest (1.83s)20452026/10/06 21:19:31 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.590906827s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20462026/10/06 21:19:31 INFO lead: released remote=192.0.2.1:12342047--- PASS: TestLeadElectsOneAndHandsOver (2.73s)20482026/10/06 21:19:32 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020492026/10/06 21:19:32 INFO Received create pin request method=POST path=/api/pins/myapp20502026/10/06 21:19:32 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC4113095903/001/store/xqw9w6lqv7rlv66yxf5izmzspzcwgzpy-pinned-file.txt narinfo_key=xqw9w6lqv7rlv66yxf5izmzspzcwgzpy.narinfo20512026/10/06 21:19:32 INFO Starting cleanup of old closures method=DELETE path=/api/closures20522026/10/06 21:19:32 INFO Garbage collection started20532026/10/06 21:19:32 INFO Aborted multipart uploads count=0 kept=020542026/10/06 21:19:32 WARN Force mode enabled - objects will be deleted immediately without grace period20552026/10/06 21:19:32 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=020562026/10/06 21:19:32 INFO Vacuumed table table=pending_closures20572026/10/06 21:19:32 INFO Vacuumed table table=pending_objects20582026/10/06 21:19:32 INFO Vacuumed table table=multipart_uploads20592026/10/06 21:19:32 INFO Vacuumed table table=closures20602026/10/06 21:19:32 INFO Vacuumed table table=objects20612026/10/06 21:19:32 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02062=== NAME TestClientIntegration2063 client_integration_test.go:323: Objects in database after GC:2064 client_integration_test.go:323: Successfully deleted all objects with GC --force2065--- PASS: TestClientIntegration (2.55s)20662026/10/06 21:19:33 WARN Rate limiter enabled after throttle name=s3-test rate=520672026/10/06 21:19:33 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2068=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2069 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102070 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002071--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.21s)2072--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.62s)20732026/10/06 21:19:33 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-config20742026/10/06 21:19:33 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=189.256549ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20752026/10/06 21:19:33 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=389.140595ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20762026/10/06 21:19:34 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=744.128097ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2077=== NAME TestPinProtectsFromGC2078 client_integration_test.go:840: Pin successfully protected closure from garbage collection2079--- PASS: TestPinProtectsFromGC (4.73s)2080--- PASS: TestConnectWaitsForAPeerMigration (5.13s)20812026/10/06 21:19:34 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.585082038s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20822026/10/06 21:19:36 INFO Aborted multipart uploads count=1 kept=020832026/10/06 21:19:36 INFO Received cleanup request method=DELETE path=/api/pending_closures20842026/10/06 21:19:36 INFO Aborted multipart uploads count=1 kept=02085--- PASS: TestPendingCleanupUsesOneCutoff (6.31s)20862026/10/06 21:19:36 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"20872026/10/06 21:19:36 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-config20882026/10/06 21:19:36 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=180.870333ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20892026/10/06 21:19:36 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=382.187372ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20902026/10/06 21:19:37 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=848.318667ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20912026/10/06 21:19:37 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.543378822s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20922026/10/06 21:19:39 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_closures20932026/10/06 21:19:39 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=205.399378ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20942026/10/06 21:19:39 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=430.703861ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20952026/10/06 21:19:40 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=792.609242ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20962026/10/06 21:19:41 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.581693977s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2097--- PASS: TestClientErrorHandling (0.00s)2098 --- PASS: TestClientErrorHandling/InvalidStorePath (0.29s)2099 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.39s)2100 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.41s)2101PASS21022026-10-06 21:19:42.831 UTC [128] LOG: received smart shutdown request21032026-10-06 21:19:42.836 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 121042026-10-06 21:19:42.848 UTC [133] LOG: shutting down21052026-10-06 21:19:42.848 UTC [133] LOG: checkpoint starting: shutdown immediate21062026-10-06 21:19:43.280 UTC [133] LOG: checkpoint complete: wrote 10610 buffers (64.8%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 30 recycled; write=0.180 s, sync=0.228 s, total=0.433 s; sync files=33373, longest=0.030 s, average=0.001 s; distance=484121 kB, estimate=484121 kB; lsn=0/1F02C188, redo lsn=0/1F02C18821072026-10-06 21:19:43.350 UTC [128] LOG: database system is shut down2108Running OIDC tests...2109=== RUN TestAudienceForIssuer2110=== PAUSE TestAudienceForIssuer2111=== RUN TestGlobMatch2112=== PAUSE TestGlobMatch2113=== RUN TestValidateToken_ValidToken2114=== PAUSE TestValidateToken_ValidToken2115=== RUN TestValidateToken_WrongAudience2116=== PAUSE TestValidateToken_WrongAudience2117=== RUN TestValidateToken_Expired2118=== PAUSE TestValidateToken_Expired2119=== RUN TestValidateToken_BoundClaimsMismatch2120=== PAUSE TestValidateToken_BoundClaimsMismatch2121=== RUN TestValidateToken_BoundSubjectMismatch2122=== PAUSE TestValidateToken_BoundSubjectMismatch2123=== RUN TestValidateToken_MultipleProviders2124=== PAUSE TestValidateToken_MultipleProviders2125=== RUN TestValidateToken_NoMatchingProvider2126=== PAUSE TestValidateToken_NoMatchingProvider2127=== RUN TestValidateToken_KubernetesServiceAccount2128=== PAUSE TestValidateToken_KubernetesServiceAccount2129=== RUN TestNewValidator_KubernetesRequiresCA2130=== PAUSE TestNewValidator_KubernetesRequiresCA2131=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2132=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2133=== RUN TestPins_ReservedForMatchingRule2134=== PAUSE TestPins_ReservedForMatchingRule2135=== RUN TestPins_TopLevelShorthand2136=== PAUSE TestPins_TopLevelShorthand2137=== RUN TestPins_ConfigValidation2138=== PAUSE TestPins_ConfigValidation2139=== RUN TestScopes_LegacyProviderDefaultsToWrite2140=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2141=== RUN TestScopes_Rules2142=== PAUSE TestScopes_Rules2143=== RUN TestScopes_ConfigValidation2144=== PAUSE TestScopes_ConfigValidation2145=== CONT TestAudienceForIssuer2146=== CONT TestValidateToken_BoundClaimsMismatch2147=== CONT TestValidateToken_NoMatchingProvider2148=== CONT TestValidateToken_MultipleProviders2149--- PASS: TestAudienceForIssuer (0.00s)2150=== CONT TestValidateToken_KubernetesServiceAccount2151=== CONT TestValidateToken_Expired2152=== CONT TestValidateToken_WrongAudience2153=== CONT TestValidateToken_ValidToken2154=== CONT TestScopes_ConfigValidation2155=== CONT TestGlobMatch2156=== RUN TestGlobMatch/foo_foo2157=== PAUSE TestGlobMatch/foo_foo2158=== RUN TestGlobMatch/foo_bar2159=== PAUSE TestGlobMatch/foo_bar2160=== RUN TestGlobMatch/*_2161=== PAUSE TestGlobMatch/*_2162=== RUN TestGlobMatch/*_anything2163=== PAUSE TestGlobMatch/*_anything2164=== RUN TestGlobMatch/foo*_foo2165=== PAUSE TestGlobMatch/foo*_foo2166=== RUN TestGlobMatch/foo*_foobar2167=== CONT TestScopes_Rules2168=== CONT TestScopes_LegacyProviderDefaultsToWrite2169=== CONT TestPins_ConfigValidation2170=== CONT TestPins_TopLevelShorthand2171=== CONT TestPins_ReservedForMatchingRule2172=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2173=== CONT TestNewValidator_KubernetesRequiresCA2174=== CONT TestValidateToken_BoundSubjectMismatch2175--- PASS: TestScopes_ConfigValidation (0.00s)2176--- PASS: TestPins_ConfigValidation (0.00s)2177=== PAUSE TestGlobMatch/foo*_foobar2178=== RUN TestGlobMatch/foo*_bar2179=== PAUSE TestGlobMatch/foo*_bar2180=== RUN TestGlobMatch/*bar_bar2181=== PAUSE TestGlobMatch/*bar_bar2182=== RUN TestGlobMatch/*bar_foobar2183=== PAUSE TestGlobMatch/*bar_foobar2184=== RUN TestGlobMatch/*bar_foo2185=== PAUSE TestGlobMatch/*bar_foo2186=== RUN TestGlobMatch/foo*bar_foobar2187=== PAUSE TestGlobMatch/foo*bar_foobar2188=== RUN TestGlobMatch/foo*bar_foo123bar2189=== PAUSE TestGlobMatch/foo*bar_foo123bar2190=== RUN TestGlobMatch/foo*bar_foobarbaz2191=== PAUSE TestGlobMatch/foo*bar_foobarbaz2192=== RUN TestGlobMatch/*/*_foo/bar2193=== PAUSE TestGlobMatch/*/*_foo/bar2194=== RUN TestGlobMatch/*/*_foo2195=== PAUSE TestGlobMatch/*/*_foo2196=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2197=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2198=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02199=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02200=== RUN TestGlobMatch/refs/*/main_refs/heads/main2201=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2202=== RUN TestGlobMatch/fo?_foo2203=== PAUSE TestGlobMatch/fo?_foo2204=== RUN TestGlobMatch/fo?_fo2205=== PAUSE TestGlobMatch/fo?_fo2206=== RUN TestGlobMatch/fo?_fooo2207=== PAUSE TestGlobMatch/fo?_fooo2208=== RUN TestGlobMatch/?oo_foo2209=== PAUSE TestGlobMatch/?oo_foo2210=== RUN TestGlobMatch/?oo_boo2211=== PAUSE TestGlobMatch/?oo_boo2212=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2213=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2214=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2215=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2216=== CONT TestGlobMatch/foo_foo2217=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2218=== CONT TestGlobMatch/?oo_boo2219=== CONT TestGlobMatch/?oo_foo2220=== CONT TestGlobMatch/fo?_fooo2221=== CONT TestGlobMatch/fo?_fo2222=== CONT TestGlobMatch/fo?_foo2223=== CONT TestGlobMatch/refs/*/main_refs/heads/main2224=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02225=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2226=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2227=== CONT TestGlobMatch/foo*_foobar2228=== CONT TestGlobMatch/foo*_foo2229=== CONT TestGlobMatch/*_anything2230=== CONT TestGlobMatch/*_2231=== CONT TestGlobMatch/foo_bar2232=== CONT TestGlobMatch/*/*_foo2233=== CONT TestGlobMatch/*/*_foo/bar2234=== CONT TestGlobMatch/foo*bar_foobarbaz2235=== CONT TestGlobMatch/foo*bar_foo123bar2236=== CONT TestGlobMatch/foo*bar_foobar2237=== CONT TestGlobMatch/*bar_foo2238=== CONT TestGlobMatch/*bar_foobar2239=== CONT TestGlobMatch/*bar_bar2240=== CONT TestGlobMatch/foo*_bar2241--- PASS: TestGlobMatch (0.00s)2242 --- PASS: TestGlobMatch/foo_foo (0.00s)2243 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2244 --- PASS: TestGlobMatch/?oo_boo (0.00s)2245 --- PASS: TestGlobMatch/?oo_foo (0.00s)2246 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2247 --- PASS: TestGlobMatch/fo?_fo (0.00s)2248 --- PASS: TestGlobMatch/fo?_foo (0.00s)2249 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2250 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2251 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2252 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2253 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2254 --- PASS: TestGlobMatch/foo*_foo (0.00s)2255 --- PASS: TestGlobMatch/*_anything (0.00s)2256 --- PASS: TestGlobMatch/*_ (0.00s)2257 --- PASS: TestGlobMatch/foo_bar (0.00s)2258 --- PASS: TestGlobMatch/*/*_foo (0.00s)2259 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2260 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2261 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2262 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2263 --- PASS: TestGlobMatch/*bar_foo (0.00s)2264 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2265 --- PASS: TestGlobMatch/*bar_bar (0.00s)2266 --- PASS: TestGlobMatch/foo*_bar (0.00s)22672026/10/06 21:19:44 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:344952268--- PASS: TestValidateToken_KubernetesServiceAccount (0.03s)22692026/10/06 21:19:44 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232270--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.08s)22712026/10/06 21:19:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44027/oidc2272--- PASS: TestScopes_Rules (0.10s)22732026/10/06 21:19:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44645/oidc22742026/10/06 21:19:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35053/oidc22752026/10/06 21:19:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37723/oidc2276--- PASS: TestValidateToken_ValidToken (0.12s)2277--- PASS: TestValidateToken_BoundClaimsMismatch (0.12s)2278--- PASS: TestValidateToken_Expired (0.13s)22792026/10/06 21:19:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38855/oidc22802026/10/06 21:19:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38933/oidc2281--- PASS: TestValidateToken_WrongAudience (0.14s)22822026/10/06 21:19:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45505/oidc2283--- PASS: TestPins_ReservedForMatchingRule (0.14s)2284--- PASS: TestValidateToken_BoundSubjectMismatch (0.14s)22852026/10/06 21:19:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44333/oidc2286--- PASS: TestPins_TopLevelShorthand (0.17s)22872026/10/06 21:19:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34599/oidc2288--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.20s)22892026/10/06 21:19:45 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:36571/oidc2290--- PASS: TestValidateToken_NoMatchingProvider (0.28s)22912026/10/06 21:19:45 http: TLS handshake error from 127.0.0.1:36160: remote error: tls: bad certificate2292--- PASS: TestNewValidator_KubernetesRequiresCA (0.30s)22932026/10/06 21:19:45 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:42731/oidc22942026/10/06 21:19:45 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:46069/oidc2295--- PASS: TestValidateToken_MultipleProviders (0.33s)2296PASS2297Running hook tests...2298=== RUN TestSendPathsEmpty2299=== PAUSE TestSendPathsEmpty2300=== RUN TestQueueEnqueueAndFetch2301=== PAUSE TestQueueEnqueueAndFetch2302=== RUN TestQueueDeduplication2303=== PAUSE TestQueueDeduplication2304=== RUN TestQueueRemove2305=== PAUSE TestQueueRemove2306=== RUN TestQueueFetchBatchLimit2307=== PAUSE TestQueueFetchBatchLimit2308=== RUN TestQueueRetryMovesToBack2309=== PAUSE TestQueueRetryMovesToBack2310=== RUN TestQueueFetchRemoveLifecycle2311=== PAUSE TestQueueFetchRemoveLifecycle2312=== RUN TestQueueConcurrentWriters2313=== PAUSE TestQueueConcurrentWriters2314=== RUN TestQueueRemoveLargeClosure2315=== PAUSE TestQueueRemoveLargeClosure2316=== RUN TestServerClientIntegration2317=== PAUSE TestServerClientIntegration2318=== RUN TestServerQueueError2319=== PAUSE TestServerQueueError2320=== RUN TestGetListenerSocketActivation2321 server_test.go:210: === RUN TestGetListenerSocketActivation2322 --- PASS: TestGetListenerSocketActivation (0.00s)2323 PASS2324 2325--- PASS: TestGetListenerSocketActivation (0.01s)2326=== RUN TestDrainIsolatesPoisonPath2327=== PAUSE TestDrainIsolatesPoisonPath2328=== RUN TestRunNotBlockedByPoisonHead2329=== PAUSE TestRunNotBlockedByPoisonHead2330=== RUN TestDrainGivesUpWhenServerDown2331=== PAUSE TestDrainGivesUpWhenServerDown2332=== RUN TestFailedPathPrunedByLaterClosure2333=== PAUSE TestFailedPathPrunedByLaterClosure2334=== RUN TestWorkerUploadsAndRemoves2335=== PAUSE TestWorkerUploadsAndRemoves2336=== RUN TestWorkerSkipsGCdPaths2337=== PAUSE TestWorkerSkipsGCdPaths2338=== RUN TestWorkerPrunesClosureDeps2339=== PAUSE TestWorkerPrunesClosureDeps2340=== RUN TestDrainTimeout2341=== PAUSE TestDrainTimeout2342=== CONT TestSendPathsEmpty2343=== CONT TestDrainGivesUpWhenServerDown2344=== CONT TestQueueRemove2345--- PASS: TestSendPathsEmpty (0.00s)2346=== CONT TestRunNotBlockedByPoisonHead2347=== CONT TestDrainIsolatesPoisonPath2348=== CONT TestServerQueueError2349=== CONT TestServerClientIntegration2350=== CONT TestQueueRemoveLargeClosure2351=== CONT TestQueueConcurrentWriters2352=== CONT TestQueueFetchRemoveLifecycle2353=== CONT TestWorkerSkipsGCdPaths23542026/10/06 21:19:45 ERROR Failed to queue paths error="permission denied" count=12355=== CONT TestQueueRetryMovesToBack2356=== CONT TestQueueDeduplication2357=== CONT TestDrainTimeout2358=== CONT TestQueueEnqueueAndFetch2359=== CONT TestWorkerPrunesClosureDeps2360--- PASS: TestServerQueueError (0.00s)2361=== CONT TestQueueFetchBatchLimit2362=== CONT TestWorkerUploadsAndRemoves2363--- PASS: TestServerClientIntegration (0.00s)2364=== CONT TestFailedPathPrunedByLaterClosure2365--- PASS: TestQueueFetchBatchLimit (0.01s)23662026/10/06 21:19:45 INFO Uploading batch count=123672026/10/06 21:19:45 ERROR Upload failed error="upload failed" count=123682026/10/06 21:19:45 INFO Uploading batch count=423692026/10/06 21:19:45 ERROR Upload failed error="upload failed" count=423702026/10/06 21:19:45 INFO Upload queue status pending=223712026/10/06 21:19:45 INFO Uploading batch count=223722026/10/06 21:19:45 ERROR Upload failed error="upload failed" count=223732026/10/06 21:19:45 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2333892988/002/a2374--- PASS: TestQueueEnqueueAndFetch (0.01s)2375--- PASS: TestQueueDeduplication (0.01s)23762026/10/06 21:19:45 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1213058909/002/nonexistent23772026/10/06 21:19:45 INFO Uploading batch count=223782026/10/06 21:19:45 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath938801029/002/bbb23792026/10/06 21:19:45 INFO Upload queue status pending=323802026/10/06 21:19:45 INFO Uploading batch count=123812026/10/06 21:19:45 ERROR Upload failed error="upload failed" count=123822026/10/06 21:19:45 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2333892988/002/b23832026/10/06 21:19:45 INFO Uploading batch count=12384--- PASS: TestQueueRemove (0.02s)23852026/10/06 21:19:45 INFO Upload queue status pending=223862026/10/06 21:19:45 INFO Upload queue status pending=223872026/10/06 21:19:45 INFO Uploading batch count=12388--- PASS: TestQueueFetchRemoveLifecycle (0.01s)23892026/10/06 21:19:45 INFO Uploading batch count=223902026/10/06 21:19:45 INFO Uploading batch count=123912026/10/06 21:19:45 INFO Uploading batch count=22392--- PASS: TestQueueRetryMovesToBack (0.01s)23932026/10/06 21:19:45 ERROR Upload failed error="upload failed" count=223942026/10/06 21:19:45 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2333892988/002/c23952026/10/06 21:19:45 INFO Uploading batch count=123962026/10/06 21:19:45 ERROR Upload failed error="upload failed" count=123972026/10/06 21:19:45 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2333892988/002/d23982026/10/06 21:19:45 INFO Uploading batch count=123992026/10/06 21:19:45 INFO Uploading batch count=124002026/10/06 21:19:45 ERROR Upload failed error="upload failed" count=124012026/10/06 21:19:45 INFO Uploading batch count=224022026/10/06 21:19:45 ERROR Upload failed error="upload failed" count=224032026/10/06 21:19:45 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2333892988/002/e24042026/10/06 21:19:45 INFO Uploading batch count=124052026/10/06 21:19:45 ERROR Upload failed error="upload failed" count=124062026/10/06 21:19:45 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2333892988/002/f24072026/10/06 21:19:45 ERROR Drain finished with paths left in queue remaining=124082026/10/06 21:19:45 ERROR Drain finished with paths left in queue remaining=102409--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)2410--- PASS: TestDrainIsolatesPoisonPath (0.02s)2411--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2412--- PASS: TestWorkerSkipsGCdPaths (0.03s)2413--- PASS: TestWorkerUploadsAndRemoves (0.03s)2414--- PASS: TestWorkerPrunesClosureDeps (0.03s)2415--- PASS: TestQueueRemoveLargeClosure (0.09s)2416--- PASS: TestQueueConcurrentWriters (0.13s)24172026/10/06 21:19:45 ERROR Upload failed error="context deadline exceeded" count=224182026/10/06 21:19:45 ERROR Drain finished with paths left in queue remaining=42419--- PASS: TestDrainTimeout (0.21s)24202026/10/06 21:19:46 INFO Uploading batch count=124212026/10/06 21:19:46 INFO Uploading batch count=124222026/10/06 21:19:46 INFO Uploading batch count=124232026/10/06 21:19:46 ERROR Upload failed error="upload failed" count=124242026/10/06 21:19:46 INFO Uploading batch count=124252026/10/06 21:19:46 ERROR Upload failed error="upload failed" count=124262026/10/06 21:19:46 INFO Uploading batch count=124272026/10/06 21:19:46 ERROR Upload failed error="upload failed" count=124282026/10/06 21:19:46 INFO Uploading batch count=124292026/10/06 21:19:46 ERROR Upload failed error="upload failed" count=124302026/10/06 21:19:46 ERROR Drain finished with paths left in queue remaining=12431--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2432PASS2433Running signing tests...2434=== RUN TestExternalSigner2435=== PAUSE TestExternalSigner2436=== RUN TestExternalSignerWrongPublicKey2437=== PAUSE TestExternalSignerWrongPublicKey2438=== RUN TestExternalSignerErrors2439=== PAUSE TestExternalSignerErrors2440=== RUN TestExternalSignerRestartsAfterCrash2441=== PAUSE TestExternalSignerRestartsAfterCrash2442=== RUN TestExternalSignerProgramErrorKeepsProcess2443=== PAUSE TestExternalSignerProgramErrorKeepsProcess2444=== RUN TestExternalSignerClose2445=== PAUSE TestExternalSignerClose2446=== RUN TestExternalSignerRejectsInvalidPublicKey2447=== PAUSE TestExternalSignerRejectsInvalidPublicKey2448=== RUN TestExternalSignerCancellation2449=== PAUSE TestExternalSignerCancellation2450=== RUN TestGenerateFingerprint2451=== PAUSE TestGenerateFingerprint2452=== RUN TestParseSigningKey2453=== PAUSE TestParseSigningKey2454=== RUN TestSign2455=== PAUSE TestSign2456=== RUN TestSignBatch2457=== PAUSE TestSignBatch2458=== RUN TestNilKeyPublicKey2459=== PAUSE TestNilKeyPublicKey2460=== RUN TestSignErrors2461=== PAUSE TestSignErrors2462=== CONT TestExternalSigner2463=== CONT TestExternalSignerCancellation2464=== CONT TestExternalSignerProgramErrorKeepsProcess2465=== CONT TestSign2466=== CONT TestParseSigningKey2467=== RUN TestParseSigningKey/valid_32-byte_key2468=== PAUSE TestParseSigningKey/valid_32-byte_key2469=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2470=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2471=== RUN TestParseSigningKey/no_colon2472=== PAUSE TestParseSigningKey/no_colon2473=== RUN TestParseSigningKey/empty_name2474=== PAUSE TestParseSigningKey/empty_name2475=== CONT TestGenerateFingerprint2476=== CONT TestExternalSignerErrors2477=== CONT TestExternalSignerRestartsAfterCrash2478=== CONT TestExternalSignerRejectsInvalidPublicKey2479=== RUN TestExternalSignerRejectsInvalidPublicKey/#002480=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002481=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2482=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2483=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2484=== CONT TestSignErrors2485=== CONT TestNilKeyPublicKey2486=== CONT TestExternalSignerWrongPublicKey2487=== CONT TestSignBatch2488=== RUN TestParseSigningKey/invalid_base642489--- PASS: TestNilKeyPublicKey (0.00s)2490=== RUN TestGenerateFingerprint/basic_with_references2491=== RUN TestExternalSignerErrors/exit_at_startup2492=== PAUSE TestExternalSignerErrors/exit_at_startup2493=== RUN TestExternalSignerErrors/exit_on_request2494=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2495=== CONT TestExternalSignerClose2496=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2497=== PAUSE TestParseSigningKey/invalid_base642498=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2499=== PAUSE TestExternalSignerErrors/exit_on_request2500=== PAUSE TestGenerateFingerprint/basic_with_references2501=== RUN TestExternalSignerErrors/wrong_signatures_shape2502=== RUN TestGenerateFingerprint/no_references2503=== PAUSE TestGenerateFingerprint/no_references2504=== RUN TestParseSigningKey/wrong_length2505=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2506=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2507=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2508=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2509=== RUN TestGenerateFingerprint/invalid_nar_hash_length2510=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2511=== RUN TestGenerateFingerprint/invalid_store_path_prefix2512=== PAUSE TestParseSigningKey/wrong_length2513=== CONT TestParseSigningKey/valid_32-byte_key2514=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2515=== RUN TestExternalSignerErrors/wrong_signature_length2516=== CONT TestParseSigningKey/wrong_length2517=== CONT TestParseSigningKey/invalid_base642518=== CONT TestParseSigningKey/empty_name2519=== PAUSE TestExternalSignerErrors/wrong_signature_length2520=== RUN TestExternalSignerErrors/invalid_JSON2521=== PAUSE TestExternalSignerErrors/invalid_JSON2522=== RUN TestExternalSignerErrors/too_few_signatures2523=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2524=== RUN TestGenerateFingerprint/invalid_reference_prefix2525=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2526=== CONT TestGenerateFingerprint/basic_with_references2527=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2528=== CONT TestParseSigningKey/no_colon2529=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2530=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2531=== CONT TestExternalSignerRejectsInvalidPublicKey/#002532=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2533=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2534=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2535=== PAUSE TestExternalSignerErrors/too_few_signatures2536=== RUN TestExternalSignerErrors/missing_signature_name2537=== PAUSE TestExternalSignerErrors/missing_signature_name2538=== CONT TestGenerateFingerprint/invalid_nar_hash_length2539=== CONT TestGenerateFingerprint/invalid_reference_prefix2540=== CONT TestGenerateFingerprint/invalid_store_path_prefix2541=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2542=== CONT TestGenerateFingerprint/no_references2543=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2544=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2545=== RUN TestExternalSignerErrors/wrong_shape2546=== PAUSE TestExternalSignerErrors/wrong_shape2547=== RUN TestExternalSignerErrors/null2548=== PAUSE TestExternalSignerErrors/null2549=== RUN TestExternalSignerErrors/wrong_id2550=== PAUSE TestExternalSignerErrors/wrong_id2551--- PASS: TestGenerateFingerprint (0.00s)2552 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2553 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2554 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2555 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2556 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2557 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2558 --- PASS: TestGenerateFingerprint/no_references (0.00s)2559--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2560 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2561 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2562 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2563 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2564 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2565=== RUN TestSignErrors/nil_key2566=== PAUSE TestSignErrors/nil_key2567=== RUN TestSignErrors/nil_narinfo2568=== PAUSE TestSignErrors/nil_narinfo2569=== RUN TestSignErrors/invalid_narinfo2570=== RUN TestExternalSignerErrors/missing_signatures2571--- PASS: TestSign (0.00s)2572=== PAUSE TestExternalSignerErrors/missing_signatures2573=== RUN TestExternalSignerErrors/unrequested_key2574--- PASS: TestParseSigningKey (0.00s)2575 --- PASS: TestParseSigningKey/wrong_length (0.00s)2576 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2577 --- PASS: TestParseSigningKey/empty_name (0.00s)2578 --- PASS: TestParseSigningKey/no_colon (0.00s)2579 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2580 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2581=== PAUSE TestExternalSignerErrors/unrequested_key2582=== RUN TestExternalSignerErrors/invalid_signature_base642583=== PAUSE TestExternalSignerErrors/invalid_signature_base642584=== RUN TestExternalSignerErrors/program_error2585=== PAUSE TestExternalSignerErrors/program_error2586=== PAUSE TestSignErrors/invalid_narinfo2587=== RUN TestSignErrors/canceled2588=== PAUSE TestSignErrors/canceled2589=== CONT TestSignErrors/nil_key2590=== CONT TestSignErrors/invalid_narinfo2591=== CONT TestSignErrors/canceled2592=== CONT TestSignErrors/nil_narinfo2593--- PASS: TestSignErrors (0.00s)2594 --- PASS: TestSignErrors/nil_key (0.00s)2595 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2596 --- PASS: TestSignErrors/canceled (0.00s)2597 --- PASS: TestSignErrors/nil_narinfo (0.00s)2598=== RUN TestExternalSignerErrors/null_signatures2599=== PAUSE TestExternalSignerErrors/null_signatures2600=== RUN TestExternalSignerErrors/wrong_signature_name2601=== PAUSE TestExternalSignerErrors/wrong_signature_name2602=== CONT TestExternalSignerErrors/exit_at_startup2603=== CONT TestExternalSignerErrors/invalid_JSON2604=== CONT TestExternalSignerErrors/too_few_signatures2605=== CONT TestExternalSignerErrors/unrequested_key2606--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2607=== CONT TestExternalSignerErrors/wrong_signature_name2608=== CONT TestExternalSignerErrors/wrong_shape2609=== CONT TestExternalSignerErrors/program_error2610=== CONT TestExternalSignerErrors/invalid_signature_base642611=== CONT TestExternalSignerErrors/missing_signatures2612=== CONT TestExternalSignerErrors/wrong_id2613=== CONT TestExternalSignerErrors/null2614=== CONT TestExternalSignerErrors/missing_signature_name2615=== CONT TestExternalSignerErrors/wrong_signatures_shape2616=== CONT TestExternalSignerErrors/wrong_signature_length2617=== CONT TestExternalSignerErrors/exit_on_request2618=== CONT TestExternalSignerErrors/null_signatures2619--- PASS: TestSignBatch (0.00s)2620--- PASS: TestExternalSignerClose (0.01s)2621--- PASS: TestExternalSignerWrongPublicKey (0.01s)2622--- PASS: TestExternalSigner (0.01s)2623--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2624--- PASS: TestExternalSignerErrors (0.00s)2625 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2626 --- PASS: TestExternalSignerErrors/invalid_JSON (0.00s)2627 --- PASS: TestExternalSignerErrors/unrequested_key (0.00s)2628 --- PASS: TestExternalSignerErrors/program_error (0.00s)2629 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2630 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2631 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2632 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2633 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2634 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2635 --- PASS: TestExternalSignerErrors/null_signatures (0.00s)2636 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2637 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2638 --- PASS: TestExternalSignerErrors/null (0.01s)2639 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2640 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.00s)2641--- PASS: TestExternalSignerCancellation (0.02s)2642PASS2643Running OpenBao signer tests...2644=== RUN TestSign2645=== PAUSE TestSign2646=== RUN TestSignErrors2647=== PAUSE TestSignErrors2648=== RUN TestServe2649=== PAUSE TestServe2650=== RUN TestServeRejectsGarbage2651=== PAUSE TestServeRejectsGarbage2652=== CONT TestSign2653=== CONT TestServe2654=== CONT TestSignErrors2655=== CONT TestServeRejectsGarbage2656=== RUN TestSignErrors/http_error2657=== PAUSE TestSignErrors/http_error2658=== RUN TestSignErrors/invalid_json2659=== PAUSE TestSignErrors/invalid_json2660--- PASS: TestServeRejectsGarbage (0.00s)2661=== RUN TestSignErrors/no_prefix2662=== PAUSE TestSignErrors/no_prefix2663=== RUN TestSignErrors/invalid_base642664=== PAUSE TestSignErrors/invalid_base642665=== CONT TestSignErrors/http_error2666=== CONT TestSignErrors/no_prefix2667=== CONT TestSignErrors/invalid_base642668--- PASS: TestServe (0.00s)2669=== CONT TestSignErrors/invalid_json2670--- PASS: TestSign (0.00s)2671--- PASS: TestSignErrors (0.00s)2672 --- PASS: TestSignErrors/invalid_base64 (0.00s)2673 --- PASS: TestSignErrors/invalid_json (0.00s)2674 --- PASS: TestSignErrors/no_prefix (0.00s)2675 --- PASS: TestSignErrors/http_error (0.00s)2676PASS