niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #363
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestRegisterUploadedObjectReusesConnections5=== PAUSE TestRegisterUploadedObjectReusesConnections6=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica7=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica8=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun9=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun10=== RUN TestCaseHackSuffix11=== PAUSE TestCaseHackSuffix12=== RUN TestFilterOversizedClosures13=== PAUSE TestFilterOversizedClosures14=== RUN TestUploadMultipart_PartsInParallel15=== PAUSE TestUploadMultipart_PartsInParallel16=== RUN TestPartSizeForNAR17=== PAUSE TestPartSizeForNAR18=== RUN TestUploadMultipart_SupersededByPeer19=== PAUSE TestUploadMultipart_SupersededByPeer20=== RUN TestDumpPathCaseHackMatchesNix21--- PASS: TestDumpPathCaseHackMatchesNix (13.41s)22=== RUN TestDumpPathCaseHackCollision23--- PASS: TestDumpPathCaseHackCollision (0.00s)24=== RUN TestDumpPathMatchesNix25=== PAUSE TestDumpPathMatchesNix26=== RUN TestDumpPathSingleFile27=== PAUSE TestDumpPathSingleFile28=== RUN TestDumpPathWriterError29=== PAUSE TestDumpPathWriterError30=== RUN TestEncodeNixBase3231=== PAUSE TestEncodeNixBase3232=== RUN TestEncodeNixBase32WithRealHash33=== PAUSE TestEncodeNixBase32WithRealHash34=== RUN TestConvertHashToNix3235=== PAUSE TestConvertHashToNix3236=== RUN TestGetStorePathHash37=== PAUSE TestGetStorePathHash38=== RUN TestPathInfoHashCompatibility39=== PAUSE TestPathInfoHashCompatibility40=== RUN TestParsePathInfoJSON41=== PAUSE TestParsePathInfoJSON42=== RUN TestParsePathInfoJSONMultiplePaths43=== PAUSE TestParsePathInfoJSONMultiplePaths44=== RUN TestPathInfoCACompatibility45=== PAUSE TestPathInfoCACompatibility46=== RUN TestRateLimiterFeedback47=== PAUSE TestRateLimiterFeedback48=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess49=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== RUN TestResolveStorePath51=== PAUSE TestResolveStorePath52=== RUN TestDoWithRetry_BodyReplayedViaGetBody53=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody54=== RUN TestShellSplit55=== PAUSE TestShellSplit56=== RUN TestShellSplitErrors57=== PAUSE TestShellSplitErrors58=== RUN TestStreamPushReportsEveryPath59=== PAUSE TestStreamPushReportsEveryPath60=== RUN TestStreamPushBatchesUnderLoad61=== PAUSE TestStreamPushBatchesUnderLoad62=== RUN TestStreamPushIsolatesFailures63=== PAUSE TestStreamPushIsolatesFailures64=== RUN TestStreamPushGivesUpOnDeadServer65=== PAUSE TestStreamPushGivesUpOnDeadServer66=== RUN TestStreamPushRequestLine67=== PAUSE TestStreamPushRequestLine68=== RUN TestStreamPushReportsSignatures69=== PAUSE TestStreamPushReportsSignatures70=== RUN TestClientSignaturesByStorePath71=== PAUSE TestClientSignaturesByStorePath72=== RUN TestSetClientTLS73=== PAUSE TestSetClientTLS74=== RUN TestSetClientTLSDoesNotMutateDefaultTransport75=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport76=== RUN TestSetClientTLSErrors77=== PAUSE TestSetClientTLSErrors78=== RUN TestStaticToken79=== PAUSE TestStaticToken80=== RUN TestFileTokenReadsAndCaches81=== PAUSE TestFileTokenReadsAndCaches82=== RUN TestFileTokenMissing83=== PAUSE TestFileTokenMissing84=== RUN TestFileTokenEmpty85=== PAUSE TestFileTokenEmpty86=== RUN TestScriptTokenNoExpiryRerunsEveryCall87=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall88=== RUN TestScriptTokenCachesUntilRefresh89=== PAUSE TestScriptTokenCachesUntilRefresh90=== RUN TestScriptTokenEmptyToken91=== PAUSE TestScriptTokenEmptyToken92=== RUN TestScriptTokenBadJSON93=== PAUSE TestScriptTokenBadJSON94=== RUN TestScriptTokenScriptFails95=== PAUSE TestScriptTokenScriptFails96=== RUN TestScriptTokenEmptyCommand97=== PAUSE TestScriptTokenEmptyCommand98=== CONT TestDoServerRequestAttachesToken99=== CONT TestScriptTokenEmptyCommand100=== CONT TestDoWithRetry_BodyReplayedViaGetBody101=== CONT TestParsePathInfoJSONMultiplePaths102=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths103=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths104=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths105=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths106=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths107--- PASS: TestScriptTokenEmptyCommand (0.00s)108=== CONT TestEncodeNixBase32109=== CONT TestUploadMultipart_PartsInParallel110=== RUN TestEncodeNixBase32/test_string_hash111=== PAUSE TestEncodeNixBase32/test_string_hash112=== RUN TestEncodeNixBase32/empty_input113=== PAUSE TestEncodeNixBase32/empty_input114=== CONT TestEncodeNixBase32/test_string_hash115=== CONT TestScriptTokenScriptFails116=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun117=== CONT TestDumpPathWriterError118=== CONT TestResolveStorePath119=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess120=== CONT TestRateLimiterFeedback121=== RUN TestRateLimiterFeedback/429_enables_limiter122=== CONT TestPathInfoCACompatibility123=== RUN TestPathInfoCACompatibility/null_ca_field124=== PAUSE TestPathInfoCACompatibility/null_ca_field125--- PASS: TestResolveStorePath (0.00s)126=== CONT TestParsePathInfoJSON127=== RUN TestParsePathInfoJSON/Nix_format128=== PAUSE TestRateLimiterFeedback/429_enables_limiter1292026/10/06 08:15:55 WARN Rate limiter enabled after throttle name=server-test rate=5130=== RUN TestPathInfoCACompatibility/old_string_format_-_text131=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text132=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive133=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive134=== RUN TestPathInfoCACompatibility/new_structured_format_-_text135=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text136=== RUN TestRateLimiterFeedback/503_enables_limiter137=== PAUSE TestRateLimiterFeedback/503_enables_limiter138=== PAUSE TestParsePathInfoJSON/Nix_format139=== RUN TestParsePathInfoJSON/Lix_format140=== PAUSE TestParsePathInfoJSON/Lix_format141--- PASS: TestScriptTokenScriptFails (0.01s)142=== CONT TestPathInfoHashCompatibility143=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter144=== RUN TestParsePathInfoJSON/empty_input145=== PAUSE TestParsePathInfoJSON/empty_input146=== RUN TestParsePathInfoJSON/whitespace_only147=== PAUSE TestParsePathInfoJSON/whitespace_only148=== RUN TestParsePathInfoJSON/invalid_JSON149=== PAUSE TestParsePathInfoJSON/invalid_JSON150=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)151=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter152=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method153=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method154=== CONT TestGetStorePathHash155=== RUN TestGetStorePathHash/valid_store_path156=== PAUSE TestGetStorePathHash/valid_store_path157=== RUN TestGetStorePathHash/basename_without_hyphen_should_error158=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error159=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error160=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error161=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error162=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error163=== CONT TestConvertHashToNix32164=== RUN TestConvertHashToNix32/SRI_format_to_Nix32165=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32166=== RUN TestConvertHashToNix32/already_Nix32_format167=== PAUSE TestConvertHashToNix32/already_Nix32_format168=== RUN TestConvertHashToNix32/invalid_format169=== PAUSE TestConvertHashToNix32/invalid_format170=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)171=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon172=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon173=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI174=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI1752026/10/06 08:15:55 WARN Rate limiter enabled after throttle name=server-test rate=5176=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512177=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512178=== CONT TestEncodeNixBase32WithRealHash1792026/10/06 08:15:55 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:64361180=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths181--- PASS: TestEncodeNixBase32WithRealHash (0.00s)182=== CONT TestDumpPathSingleFile183--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)184 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)185 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)186=== CONT TestFilterOversizedClosures187=== RUN TestFilterOversizedClosures/no_limit_keeps_everything188=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything189=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped190=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped191=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter192=== RUN TestFilterOversizedClosures/all_closures_skipped193=== PAUSE TestFilterOversizedClosures/all_closures_skipped194=== CONT TestStreamPushBatchesUnderLoad195=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter196--- PASS: TestDoServerRequestAttachesToken (0.01s)197=== CONT TestClientSignaturesByStorePath198--- PASS: TestClientSignaturesByStorePath (0.00s)199=== CONT TestStreamPushReportsSignatures200=== CONT TestUploadMultipart_SupersededByPeer2012026/10/06 08:15:55 INFO Garbage collection started202=== RUN TestUploadMultipart_SupersededByPeer/exists203=== PAUSE TestUploadMultipart_SupersededByPeer/exists204=== CONT TestDumpPathMatchesNix205=== RUN TestUploadMultipart_SupersededByPeer/missing206=== PAUSE TestUploadMultipart_SupersededByPeer/missing2072026/10/06 08:15:55 ERROR Upload failed error=boom count=1208=== CONT TestStreamPushRequestLine209--- PASS: TestStreamPushReportsSignatures (0.00s)210=== CONT TestStreamPushGivesUpOnDeadServer2112026/10/06 08:15:55 WARN Rate limiter backed off name=server-test rate=52122026/10/06 08:15:55 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:643612132026/10/06 08:15:55 ERROR Upload failed error=boom count=12142026/10/06 08:15:55 ERROR Upload failed error="connection refused" count=202152026/10/06 08:15:55 ERROR Server seems unavailable, giving up on batch untried=17216--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)217=== CONT TestStreamPushIsolatesFailures2182026/10/06 08:15:55 ERROR Upload failed error="bad path" count=3219--- PASS: TestStreamPushIsolatesFailures (0.00s)220=== CONT TestSetClientTLS221--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)222=== CONT TestScriptTokenBadJSON223--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)224=== CONT TestScriptTokenEmptyToken225=== RUN TestSetClientTLS/rejects_connection_without_client_cert226=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert227=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA228=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA229=== RUN TestSetClientTLS/preserves_debug_logging_transport230=== PAUSE TestSetClientTLS/preserves_debug_logging_transport231=== CONT TestScriptTokenCachesUntilRefresh232--- PASS: TestStreamPushRequestLine (0.01s)233=== CONT TestPartSizeForNAR234=== RUN TestPartSizeForNAR/zero_stays_at_minimum235=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum236=== RUN TestPartSizeForNAR/small_stays_at_minimum237=== PAUSE TestPartSizeForNAR/small_stays_at_minimum238=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum239=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum240=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts241=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts242=== RUN TestPartSizeForNAR/1_TiB243--- PASS: TestScriptTokenBadJSON (0.01s)244=== CONT TestScriptTokenNoExpiryRerunsEveryCall245=== PAUSE TestPartSizeForNAR/1_TiB246=== RUN TestPartSizeForNAR/5_TiB_S3_max_object247=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object248=== RUN TestPartSizeForNAR/capped_at_5_GiB249=== PAUSE TestPartSizeForNAR/capped_at_5_GiB250=== CONT TestFileTokenEmpty251--- PASS: TestScriptTokenEmptyToken (0.01s)252=== CONT TestFileTokenMissing253--- PASS: TestFileTokenMissing (0.00s)254=== CONT TestFileTokenReadsAndCaches255--- PASS: TestFileTokenEmpty (0.00s)256=== CONT TestStaticToken257--- PASS: TestStaticToken (0.00s)258=== CONT TestSetClientTLSErrors259--- PASS: TestFileTokenReadsAndCaches (0.00s)260=== CONT TestSetClientTLSDoesNotMutateDefaultTransport261=== RUN TestSetClientTLSErrors/missing_cert_file262=== PAUSE TestSetClientTLSErrors/missing_cert_file263=== RUN TestSetClientTLSErrors/missing_key_file264=== PAUSE TestSetClientTLSErrors/missing_key_file265=== RUN TestSetClientTLSErrors/missing_ca_file266=== PAUSE TestSetClientTLSErrors/missing_ca_file267=== RUN TestSetClientTLSErrors/invalid_ca_file268=== PAUSE TestSetClientTLSErrors/invalid_ca_file269=== CONT TestShellSplit270--- PASS: TestShellSplit (0.00s)271=== CONT TestStreamPushReportsEveryPath272--- PASS: TestStreamPushReportsEveryPath (0.00s)273=== CONT TestShellSplitErrors274--- PASS: TestShellSplitErrors (0.00s)275=== CONT TestCaseHackSuffix276--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)277=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica2782026/10/06 08:15:55 INFO Garbage collection started2792026/10/06 08:15:55 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=02802026/10/06 08:15:55 WARN Garbage collection finished on another replica. Its statistics are not available here281--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)282=== CONT TestRegisterUploadedObjectReusesConnections283--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)284=== CONT TestEncodeNixBase32/empty_input285--- PASS: TestEncodeNixBase32 (0.00s)286 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)287 --- PASS: TestEncodeNixBase32/empty_input (0.00s)288=== CONT TestParsePathInfoJSON/Nix_format289=== CONT TestParsePathInfoJSON/invalid_JSON290=== CONT TestParsePathInfoJSON/empty_input291=== CONT TestParsePathInfoJSON/whitespace_only292=== CONT TestParsePathInfoJSON/Lix_format293--- PASS: TestParsePathInfoJSON (0.00s)294 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)295 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)296 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)297 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)298 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)299=== CONT TestPathInfoCACompatibility/null_ca_field300=== CONT TestGetStorePathHash/valid_store_path301=== CONT TestConvertHashToNix32/SRI_format_to_Nix32302=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method303=== CONT TestPathInfoCACompatibility/new_structured_format_-_text304=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive305=== CONT TestPathInfoCACompatibility/old_string_format_-_text306--- PASS: TestPathInfoCACompatibility (0.01s)307 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)308 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)309 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)310 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)311 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)312=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)313=== CONT TestConvertHashToNix32/already_Nix32_format314=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error315=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error316=== CONT TestGetStorePathHash/basename_without_hyphen_should_error317--- PASS: TestGetStorePathHash (0.00s)318 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)319 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)320 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)321 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)322=== CONT TestConvertHashToNix32/invalid_format323--- PASS: TestConvertHashToNix32 (0.00s)324 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)325 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)326 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)327=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512328=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI329=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon330=== CONT TestFilterOversizedClosures/no_limit_keeps_everything331--- PASS: TestPathInfoHashCompatibility (0.00s)332 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)333 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)334 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)335 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)336=== CONT TestRateLimiterFeedback/429_enables_limiter3372026/10/06 08:15:55 WARN Rate limiter enabled after throttle name=server-test rate=53382026/10/06 08:15:55 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:644363392026/10/06 08:15:55 WARN Rate limiter backed off name=server-test rate=5340=== CONT TestFilterOversizedClosures/all_closures_skipped3412026/10/06 08:15:55 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=50342=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3432026/10/06 08:15:55 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=2000344=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter345--- PASS: TestFilterOversizedClosures (0.00s)346 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)347 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)348 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)349=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter350=== CONT TestRateLimiterFeedback/503_enables_limiter351--- PASS: TestRegisterUploadedObjectReusesConnections (0.02s)352=== CONT TestUploadMultipart_SupersededByPeer/exists3532026/10/06 08:15:55 WARN Rate limiter enabled after throttle name=server-test rate=53542026/10/06 08:15:55 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:644423552026/10/06 08:15:55 WARN Rate limiter backed off name=server-test rate=5356--- PASS: TestRateLimiterFeedback (0.01s)357 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)358 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)359 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)360 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)361=== CONT TestUploadMultipart_SupersededByPeer/missing362=== CONT TestSetClientTLS/rejects_connection_without_client_cert363--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)364 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)365 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)366=== CONT TestSetClientTLS/preserves_debug_logging_transport367=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA368--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)369=== CONT TestPartSizeForNAR/zero_stays_at_minimum370=== CONT TestPartSizeForNAR/1_TiB371=== CONT TestPartSizeForNAR/capped_at_5_GiB372=== CONT TestPartSizeForNAR/5_TiB_S3_max_object373=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum374=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts375=== CONT TestPartSizeForNAR/small_stays_at_minimum376--- PASS: TestPartSizeForNAR (0.00s)377 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)378 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)379 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)380 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)381 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)382 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)383 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)384=== CONT TestSetClientTLSErrors/missing_cert_file385=== CONT TestSetClientTLSErrors/missing_ca_file386=== CONT TestSetClientTLSErrors/missing_key_file387--- PASS: TestDumpPathWriterError (0.06s)388=== CONT TestSetClientTLSErrors/invalid_ca_file389--- PASS: TestSetClientTLSErrors (0.00s)390 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)391 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)392 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)393 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)3942026/10/06 08:15:55 http: TLS handshake error from 127.0.0.1:64448: remote error: tls: bad certificate395--- PASS: TestSetClientTLS (0.01s)396 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)397 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)398 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)399--- PASS: TestDumpPathSingleFile (0.07s)400--- PASS: TestCaseHackSuffix (0.07s)401--- PASS: TestDumpPathMatchesNix (0.10s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestUploadMultipart_PartsInParallel (0.62s)404--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.01s)405PASS406Running server tests...407The files belonging to this database system will be owned by user "_nixbld12".408This user must also own the server process.409410The database cluster will be initialized with locale "C".411The default database encoding has accordingly been set to "SQL_ASCII".412The default text search configuration will be set to "english".413414Data page checksums are enabled.415416creating directory /nix/var/nix/builds/nix-18015-426991606/postgres1733532267/data ... ok417creating subdirectories ... ok418selecting dynamic shared memory implementation ... posix419selecting default "max_connections" ... 100420selecting default "shared_buffers" ... 128MB421selecting default time zone ... UTC422creating configuration files ... ok423running bootstrap script ... ok424performing post-bootstrap initialization ... ok425syncing data to disk ... ok426427initdb: warning: enabling "trust" authentication for local connections428initdb: 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.429430Success. You can now start the database server using:431432 pg_ctl -D /nix/var/nix/builds/nix-18015-426991606/postgres1733532267/data -l logfile start4334342026-10-06 08:15:59.797 UTC [28954] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4352026-10-06 08:15:59.797 UTC [28954] LOG: listening on Unix socket "/nix/var/nix/builds/nix-18015-426991606/postgres1733532267/.s.PGSQL.5432"4362026-10-06 08:15:59.801 UTC [28969] LOG: database system was shut down at 2026-10-06 08:15:59 UTC4372026-10-06 08:15:59.802 UTC [28954] LOG: database system is ready to accept connections438/nix/var/nix/builds/nix-18015-426991606/postgres1733532267:5432 - accepting connections439{"timestamp":"2026-10-06T08:16:02.057584Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"147e3a3e-f7b8-4941-a4f8-434b2577c860","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(3)"}440{"timestamp":"2026-10-06T08:16:02.16473Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"4532460b-50fb-4c01-8303-066897a1dae3","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(2)"}441{"timestamp":"2026-10-06T08:16:02.267411Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"43b688f9-8696-40dc-be4a-a72bba79dfec","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(9)"}442=== RUN TestService_AuthMiddleware443=== PAUSE TestService_AuthMiddleware444=== RUN TestService_AuthMiddleware_MTLSProxyHeader445=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader446=== RUN TestService_AuthMiddleware_MTLSBoundSubjects447=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects448=== RUN TestService_ReadAuthMiddleware449=== PAUSE TestService_ReadAuthMiddleware450=== RUN TestService_AuthMiddleware_OIDC451=== PAUSE TestService_AuthMiddleware_OIDC452=== RUN TestService_RequireScope_OIDC453=== PAUSE TestService_RequireScope_OIDC454=== RUN TestService_ReadScope_PublicByDefault455=== PAUSE TestService_ReadScope_PublicByDefault456=== RUN TestCacheConfigHandler457=== PAUSE TestCacheConfigHandler458=== RUN TestCacheStatsHandler459=== PAUSE TestCacheStatsHandler460=== RUN TestClientCADerivations461=== PAUSE TestClientCADerivations462=== RUN TestClientErrorHandling463=== PAUSE TestClientErrorHandling464=== RUN TestClientIntegration465=== PAUSE TestClientIntegration466=== RUN TestClientMultipleUploads467=== PAUSE TestClientMultipleUploads468=== RUN TestClientWithDependencies469=== PAUSE TestClientWithDependencies470=== RUN TestClientSharedPathCommittedMidPush471=== PAUSE TestClientSharedPathCommittedMidPush472=== RUN TestPinProtectsFromGC473=== PAUSE TestPinProtectsFromGC474=== RUN TestClientPushesUseOnePush475=== PAUSE TestClientPushesUseOnePush476=== RUN TestClientFallsBackToClosures477=== PAUSE TestClientFallsBackToClosures478=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock479=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock480=== RUN TestResolveDBConnectionString481=== PAUSE TestResolveDBConnectionString482=== RUN TestConnectWaitsForAPeerMigration483=== PAUSE TestConnectWaitsForAPeerMigration484=== RUN TestLeadElectsOneAndHandsOver485=== PAUSE TestLeadElectsOneAndHandsOver486=== RUN TestLeadIncumbentWinsAfterRestart4872026/10/06 08:16:02 INFO lead: acquired remote=192.0.2.1:12344882026/10/06 08:16:03 INFO lead: released remote=192.0.2.1:12344892026/10/06 08:16:03 INFO lead: acquired remote=192.0.2.1:12344902026/10/06 08:16:04 INFO lead: released remote=192.0.2.1:1234491--- PASS: TestLeadIncumbentWinsAfterRestart (2.19s)492=== RUN TestLeadIncumbentAnnouncesAtOnce493=== PAUSE TestLeadIncumbentAnnouncesAtOnce494=== RUN TestLeadEndsOnShutdown495=== PAUSE TestLeadEndsOnShutdown496=== RUN TestLeadEndsWhenItsConnectionHangs4972026/10/06 08:16:04 INFO lead: acquired remote=192.0.2.1:12344982026-10-06 08:16:06.169 UTC [31719] FATAL: terminating connection due to administrator command4992026/10/06 08:16:06 INFO lead: acquired remote=192.0.2.1:12345002026/10/06 08:16:07 WARN lead: lock connection lost error="timeout: context deadline exceeded"5012026/10/06 08:16:07 INFO lead: released remote=192.0.2.1:12345022026/10/06 08:16:07 INFO lead: released remote=192.0.2.1:1234503--- PASS: TestLeadEndsWhenItsConnectionHangs (3.01s)504=== RUN TestGCAdvisoryLockBlocksConcurrentRun505=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun506=== RUN TestGCBugBareHashReferences507=== PAUSE TestGCBugBareHashReferences508=== RUN TestGCMetrics509=== PAUSE TestGCMetrics510=== RUN TestPushDedupSurvivesConcurrentGC511=== PAUSE TestPushDedupSurvivesConcurrentGC512=== RUN TestDeduplicatedObjectsRecordedAsPending513=== PAUSE TestDeduplicatedObjectsRecordedAsPending514=== RUN TestGCSweepSkipsPendingObjects515=== PAUSE TestGCSweepSkipsPendingObjects516=== RUN TestTombstonedObjectOfferedWithoutWaiting517=== PAUSE TestTombstonedObjectOfferedWithoutWaiting518=== RUN TestGCSweepDeliversEachKeyOnce519=== PAUSE TestGCSweepDeliversEachKeyOnce520=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection521=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection522=== RUN TestForceGCDuringPushOffersSweptObject523=== PAUSE TestForceGCDuringPushOffersSweptObject524=== RUN TestFailedS3DeleteKeepsTombstone525=== PAUSE TestFailedS3DeleteKeepsTombstone526=== RUN TestSweepSkipsRowsLockedByPush527=== PAUSE TestSweepSkipsRowsLockedByPush528=== RUN TestRegisterCompletedObjectNeedsPendingRow529=== PAUSE TestRegisterCompletedObjectNeedsPendingRow530=== RUN TestGetExistingObjectsLocksRows531=== PAUSE TestGetExistingObjectsLocksRows532=== RUN TestSweepRechecksPendingAfterLocking533=== PAUSE TestSweepRechecksPendingAfterLocking534=== RUN TestPushWaitsForSweepHoldingRow535=== PAUSE TestPushWaitsForSweepHoldingRow536=== RUN TestCommitRacingPendingCleanupKeepsObjects537=== PAUSE TestCommitRacingPendingCleanupKeepsObjects538=== RUN TestGCEndsOnShutdown539=== PAUSE TestGCEndsOnShutdown540=== RUN TestGCTaskStore_StartNew541=== PAUSE TestGCTaskStore_StartNew542=== RUN TestGCTaskStore_DeduplicateSameParams543=== PAUSE TestGCTaskStore_DeduplicateSameParams544=== RUN TestGCTaskStore_ConflictDifferentParams545=== PAUSE TestGCTaskStore_ConflictDifferentParams546=== RUN TestGCTaskStore_GetEmpty547=== PAUSE TestGCTaskStore_GetEmpty548=== RUN TestGCTaskStore_GetReturnsLatest549=== PAUSE TestGCTaskStore_GetReturnsLatest550=== RUN TestGCTaskStore_CompletedAllowsNewTask551=== PAUSE TestGCTaskStore_CompletedAllowsNewTask552=== RUN TestGCTaskStore_PhaseUpdates553=== PAUSE TestGCTaskStore_PhaseUpdates554=== RUN TestGCTaskStore_Fail555=== PAUSE TestGCTaskStore_Fail556=== RUN TestGracefulShutdownDrainsInflight557=== PAUSE TestGracefulShutdownDrainsInflight558=== RUN TestService_healthCheckHandler559=== PAUSE TestService_healthCheckHandler560=== RUN TestService_readinessHandler561=== PAUSE TestService_readinessHandler562=== RUN TestGenerateLandingPage563=== PAUSE TestGenerateLandingPage564=== RUN TestCacheConfigHandlerMaxNarSize565=== PAUSE TestCacheConfigHandlerMaxNarSize566=== RUN TestCreatePendingClosureRejectsOversizedNAR567=== PAUSE TestCreatePendingClosureRejectsOversizedNAR568=== RUN TestNARDeduplicationMetadataUploadBug569=== PAUSE TestNARDeduplicationMetadataUploadBug570=== RUN TestMetricsInventory571=== PAUSE TestMetricsInventory572=== RUN TestService_NativeMTLS573=== PAUSE TestService_NativeMTLS574=== RUN TestServerTLSConfig575=== PAUSE TestServerTLSConfig576=== RUN TestMultipartCleanup577=== PAUSE TestMultipartCleanup578=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded579=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded580=== RUN TestPendingCleanupUsesOneCutoff581=== PAUSE TestPendingCleanupUsesOneCutoff582=== RUN TestObjectStatsTrigger583=== PAUSE TestObjectStatsTrigger584=== RUN TestOrphanedObjectsGC585=== PAUSE TestOrphanedObjectsGC586=== RUN TestOrphanedObjectsGCStressTest587=== PAUSE TestOrphanedObjectsGCStressTest588=== RUN TestCreatePin_ReservedPins589=== PAUSE TestCreatePin_ReservedPins590=== RUN TestPresentReportsOnlyClosureRoots591=== PAUSE TestPresentReportsOnlyClosureRoots592=== RUN TestPresentNotReportedWhileGCDeletesClosure593=== PAUSE TestPresentNotReportedWhileGCDeletesClosure594=== RUN TestParseSingleRange595=== PAUSE TestParseSingleRange596=== RUN TestProxyHeadersOnlyTrustedOnSocket597=== PAUSE TestProxyHeadersOnlyTrustedOnSocket598=== RUN TestIsValidCachePath599=== PAUSE TestIsValidCachePath600=== RUN TestReadProxyNarinfo601=== PAUSE TestReadProxyNarinfo602=== RUN TestReadProxyNarinfoAlreadyDecompressed603=== PAUSE TestReadProxyNarinfoAlreadyDecompressed604=== RUN TestReadProxyNarStreaming605=== PAUSE TestReadProxyNarStreaming606=== RUN TestReadProxy404607=== PAUSE TestReadProxy404608=== RUN TestReadProxyInvalidPath609=== PAUSE TestReadProxyInvalidPath610=== RUN TestReadProxyHead611=== PAUSE TestReadProxyHead612=== RUN TestReadProxyOutlastsServerWriteTimeout613=== PAUSE TestReadProxyOutlastsServerWriteTimeout614=== RUN TestReadProxyConditionalGet615=== PAUSE TestReadProxyConditionalGet616=== RUN TestReadProxyRootRedirectsToIndexHTML617=== PAUSE TestReadProxyRootRedirectsToIndexHTML618=== RUN TestReadProxyDisabled619=== PAUSE TestReadProxyDisabled620=== RUN TestReadRedirectNar621=== PAUSE TestReadRedirectNar622=== RUN TestReadRedirectKeepsNarinfoProxied623=== PAUSE TestReadRedirectKeepsNarinfoProxied624=== RUN TestReadProxyRangeRequest625=== PAUSE TestReadProxyRangeRequest626=== RUN TestReadRedirectUsesPublicS3URL627=== PAUSE TestReadRedirectUsesPublicS3URL628=== RUN TestPush_OverlappingRootsStoreOneRowPerKey629=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey630=== RUN TestPush_CompleteCommitsEveryRoot631=== PAUSE TestPush_CompleteCommitsEveryRoot632=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit633=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit634=== RUN TestPush_RejectsBadRequests635=== PAUSE TestPush_RejectsBadRequests636=== RUN TestPush_SignsNarinfosOfItsPendingObjects637=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects638=== RUN TestRedundantMultipartUpload639=== PAUSE TestRedundantMultipartUpload640=== RUN TestCompleteMultipartUpload_ErrorButObjectExists641=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists642=== RUN TestCompletedNarNotReofferedAcrossClosures643=== PAUSE TestCompletedNarNotReofferedAcrossClosures644=== RUN TestPresignedUploadRegisteredBeforeCommit645=== PAUSE TestPresignedUploadRegisteredBeforeCommit646=== RUN TestService_Rustfstest647=== PAUSE TestService_Rustfstest648=== RUN TestParseSize649=== PAUSE TestParseSize650=== RUN TestSkippedUploadsHandler651=== PAUSE TestSkippedUploadsHandler652=== RUN TestSystemdListenerNotActivated653--- PASS: TestSystemdListenerNotActivated (0.00s)654=== RUN TestWatchdogBeatsWhenHealthy655--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)656=== RUN TestWatchdogSkipsWhenUnhealthy6572026/10/06 08:16:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6582026/10/06 08:16:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6592026/10/06 08:16:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/06 08:16:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/06 08:16:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/06 08:16:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/06 08:16:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/06 08:16:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/06 08:16:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/06 08:16:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"667--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)668=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle669=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle670=== RUN TestProxyWriteTimeout671=== PAUSE TestProxyWriteTimeout672=== RUN TestPendingClosureWriteTimeout673=== PAUSE TestPendingClosureWriteTimeout674=== RUN TestIsValidUploadKey675=== PAUSE TestIsValidUploadKey676=== RUN TestUploadHandlersRejectInvalidKeys677=== PAUSE TestUploadHandlersRejectInvalidKeys678=== RUN TestUploadHandlersRejectOversizedBody679=== PAUSE TestUploadHandlersRejectOversizedBody680=== RUN TestService_cleanupPendingClosuresHandler681=== PAUSE TestService_cleanupPendingClosuresHandler682=== RUN TestService_createPendingClosureHandler683=== PAUSE TestService_createPendingClosureHandler684=== RUN TestService_verifyS3Integrity685=== PAUSE TestService_verifyS3Integrity686=== RUN TestCompleteMultipartUnregistered687=== PAUSE TestCompleteMultipartUnregistered688=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT689=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT690=== CONT TestService_verifyS3Integrity691=== CONT TestService_AuthMiddleware692=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT693=== CONT TestCompleteMultipartUnregistered694=== CONT TestGenerateLandingPage695=== CONT TestPushDedupSurvivesConcurrentGC696=== CONT TestService_readinessHandler697=== CONT TestService_healthCheckHandler698=== CONT TestGracefulShutdownDrainsInflight699=== CONT TestGCTaskStore_Fail700--- PASS: TestGCTaskStore_Fail (0.00s)701=== CONT TestGCTaskStore_PhaseUpdates702--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)703=== CONT TestGCTaskStore_CompletedAllowsNewTask704--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)705=== CONT TestGCTaskStore_GetReturnsLatest706--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)707=== CONT TestGCTaskStore_GetEmpty708--- PASS: TestGCTaskStore_GetEmpty (0.00s)709=== CONT TestGCTaskStore_ConflictDifferentParams710--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)711=== CONT TestGCTaskStore_DeduplicateSameParams712--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)713=== CONT TestGCTaskStore_StartNew714--- PASS: TestGCTaskStore_StartNew (0.00s)715=== CONT TestGCEndsOnShutdown716=== RUN TestGCEndsOnShutdown/before_the_run717=== PAUSE TestGCEndsOnShutdown/before_the_run718=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete719=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete720=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark721=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark722=== CONT TestCommitRacingPendingCleanupKeepsObjects723--- PASS: TestGenerateLandingPage (0.00s)724=== CONT TestPushWaitsForSweepHoldingRow7252026/10/06 08:16:07 INFO Starting HTTP server address=127.0.0.1:645177262026/10/06 08:16:07 INFO Shutdown signal received, draining in-flight requests timeout=10s727--- PASS: TestGracefulShutdownDrainsInflight (0.08s)728=== CONT TestSweepRechecksPendingAfterLocking7292026/10/06 08:16:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7302026/10/06 08:16:08 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst731--- PASS: TestCompleteMultipartUnregistered (0.43s)732=== CONT TestGetExistingObjectsLocksRows7332026/10/06 08:16:08 INFO Received uploads request method=POST path=/api/pending_closures7342026/10/06 08:16:08 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"735--- PASS: TestService_AuthMiddleware (0.85s)736=== CONT TestRegisterCompletedObjectNeedsPendingRow7372026/10/06 08:16:09 INFO Received uploads request method=POST path=/api/pending_closures738--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.29s)739=== CONT TestSweepSkipsRowsLockedByPush7402026/10/06 08:16:09 INFO Received uploads request method=POST path=/api/pending_closures7412026/10/06 08:16:09 INFO Received uploads request method=POST path=/api/pending_closures7422026/10/06 08:16:09 INFO Aborted multipart uploads count=0 kept=07432026/10/06 08:16:09 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=07442026/10/06 08:16:09 INFO Vacuumed table table=pending_closures7452026/10/06 08:16:09 INFO Vacuumed table table=pending_objects7462026/10/06 08:16:09 INFO Vacuumed table table=multipart_uploads7472026/10/06 08:16:09 INFO Vacuumed table table=closures7482026/10/06 08:16:09 INFO Vacuumed table table=objects7492026/10/06 08:16:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7502026/10/06 08:16:09 INFO Aborted multipart uploads count=0 kept=07512026/10/06 08:16:09 WARN Force mode enabled - objects will be deleted immediately without grace period7522026/10/06 08:16:09 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=07532026/10/06 08:16:09 WARN readiness check failed error="closed pool"754--- PASS: TestService_readinessHandler (1.95s)755=== CONT TestFailedS3DeleteKeepsTombstone7562026/10/06 08:16:09 INFO Vacuumed table table=pending_closures7572026/10/06 08:16:09 INFO Vacuumed table table=pending_objects7582026/10/06 08:16:09 INFO Vacuumed table table=multipart_uploads7592026/10/06 08:16:09 INFO Vacuumed table table=closures7602026/10/06 08:16:09 INFO Vacuumed table table=objects761--- PASS: TestPushDedupSurvivesConcurrentGC (2.00s)762=== CONT TestForceGCDuringPushOffersSweptObject763=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows764=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows765=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check766=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check767=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection768--- PASS: TestPushWaitsForSweepHoldingRow (2.00s)769=== CONT TestGCSweepDeliversEachKeyOnce7702026/10/06 08:16:09 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NTZlMDI1N2EtMjk4My00YjVkLTg2MGMtN2FhZDk5NzFhN2EwLmNkOGE0Njg3LTVmYzEtNGMyMi04NDMxLWZmZTU5NGI1ZmM3Y3gxNzkxMjc0NTY4NDgxMDk1MDAw parts=107712026/10/06 08:16:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7722026/10/06 08:16:09 INFO Completed upload id=17732026/10/06 08:16:09 INFO Received uploads request method=POST path=/api/pending_closures7742026/10/06 08:16:09 INFO Received uploads request method=POST path=/api/pending_closures7752026/10/06 08:16:09 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo7762026/10/06 08:16:09 WARN Found objects in DB but missing from S3, will re-upload count=1777--- PASS: TestService_verifyS3Integrity (2.02s)778=== CONT TestTombstonedObjectOfferedWithoutWaiting779--- PASS: TestService_healthCheckHandler (2.16s)780=== CONT TestGCSweepSkipsPendingObjects7812026/10/06 08:16:10 INFO Aborted multipart uploads count=0 kept=07822026/10/06 08:16:10 WARN Force mode enabled - objects will be deleted immediately without grace period7832026/10/06 08:16:10 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=07842026/10/06 08:16:10 INFO Vacuumed table table=pending_closures7852026/10/06 08:16:10 INFO Vacuumed table table=pending_objects7862026/10/06 08:16:10 INFO Vacuumed table table=multipart_uploads7872026/10/06 08:16:10 INFO Vacuumed table table=closures7882026/10/06 08:16:10 INFO Vacuumed table table=objects789--- PASS: TestCommitRacingPendingCleanupKeepsObjects (2.48s)790=== CONT TestDeduplicatedObjectsRecordedAsPending7912026/10/06 08:16:10 INFO Aborted multipart uploads count=0 kept=07922026/10/06 08:16:10 WARN Force mode enabled - objects will be deleted immediately without grace period7932026/10/06 08:16:10 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=07942026/10/06 08:16:10 INFO Vacuumed table table=pending_closures7952026/10/06 08:16:10 INFO Vacuumed table table=pending_objects7962026/10/06 08:16:10 INFO Vacuumed table table=multipart_uploads7972026/10/06 08:16:10 INFO Vacuumed table table=closures7982026/10/06 08:16:10 INFO Vacuumed table table=objects799--- PASS: TestSweepRechecksPendingAfterLocking (2.57s)800=== CONT TestReadProxyRootRedirectsToIndexHTML801--- PASS: TestGetExistingObjectsLocksRows (2.38s)802=== CONT TestService_createPendingClosureHandler803--- PASS: TestRegisterCompletedObjectNeedsPendingRow (2.21s)804=== CONT TestService_cleanupPendingClosuresHandler8052026/10/06 08:16:11 INFO Aborted multipart uploads count=0 kept=08062026/10/06 08:16:11 WARN Force mode enabled - objects will be deleted immediately without grace period8072026/10/06 08:16:11 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=08082026/10/06 08:16:11 INFO Vacuumed table table=pending_closures8092026/10/06 08:16:11 INFO Vacuumed table table=pending_objects8102026/10/06 08:16:11 INFO Vacuumed table table=multipart_uploads8112026/10/06 08:16:11 INFO Vacuumed table table=closures8122026/10/06 08:16:11 INFO Vacuumed table table=objects8132026/10/06 08:16:11 INFO Aborted multipart uploads count=0 kept=08142026/10/06 08:16:11 WARN Force mode enabled - objects will be deleted immediately without grace period8152026/10/06 08:16:11 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=08162026/10/06 08:16:11 INFO Vacuumed table table=pending_closures8172026/10/06 08:16:11 INFO Vacuumed table table=pending_objects8182026/10/06 08:16:11 INFO Vacuumed table table=multipart_uploads8192026/10/06 08:16:11 INFO Vacuumed table table=closures8202026/10/06 08:16:11 INFO Vacuumed table table=objects821--- PASS: TestSweepSkipsRowsLockedByPush (2.03s)822=== CONT TestUploadHandlersRejectOversizedBody823=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart824=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart825=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts826=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts827=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure828=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure829=== CONT TestUploadHandlersRejectInvalidKeys830=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info831=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info832=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal833=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal834=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key835=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key836=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key837=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key838=== CONT TestIsValidUploadKey839=== RUN TestIsValidUploadKey/narinfo840=== PAUSE TestIsValidUploadKey/narinfo841=== RUN TestIsValidUploadKey/nar_zst842=== PAUSE TestIsValidUploadKey/nar_zst843=== RUN TestIsValidUploadKey/nar_xz844=== PAUSE TestIsValidUploadKey/nar_xz845=== RUN TestIsValidUploadKey/nar_plain846=== PAUSE TestIsValidUploadKey/nar_plain847=== RUN TestIsValidUploadKey/listing848=== PAUSE TestIsValidUploadKey/listing849=== RUN TestIsValidUploadKey/build_log850=== PAUSE TestIsValidUploadKey/build_log851=== RUN TestIsValidUploadKey/build_log_home-manager_file852=== PAUSE TestIsValidUploadKey/build_log_home-manager_file853=== RUN TestIsValidUploadKey/build_log_plus_in_name854=== PAUSE TestIsValidUploadKey/build_log_plus_in_name855=== RUN TestIsValidUploadKey/build_log_question_mark856=== PAUSE TestIsValidUploadKey/build_log_question_mark857=== RUN TestIsValidUploadKey/build_log_equals858=== PAUSE TestIsValidUploadKey/build_log_equals859=== RUN TestIsValidUploadKey/realisation860=== PAUSE TestIsValidUploadKey/realisation861=== RUN TestIsValidUploadKey/realisation_plus_in_output862=== PAUSE TestIsValidUploadKey/realisation_plus_in_output863=== RUN TestIsValidUploadKey/nix-cache-info864=== PAUSE TestIsValidUploadKey/nix-cache-info865=== RUN TestIsValidUploadKey/index.html866=== PAUSE TestIsValidUploadKey/index.html867=== RUN TestIsValidUploadKey/narinfo_key,_nar_type868=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type869=== RUN TestIsValidUploadKey/nar_key,_narinfo_type870=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type871=== RUN TestIsValidUploadKey/listing_key,_narinfo_type872=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type873=== RUN TestIsValidUploadKey/traversal874=== PAUSE TestIsValidUploadKey/traversal875=== RUN TestIsValidUploadKey/traversal_nar876=== PAUSE TestIsValidUploadKey/traversal_nar877=== RUN TestIsValidUploadKey/absolute878=== PAUSE TestIsValidUploadKey/absolute879=== RUN TestIsValidUploadKey/empty_key880=== PAUSE TestIsValidUploadKey/empty_key881=== RUN TestIsValidUploadKey/unknown_type882=== PAUSE TestIsValidUploadKey/unknown_type883=== CONT TestPendingClosureWriteTimeout884=== RUN TestPendingClosureWriteTimeout/empty885=== PAUSE TestPendingClosureWriteTimeout/empty886=== RUN TestPendingClosureWriteTimeout/400_objects887=== PAUSE TestPendingClosureWriteTimeout/400_objects888=== RUN TestPendingClosureWriteTimeout/670k_objects889=== PAUSE TestPendingClosureWriteTimeout/670k_objects890=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline891=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline892=== CONT TestProxyWriteTimeout893=== RUN TestProxyWriteTimeout/narinfo894=== PAUSE TestProxyWriteTimeout/narinfo895=== RUN TestProxyWriteTimeout/1_GiB_nar896=== PAUSE TestProxyWriteTimeout/1_GiB_nar897=== RUN TestProxyWriteTimeout/10_GiB_nar898=== PAUSE TestProxyWriteTimeout/10_GiB_nar899=== RUN TestProxyWriteTimeout/unknown_size900=== PAUSE TestProxyWriteTimeout/unknown_size901=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle9022026/10/06 08:16:11 INFO Aborted multipart uploads count=0 kept=09032026/10/06 08:16:11 WARN Force mode enabled - objects will be deleted immediately without grace period9042026/10/06 08:16:11 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=09052026/10/06 08:16:11 INFO Vacuumed table table=pending_closures9062026/10/06 08:16:11 INFO Vacuumed table table=pending_objects9072026/10/06 08:16:11 INFO Vacuumed table table=multipart_uploads9082026/10/06 08:16:11 INFO Vacuumed table table=closures9092026/10/06 08:16:11 INFO Vacuumed table table=objects910--- PASS: TestGCSweepDeliversEachKeyOnce (1.61s)911=== CONT TestSkippedUploadsHandler9122026/10/06 08:16:11 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000913--- PASS: TestSkippedUploadsHandler (0.00s)914=== CONT TestParseSize915--- PASS: TestParseSize (0.00s)916=== CONT TestService_Rustfstest9172026/10/06 08:16:11 INFO Received uploads request method=POST path=/api/pending_closures918--- PASS: TestTombstonedObjectOfferedWithoutWaiting (1.71s)919=== CONT TestPresignedUploadRegisteredBeforeCommit9202026/10/06 08:16:11 INFO Received uploads request method=POST path=/api/pending_closures9212026/10/06 08:16:11 INFO Received uploads request method=POST path=/api/pending_closures922--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (2.10s)923=== CONT TestCompletedNarNotReofferedAcrossClosures9242026/10/06 08:16:11 INFO Aborted multipart uploads count=0 kept=09252026/10/06 08:16:11 WARN Force mode enabled - objects will be deleted immediately without grace period9262026/10/06 08:16:11 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."9272026/10/06 08:16:11 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."928--- PASS: TestFailedS3DeleteKeepsTombstone (2.21s)929=== CONT TestCompleteMultipartUpload_ErrorButObjectExists9302026/10/06 08:16:12 INFO Received uploads request method=POST path=/api/pending_closures9312026/10/06 08:16:12 INFO Aborted multipart uploads count=0 kept=09322026/10/06 08:16:12 WARN Force mode enabled - objects will be deleted immediately without grace period9332026/10/06 08:16:12 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09342026/10/06 08:16:12 INFO Vacuumed table table=pending_closures9352026/10/06 08:16:12 INFO Vacuumed table table=pending_objects9362026/10/06 08:16:12 INFO Vacuumed table table=multipart_uploads9372026/10/06 08:16:12 INFO Vacuumed table table=closures9382026/10/06 08:16:12 INFO Vacuumed table table=objects939--- PASS: TestGCSweepSkipsPendingObjects (2.20s)940=== CONT TestRedundantMultipartUpload9412026/10/06 08:16:12 INFO Received uploads request method=POST path=/api/pending_closures942--- PASS: TestDeduplicatedObjectsRecordedAsPending (2.03s)943=== CONT TestPush_SignsNarinfosOfItsPendingObjects944--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.03s)945=== CONT TestPush_RejectsBadRequests9462026/10/06 08:16:12 INFO Received uploads request method=POST path=/api/pending_closures9472026/10/06 08:16:12 INFO Received uploads request method=POST path=/api/pending_closures9482026/10/06 08:16:12 INFO Received uploads request method=POST path=/api/pending_closures9492026/10/06 08:16:12 INFO Received cleanup request method=DELETE path=/api/pending_closures9502026/10/06 08:16:12 INFO Aborted multipart uploads count=0 kept=09512026/10/06 08:16:12 INFO Received uploads request method=POST path=/api/pending_closures9522026/10/06 08:16:13 INFO Received cleanup request method=DELETE path=/api/pending_closures9532026/10/06 08:16:13 INFO Aborted multipart uploads count=1 kept=09542026/10/06 08:16:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9552026-10-06 08:16:13.035 UTC [34176] ERROR: Closure does not exist: id=19562026-10-06 08:16:13.035 UTC [34176] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE9572026-10-06 08:16:13.035 UTC [34176] STATEMENT: -- name: CommitPendingClosure :exec958 SELECT commit_pending_closure($1::bigint)959 960--- PASS: TestService_cleanupPendingClosuresHandler (2.18s)961=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit9622026/10/06 08:16:13 INFO Received uploads request method=POST path=/api/pending_closures963--- PASS: TestService_Rustfstest (2.17s)964=== CONT TestPush_CompleteCommitsEveryRoot9652026/10/06 08:16:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9662026/10/06 08:16:13 INFO Received uploads request method=POST path=/api/pending_closures9672026/10/06 08:16:13 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9682026/10/06 08:16:13 INFO Received uploads request method=POST path=/api/pending_closures969--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.38s)970=== CONT TestPush_OverlappingRootsStoreOneRowPerKey9712026/10/06 08:16:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9722026/10/06 08:16:14 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NTZlMDI1N2EtMjk4My00YjVkLTg2MGMtN2FhZDk5NzFhN2EwLmNkNzViYTY5LTg5YTgtNDAzYS1hYmY0LTdjZmQ3NzUyMjgzN3gxNzkxMjc0NTcyNjkxNzIwMDAw parts=109732026/10/06 08:16:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9742026/10/06 08:16:14 INFO Completed upload id=19752026/10/06 08:16:14 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009762026/10/06 08:16:14 INFO Received uploads request method=POST path=/api/pending_closures9772026/10/06 08:16:14 INFO Starting cleanup of old closures method=DELETE path=/api/closures9782026/10/06 08:16:14 INFO Aborted multipart uploads count=0 kept=09792026/10/06 08:16:14 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=09802026/10/06 08:16:14 INFO Vacuumed table table=pending_closures9812026/10/06 08:16:14 INFO Received uploads request method=POST path=/api/pending_closures9822026/10/06 08:16:14 INFO Vacuumed table table=pending_objects9832026/10/06 08:16:14 INFO Vacuumed table table=multipart_uploads9842026/10/06 08:16:14 INFO Received uploads request method=POST path=/api/pending_closures9852026/10/06 08:16:14 INFO Vacuumed table table=closures9862026/10/06 08:16:14 INFO Vacuumed table table=objects9872026/10/06 08:16:14 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000988--- PASS: TestService_createPendingClosureHandler (3.68s)989=== CONT TestReadRedirectUsesPublicS3URL9902026/10/06 08:16:14 INFO Received uploads request method=POST path=/api/pending_closures9912026/10/06 08:16:14 INFO Received uploads request method=POST path=/api/pending_closures9922026/10/06 08:16:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9932026/10/06 08:16:15 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NTZlMDI1N2EtMjk4My00YjVkLTg2MGMtN2FhZDk5NzFhN2EwLjVlMWMxYzUwLTQwYjgtNDJkZi1hNTc2LTlmZWY4MWEzNTI4YXgxNzkxMjc0NTc0ODcxOTM1MDAw9942026/10/06 08:16:15 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NTZlMDI1N2EtMjk4My00YjVkLTg2MGMtN2FhZDk5NzFhN2EwLjVlMWMxYzUwLTQwYjgtNDJkZi1hNTc2LTlmZWY4MWEzNTI4YXgxNzkxMjc0NTc0ODcxOTM1MDAw parts=1995--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (3.17s)996=== CONT TestReadProxyRangeRequest9972026/10/06 08:16:15 INFO Received push request method=POST path=/api/pushes9982026/10/06 08:16:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9992026/10/06 08:16:15 INFO Signed narinfos id=1 count=110002026/10/06 08:16:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10012026/10/06 08:16:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10022026/10/06 08:16:15 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"10032026/10/06 08:16:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10042026/10/06 08:16:15 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"10052026/10/06 08:16:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10062026/10/06 08:16:15 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=110072026/10/06 08:16:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10082026/10/06 08:16:15 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1009--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (2.96s)1010=== CONT TestReadRedirectKeepsNarinfoProxied1011=== RUN TestPush_RejectsBadRequests/no_roots1012=== PAUSE TestPush_RejectsBadRequests/no_roots1013=== RUN TestPush_RejectsBadRequests/no_objects1014=== PAUSE TestPush_RejectsBadRequests/no_objects1015=== RUN TestPush_RejectsBadRequests/bad_root1016=== PAUSE TestPush_RejectsBadRequests/bad_root1017=== RUN TestPush_RejectsBadRequests/root_not_in_objects1018=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1019=== CONT TestReadRedirectNar10202026/10/06 08:16:15 INFO Received push request method=POST path=/api/pushes10212026/10/06 08:16:15 INFO Received complete push request method=POST path=/api/pushes/1/complete10222026/10/06 08:16:15 INFO Received push request method=POST path=/api/pushes10232026/10/06 08:16:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10242026/10/06 08:16:16 INFO Aborted multipart uploads count=0 kept=010252026/10/06 08:16:16 WARN Force mode enabled - objects will be deleted immediately without grace period10262026/10/06 08:16:16 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=010272026/10/06 08:16:16 INFO Vacuumed table table=pending_closures10282026/10/06 08:16:16 INFO Vacuumed table table=pending_objects10292026/10/06 08:16:16 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NTZlMDI1N2EtMjk4My00YjVkLTg2MGMtN2FhZDk5NzFhN2EwLjNkMGQ1ZjkzLTEyZmMtNDFhOS05OWQwLTJkNDEzYTZiNmU5Y3gxNzkxMjc0NTc0MjE3ODY5MDAw parts=1210302026/10/06 08:16:16 INFO Received uploads request method=POST path=/api/pending_closures10312026/10/06 08:16:16 INFO Vacuumed table table=multipart_uploads10322026/10/06 08:16:16 INFO Received uploads request method=POST path=/api/pending_closures10332026/10/06 08:16:16 INFO Vacuumed table table=closures10342026/10/06 08:16:16 INFO Vacuumed table table=objects10352026/10/06 08:16:16 INFO Received complete push request method=POST path=/api/pushes/2/complete1036--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (3.30s)1037=== CONT TestReadProxyDisabled10382026/10/06 08:16:16 INFO Received push request method=POST path=/api/pushes10392026/10/06 08:16:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10402026/10/06 08:16:16 INFO Received complete push request method=POST path=/api/pushes/1/complete1041--- PASS: TestPush_CompleteCommitsEveryRoot (3.00s)1042=== CONT TestClientSharedPathCommittedMidPush10432026/10/06 08:16:16 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NTZlMDI1N2EtMjk4My00YjVkLTg2MGMtN2FhZDk5NzFhN2EwLmQwYWMzYTJlLTBkYjItNDI0NC04YjdkLTdjMTMwNjk4MjEzZHgxNzkxMjc0NTc0NTM5NzUwMDAw parts=1210442026/10/06 08:16:16 INFO Received uploads request method=POST path=/api/pending_closures1045--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.69s)1046=== CONT TestGCMetrics10472026/10/06 08:16:16 INFO Received push request method=POST path=/api/pushes1048--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (3.08s)1049=== CONT TestGCBugBareHashReferences1050--- PASS: TestReadRedirectUsesPublicS3URL (3.03s)1051=== CONT TestGCAdvisoryLockBlocksConcurrentRun10522026/10/06 08:16:17 WARN Rate limiter enabled after throttle name=s3-test rate=510532026/10/06 08:16:17 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1054=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1055 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101056 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001057--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.48s)1058=== CONT TestLeadEndsOnShutdown1059--- PASS: TestReadProxyRangeRequest (2.92s)1060=== CONT TestLeadIncumbentAnnouncesAtOnce1061--- PASS: TestReadRedirectNar (3.10s)1062=== CONT TestLeadElectsOneAndHandsOver10632026/10/06 08:16:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10642026/10/06 08:16:18 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NTZlMDI1N2EtMjk4My00YjVkLTg2MGMtN2FhZDk5NzFhN2EwLmNhZmY2MzJhLTYwYTAtNGYyNi05MjczLTg3ZWQ2ZTU5MmVmZXgxNzkxMjc0NTc2Mjc2NzA5MDAw error="Get \"http://127.0.0.1:1/bucket28/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"10652026/10/06 08:16:18 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NTZlMDI1N2EtMjk4My00YjVkLTg2MGMtN2FhZDk5NzFhN2EwLmNiYzBlMjA5LWVkYWItNDlmYy1iZjNiLTEyYTBmM2FkMzBjMXgxNzkxMjc0NTc2MjE3OTQ5MDAw parts=1210662026/10/06 08:16:18 INFO Received cleanup request method=DELETE path=/api/pending_closures10672026/10/06 08:16:18 INFO Aborted multipart uploads count=1 kept=01068--- PASS: TestRedundantMultipartUpload (6.68s)1069=== CONT TestConnectWaitsForAPeerMigration1070--- PASS: TestReadRedirectKeepsNarinfoProxied (3.82s)1071=== CONT TestResolveDBConnectionString1072=== RUN TestResolveDBConnectionString/flag_wins1073=== PAUSE TestResolveDBConnectionString/flag_wins1074=== RUN TestResolveDBConnectionString/file_when_flag_empty1075=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1076=== RUN TestResolveDBConnectionString/missing_file_is_an_error1077=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1078=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1079=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1080=== RUN TestResolveDBConnectionString/nothing_configured1081=== PAUSE TestResolveDBConnectionString/nothing_configured1082=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1083--- PASS: TestReadProxyDisabled (3.14s)1084=== CONT TestClientFallsBackToClosures10852026/10/06 08:16:20 INFO Aborted multipart uploads count=0 kept=010862026/10/06 08:16:20 WARN Force mode enabled - objects will be deleted immediately without grace period10872026/10/06 08:16:20 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=010882026/10/06 08:16:20 INFO Vacuumed table table=pending_closures10892026/10/06 08:16:20 INFO Vacuumed table table=pending_objects10902026/10/06 08:16:20 INFO Vacuumed table table=multipart_uploads10912026/10/06 08:16:20 INFO Vacuumed table table=closures10922026/10/06 08:16:20 INFO Vacuumed table table=objects1093--- PASS: TestGCMetrics (3.52s)1094=== CONT TestClientPushesUseOnePush10952026/10/06 08:16:20 INFO Received push request method=POST path=/api/pushes10962026/10/06 08:16:20 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)10972026/10/06 08:16:20 INFO Uploading 7d9rl5n452xd4n0fhqjgic7qn56fhxas-shared-dep (136B)10982026/10/06 08:16:20 INFO Uploading 5xsndc2s6gkqprd7gnrvld0z26i8hwjn-top (256B)10992026/10/06 08:16:20 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11002026/10/06 08:16:20 WARN Failed to register uploaded object key=7d9rl5n452xd4n0fhqjgic7qn56fhxas.ls error="server returned 404: 404 page not found\n"11012026/10/06 08:16:20 WARN Failed to register uploaded object key=5xsndc2s6gkqprd7gnrvld0z26i8hwjn.ls error="server returned 404: 404 page not found\n"11022026/10/06 08:16:20 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11032026/10/06 08:16:20 WARN Failed to register uploaded object key=nar/1vhpf40jbv9appviv1062n77g83bngkca8zajyi90n5jrk8zba20.nar.zst error="server returned 404: 404 page not found\n"11042026/10/06 08:16:20 INFO Signed narinfos id=1 count=211052026/10/06 08:16:20 INFO Uploading 2 narinfos11062026/10/06 08:16:20 INFO Received complete push request method=POST path=/api/pushes/1/complete11072026/10/06 08:16:20 WARN Failed to register uploaded object key=5xsndc2s6gkqprd7gnrvld0z26i8hwjn.narinfo error="server returned 404: 404 page not found\n"11082026/10/06 08:16:20 WARN Failed to register uploaded object key=7d9rl5n452xd4n0fhqjgic7qn56fhxas.narinfo error="server returned 404: 404 page not found\n"11092026/10/06 08:16:20 INFO Upload complete. (136ms)1110=== NAME TestClientSharedPathCommittedMidPush1111 client_integration_test.go:680: Retrieved narinfo from S3:1112 StorePath: /nix/var/nix/builds/nix-18015-426991606/TestClientSharedPathCommittedMidPush1719552086/001/store/7d9rl5n452xd4n0fhqjgic7qn56fhxas-shared-dep1113 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1114 Compression: zstd1115 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821116 NarSize: 1361117 References: 1118 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1119 client_integration_test.go:680: Retrieved narinfo from S3:1120 StorePath: /nix/var/nix/builds/nix-18015-426991606/TestClientSharedPathCommittedMidPush1719552086/001/store/5xsndc2s6gkqprd7gnrvld0z26i8hwjn-top1121 URL: nar/1vhpf40jbv9appviv1062n77g83bngkca8zajyi90n5jrk8zba20.nar.zst1122 Compression: zstd1123 NarHash: sha256:1vhpf40jbv9appviv1062n77g83bngkca8zajyi90n5jrk8zba201124 NarSize: 2561125 References: /nix/var/nix/builds/nix-18015-426991606/TestClientSharedPathCommittedMidPush1719552086/001/store/7d9rl5n452xd4n0fhqjgic7qn56fhxas-shared-dep1126 CA: text:sha256:10yc6k111fkldjvp2b295cxhzrl80l5qrw1d6jgiwcasw5ra0am41127--- PASS: TestClientSharedPathCommittedMidPush (3.74s)1128=== CONT TestPinProtectsFromGC1129--- PASS: TestGCBugBareHashReferences (3.55s)1130=== CONT TestPresentReportsOnlyClosureRoots11312026/10/06 08:16:20 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_nixbld12 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1132--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (3.26s)1133=== CONT TestReadProxyConditionalGet11342026/10/06 08:16:20 INFO lead: acquired remote=192.0.2.1:123411352026/10/06 08:16:21 INFO lead: acquired remote=192.0.2.1:123411362026/10/06 08:16:21 INFO lead: released remote=192.0.2.1:12341137--- PASS: TestLeadIncumbentAnnouncesAtOnce (3.11s)1138=== CONT TestReadProxyOutlastsServerWriteTimeout11392026/10/06 08:16:21 INFO lead: acquired remote=192.0.2.1:123411402026/10/06 08:16:21 INFO lead: released remote=192.0.2.1:12341141--- PASS: TestLeadEndsOnShutdown (4.31s)1142=== CONT TestReadProxyHead11432026/10/06 08:16:22 INFO Received uploads request method=POST path=/api/pending_closures11442026/10/06 08:16:22 INFO Received uploads request method=POST path=/api/pending_closures1145--- PASS: TestReadProxyConditionalGet (1.96s)1146=== CONT TestReadProxyInvalidPath11472026/10/06 08:16:22 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11482026/10/06 08:16:22 INFO Uploading n5li5q51lg0f0aa06qmrrfpl66ncdmk9-b (248B)11492026/10/06 08:16:22 INFO Uploading saibysxxybip3r15mkdgwzp27zai4qml-shared-dep (136B)1150--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (3.46s)1151=== CONT TestReadProxy40411522026/10/06 08:16:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11532026/10/06 08:16:22 WARN Failed to register uploaded object key=saibysxxybip3r15mkdgwzp27zai4qml.ls error="server returned 404: 404 page not found\n"11542026/10/06 08:16:22 WARN Failed to register uploaded object key=n5li5q51lg0f0aa06qmrrfpl66ncdmk9.ls error="server returned 404: 404 page not found\n"11552026/10/06 08:16:22 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11562026/10/06 08:16:22 WARN Failed to register uploaded object key=f3diqy9inxc82nhr21z4y3p95whxyy7l.ls error="server returned 404: 404 page not found\n"11572026/10/06 08:16:22 WARN Failed to register uploaded object key=nar/0mjypy7yra4nlvpimh67ak60gm41brq36v5b4bm0hqp1gnb60zd1.nar.zst error="server returned 404: 404 page not found\n"11582026/10/06 08:16:22 INFO Signed narinfos id=1 count=211592026/10/06 08:16:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign11602026/10/06 08:16:22 INFO Signed narinfos id=2 count=211612026/10/06 08:16:22 INFO Uploading 4 narinfos11622026/10/06 08:16:22 WARN Failed to register uploaded object key=saibysxxybip3r15mkdgwzp27zai4qml.narinfo error="server returned 404: 404 page not found\n"11632026/10/06 08:16:22 WARN Failed to register uploaded object key=n5li5q51lg0f0aa06qmrrfpl66ncdmk9.narinfo error="server returned 404: 404 page not found\n"11642026/10/06 08:16:22 WARN Failed to register uploaded object key=f3diqy9inxc82nhr21z4y3p95whxyy7l.narinfo error="server returned 404: 404 page not found\n"11652026/10/06 08:16:22 INFO lead: released remote=192.0.2.1:123411662026/10/06 08:16:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11672026/10/06 08:16:22 WARN Failed to register uploaded object key=saibysxxybip3r15mkdgwzp27zai4qml.narinfo error="server returned 404: 404 page not found\n"11682026/10/06 08:16:22 INFO Completed upload id=111692026/10/06 08:16:22 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11702026/10/06 08:16:22 INFO Completed upload id=211712026/10/06 08:16:22 INFO Upload complete. (227ms)1172=== NAME TestClientFallsBackToClosures1173 client_pushes_test.go:112: Retrieved narinfo from S3:1174 StorePath: /nix/var/nix/builds/nix-18015-426991606/TestClientFallsBackToClosures405362124/001/store/saibysxxybip3r15mkdgwzp27zai4qml-shared-dep1175 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1176 Compression: zstd1177 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821178 NarSize: 1361179 References: 1180 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1181 client_pushes_test.go:112: Retrieved narinfo from S3:1182 StorePath: /nix/var/nix/builds/nix-18015-426991606/TestClientFallsBackToClosures405362124/001/store/f3diqy9inxc82nhr21z4y3p95whxyy7l-a1183 URL: nar/0mjypy7yra4nlvpimh67ak60gm41brq36v5b4bm0hqp1gnb60zd1.nar.zst1184 Compression: zstd1185 NarHash: sha256:0mjypy7yra4nlvpimh67ak60gm41brq36v5b4bm0hqp1gnb60zd11186 NarSize: 2481187 References: /nix/var/nix/builds/nix-18015-426991606/TestClientFallsBackToClosures405362124/001/store/saibysxxybip3r15mkdgwzp27zai4qml-shared-dep1188 CA: text:sha256:0bl051kvqdya0abvb3sh3dxnzh0sj25r7zhycwnkpgszdymvfskm1189 client_pushes_test.go:112: Retrieved narinfo from S3:1190 StorePath: /nix/var/nix/builds/nix-18015-426991606/TestClientFallsBackToClosures405362124/001/store/n5li5q51lg0f0aa06qmrrfpl66ncdmk9-b1191 URL: nar/0mjypy7yra4nlvpimh67ak60gm41brq36v5b4bm0hqp1gnb60zd1.nar.zst1192 Compression: zstd1193 NarHash: sha256:0mjypy7yra4nlvpimh67ak60gm41brq36v5b4bm0hqp1gnb60zd11194 NarSize: 2481195 References: /nix/var/nix/builds/nix-18015-426991606/TestClientFallsBackToClosures405362124/001/store/saibysxxybip3r15mkdgwzp27zai4qml-shared-dep1196 CA: text:sha256:0bl051kvqdya0abvb3sh3dxnzh0sj25r7zhycwnkpgszdymvfskm11972026/10/06 08:16:22 INFO lead: acquired remote=192.0.2.1:12341198--- PASS: TestClientFallsBackToClosures (3.22s)1199=== CONT TestReadProxyNarStreaming1200=== NAME TestPinProtectsFromGC1201 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-18015-426991606/TestPinProtectsFromGC3938906996/001/store/39n624aqnn9lb5xmnyq9w1m334m3vsmb-pinned-file.txt1202 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-18015-426991606/TestPinProtectsFromGC3938906996/001/store/rrfcwrclf6hv6087c06087gvxkdgbvp6-unpinned-file.txt12032026/10/06 08:16:22 INFO Received push request method=POST path=/api/pushes12042026/10/06 08:16:22 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12052026/10/06 08:16:22 INFO Uploading n9vr6p63f6dlh987j8c721ygjzwhxfmw-a (248B)1206--- PASS: TestPresentReportsOnlyClosureRoots (2.29s)1207=== CONT TestReadProxyNarinfoAlreadyDecompressed12082026/10/06 08:16:22 INFO Uploading abn53hd2p9f50rgw1i76njd5wlqd74f4-shared-dep (136B)12092026/10/06 08:16:22 WARN Failed to register uploaded object key=bq40xjf9s9h0j8af740p5hjf176aaywk.ls error="server returned 404: 404 page not found\n"12102026/10/06 08:16:22 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12112026/10/06 08:16:22 WARN Failed to register uploaded object key=n9vr6p63f6dlh987j8c721ygjzwhxfmw.ls error="server returned 404: 404 page not found\n"12122026/10/06 08:16:22 WARN Failed to register uploaded object key=abn53hd2p9f50rgw1i76njd5wlqd74f4.ls error="server returned 404: 404 page not found\n"12132026/10/06 08:16:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12142026/10/06 08:16:22 WARN Failed to register uploaded object key=nar/1ymir9vf9wlya0qqybzd3ldfkxiv5fwrbz46p40mc0ns5i2bsp1z.nar.zst error="server returned 404: 404 page not found\n"12152026/10/06 08:16:22 INFO Signed narinfos id=1 count=312162026/10/06 08:16:22 INFO Uploading 3 narinfos12172026/10/06 08:16:22 WARN Failed to register uploaded object key=bq40xjf9s9h0j8af740p5hjf176aaywk.narinfo error="server returned 404: 404 page not found\n"12182026/10/06 08:16:22 WARN Failed to register uploaded object key=abn53hd2p9f50rgw1i76njd5wlqd74f4.narinfo error="server returned 404: 404 page not found\n"12192026/10/06 08:16:22 INFO Received complete push request method=POST path=/api/pushes/1/complete12202026/10/06 08:16:22 WARN Failed to register uploaded object key=n9vr6p63f6dlh987j8c721ygjzwhxfmw.narinfo error="server returned 404: 404 page not found\n"12212026/10/06 08:16:22 INFO Upload complete. (229ms)1222=== NAME TestClientPushesUseOnePush1223 client_pushes_test.go:97: Retrieved narinfo from S3:1224 StorePath: /nix/var/nix/builds/nix-18015-426991606/TestClientPushesUseOnePush381241115/001/store/abn53hd2p9f50rgw1i76njd5wlqd74f4-shared-dep1225 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1226 Compression: zstd1227 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821228 NarSize: 1361229 References: 1230 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1231 client_pushes_test.go:97: Retrieved narinfo from S3:1232 StorePath: /nix/var/nix/builds/nix-18015-426991606/TestClientPushesUseOnePush381241115/001/store/n9vr6p63f6dlh987j8c721ygjzwhxfmw-a1233 URL: nar/1ymir9vf9wlya0qqybzd3ldfkxiv5fwrbz46p40mc0ns5i2bsp1z.nar.zst1234 Compression: zstd1235 NarHash: sha256:1ymir9vf9wlya0qqybzd3ldfkxiv5fwrbz46p40mc0ns5i2bsp1z1236 NarSize: 2481237 References: /nix/var/nix/builds/nix-18015-426991606/TestClientPushesUseOnePush381241115/001/store/abn53hd2p9f50rgw1i76njd5wlqd74f4-shared-dep1238 CA: text:sha256:0zj27zkgffy0pf3lmq3kkzinwps7rlp9f9m91fd0snkdmr75gn0c1239 client_pushes_test.go:97: Retrieved narinfo from S3:1240 StorePath: /nix/var/nix/builds/nix-18015-426991606/TestClientPushesUseOnePush381241115/001/store/bq40xjf9s9h0j8af740p5hjf176aaywk-b1241 URL: nar/1ymir9vf9wlya0qqybzd3ldfkxiv5fwrbz46p40mc0ns5i2bsp1z.nar.zst1242 Compression: zstd1243 NarHash: sha256:1ymir9vf9wlya0qqybzd3ldfkxiv5fwrbz46p40mc0ns5i2bsp1z1244 NarSize: 2481245 References: /nix/var/nix/builds/nix-18015-426991606/TestClientPushesUseOnePush381241115/001/store/abn53hd2p9f50rgw1i76njd5wlqd74f4-shared-dep1246 CA: text:sha256:0zj27zkgffy0pf3lmq3kkzinwps7rlp9f9m91fd0snkdmr75gn0c12472026/10/06 08:16:22 INFO Received push request method=POST path=/api/pushes1248--- PASS: TestClientPushesUseOnePush (2.85s)1249=== CONT TestReadProxyNarinfo12502026/10/06 08:16:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12512026/10/06 08:16:22 INFO Uploading 39n624aqnn9lb5xmnyq9w1m334m3vsmb-pinned-file.txt (128B)12522026/10/06 08:16:22 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"12532026/10/06 08:16:23 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12542026/10/06 08:16:23 WARN Failed to register uploaded object key=39n624aqnn9lb5xmnyq9w1m334m3vsmb.ls error="server returned 404: 404 page not found\n"12552026/10/06 08:16:23 INFO Signed narinfos id=1 count=112562026/10/06 08:16:23 INFO Uploading 1 narinfos12572026/10/06 08:16:23 INFO Received complete push request method=POST path=/api/pushes/1/complete12582026/10/06 08:16:23 WARN Failed to register uploaded object key=39n624aqnn9lb5xmnyq9w1m334m3vsmb.narinfo error="server returned 404: 404 page not found\n"12592026/10/06 08:16:23 INFO Upload complete. (285ms)1260--- PASS: TestReadProxyHead (1.42s)1261=== CONT TestIsValidCachePath1262=== RUN TestIsValidCachePath/narinfo1263=== PAUSE TestIsValidCachePath/narinfo1264=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1265=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1266=== RUN TestIsValidCachePath/nar_zst1267=== PAUSE TestIsValidCachePath/nar_zst1268=== RUN TestIsValidCachePath/nar_xz1269=== PAUSE TestIsValidCachePath/nar_xz1270=== RUN TestIsValidCachePath/nar_bz21271=== PAUSE TestIsValidCachePath/nar_bz21272=== RUN TestIsValidCachePath/nar_uncompressed1273=== PAUSE TestIsValidCachePath/nar_uncompressed1274=== RUN TestIsValidCachePath/ls1275=== PAUSE TestIsValidCachePath/ls1276=== RUN TestIsValidCachePath/log1277=== PAUSE TestIsValidCachePath/log1278=== RUN TestIsValidCachePath/realisation1279=== PAUSE TestIsValidCachePath/realisation1280=== RUN TestIsValidCachePath/nix-cache-info1281=== PAUSE TestIsValidCachePath/nix-cache-info1282=== RUN TestIsValidCachePath/index.html1283=== PAUSE TestIsValidCachePath/index.html1284=== RUN TestIsValidCachePath/traversal_parent1285=== PAUSE TestIsValidCachePath/traversal_parent1286=== RUN TestIsValidCachePath/traversal_in_middle1287=== PAUSE TestIsValidCachePath/traversal_in_middle1288=== RUN TestIsValidCachePath/invalid_char_e1289=== PAUSE TestIsValidCachePath/invalid_char_e1290=== RUN TestIsValidCachePath/invalid_char_u1291=== PAUSE TestIsValidCachePath/invalid_char_u1292=== RUN TestIsValidCachePath/random_path1293=== PAUSE TestIsValidCachePath/random_path1294=== RUN TestIsValidCachePath/empty1295=== PAUSE TestIsValidCachePath/empty1296=== RUN TestIsValidCachePath/leading_slash1297=== PAUSE TestIsValidCachePath/leading_slash1298=== RUN TestIsValidCachePath/wrong_extension1299=== PAUSE TestIsValidCachePath/wrong_extension1300=== RUN TestIsValidCachePath/short_hash1301=== PAUSE TestIsValidCachePath/short_hash1302=== CONT TestProxyHeadersOnlyTrustedOnSocket13032026/10/06 08:16:23 INFO Received push request method=POST path=/api/pushes13042026/10/06 08:16:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13052026/10/06 08:16:23 INFO Uploading rrfcwrclf6hv6087c06087gvxkdgbvp6-unpinned-file.txt (128B)13062026/10/06 08:16:23 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"13072026/10/06 08:16:23 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13082026/10/06 08:16:23 INFO Signed narinfos id=2 count=113092026/10/06 08:16:23 WARN Failed to register uploaded object key=rrfcwrclf6hv6087c06087gvxkdgbvp6.ls error="server returned 404: 404 page not found\n"13102026/10/06 08:16:23 INFO Uploading 1 narinfos13112026/10/06 08:16:23 INFO Received complete push request method=POST path=/api/pushes/2/complete13122026/10/06 08:16:23 WARN Failed to register uploaded object key=rrfcwrclf6hv6087c06087gvxkdgbvp6.narinfo error="server returned 404: 404 page not found\n"13132026/10/06 08:16:23 INFO Upload complete. (282ms)1314--- PASS: TestReadProxyInvalidPath (1.06s)1315=== CONT TestParseSingleRange1316=== RUN TestParseSingleRange/none1317=== PAUSE TestParseSingleRange/none1318=== RUN TestParseSingleRange/unknown_unit1319=== PAUSE TestParseSingleRange/unknown_unit1320=== RUN TestParseSingleRange/multi-range_ignored1321=== PAUSE TestParseSingleRange/multi-range_ignored1322=== RUN TestParseSingleRange/malformed_no_dash1323=== PAUSE TestParseSingleRange/malformed_no_dash1324=== RUN TestParseSingleRange/malformed_both_empty1325=== PAUSE TestParseSingleRange/malformed_both_empty1326=== RUN TestParseSingleRange/malformed_end_before_start1327=== PAUSE TestParseSingleRange/malformed_end_before_start1328=== RUN TestParseSingleRange/closed1329=== PAUSE TestParseSingleRange/closed1330=== RUN TestParseSingleRange/open-ended1331=== PAUSE TestParseSingleRange/open-ended1332=== RUN TestParseSingleRange/end_clamped_to_size1333=== PAUSE TestParseSingleRange/end_clamped_to_size1334=== RUN TestParseSingleRange/suffix1335=== PAUSE TestParseSingleRange/suffix1336=== RUN TestParseSingleRange/suffix_exceeds_size1337=== PAUSE TestParseSingleRange/suffix_exceeds_size1338=== RUN TestParseSingleRange/single_byte1339=== PAUSE TestParseSingleRange/single_byte1340=== RUN TestParseSingleRange/start_past_EOF1341=== PAUSE TestParseSingleRange/start_past_EOF1342=== RUN TestParseSingleRange/start_far_past_EOF1343=== PAUSE TestParseSingleRange/start_far_past_EOF1344=== CONT TestPresentNotReportedWhileGCDeletesClosure13452026/10/06 08:16:23 INFO Starting cleanup of old closures method=DELETE path=/api/closures13462026/10/06 08:16:23 INFO Garbage collection started13472026/10/06 08:16:23 INFO Aborted multipart uploads count=0 kept=013482026/10/06 08:16:23 WARN Force mode enabled - objects will be deleted immediately without grace period13492026/10/06 08:16:23 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=013502026/10/06 08:16:23 INFO Vacuumed table table=pending_closures13512026/10/06 08:16:23 INFO Vacuumed table table=pending_objects13522026/10/06 08:16:23 INFO Vacuumed table table=multipart_uploads13532026/10/06 08:16:23 INFO Vacuumed table table=closures13542026/10/06 08:16:23 INFO Vacuumed table table=objects13552026/10/06 08:16:23 INFO lead: released remote=192.0.2.1:12341356--- PASS: TestLeadElectsOneAndHandsOver (5.20s)1357=== CONT TestMultipartCleanup1358--- PASS: TestReadProxy404 (1.34s)1359=== CONT TestCreatePin_ReservedPins13602026/10/06 08:16:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64751/oidc1361--- PASS: TestReadProxyNarStreaming (1.36s)1362=== CONT TestOrphanedObjectsGCStressTest1363--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.49s)1364=== CONT TestOrphanedObjectsGC13652026/10/06 08:16:24 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"13662026/10/06 08:16:24 INFO Starting HTTP server address=127.0.0.1:6476813672026/10/06 08:16:24 INFO Starting HTTP server address=/nix/var/nix/builds/nix-18015-426991606/TestProxyHeadersOnlyTrustedOnSocket2475930874/001/proxy.sock13682026/10/06 08:16:24 WARN mTLS auth: subject not in bound subjects subject="CN=someone"13692026/10/06 08:16:24 INFO Shutdown signal received, draining in-flight requests timeout=10s1370--- PASS: TestProxyHeadersOnlyTrustedOnSocket (1.51s)1371=== CONT TestObjectStatsTrigger13722026/10/06 08:16:24 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772161373--- PASS: TestReadProxyNarinfo (1.93s)1374=== CONT TestPendingCleanupUsesOneCutoff1375--- PASS: TestConnectWaitsForAPeerMigration (6.37s)1376=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded13772026/10/06 08:16:25 INFO Received uploads request method=POST path=/api/pending_closures13782026/10/06 08:16:25 INFO Received cleanup request method=DELETE path=/api/pending_closures13792026/10/06 08:16:25 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket63/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""13802026/10/06 08:16:25 INFO Aborted multipart uploads count=0 kept=113812026/10/06 08:16:25 INFO Received cleanup request method=DELETE path=/api/pending_closures13822026/10/06 08:16:25 INFO Aborted multipart uploads count=1 kept=01383--- PASS: TestMultipartCleanup (1.72s)1384=== CONT TestCacheConfigHandler1385=== RUN TestCacheConfigHandler/full_config,_no_issuer1386=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1387=== RUN TestCacheConfigHandler/no_cache_url_configured1388=== PAUSE TestCacheConfigHandler/no_cache_url_configured1389=== RUN TestCacheConfigHandler/no_signing_keys1390=== PAUSE TestCacheConfigHandler/no_signing_keys1391=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1392=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1393=== CONT TestClientWithDependencies13942026/10/06 08:16:25 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13952026/10/06 08:16:25 WARN Refused reserved pin name=worker-x86_64-linux13962026/10/06 08:16:25 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13972026/10/06 08:16:25 INFO Received create pin request method=POST path=/api/pins/my-app13982026/10/06 08:16:25 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1399--- PASS: TestCreatePin_ReservedPins (1.69s)1400=== CONT TestClientMultipleUploads1401--- PASS: TestPresentNotReportedWhileGCDeletesClosure (2.01s)1402=== CONT TestClientIntegration14032026/10/06 08:16:25 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=014042026/10/06 08:16:25 INFO Received create pin request method=POST path=/api/pins/myapp14052026/10/06 08:16:25 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-18015-426991606/TestPinProtectsFromGC3938906996/001/store/39n624aqnn9lb5xmnyq9w1m334m3vsmb-pinned-file.txt narinfo_key=39n624aqnn9lb5xmnyq9w1m334m3vsmb.narinfo14062026/10/06 08:16:25 INFO Starting cleanup of old closures method=DELETE path=/api/closures14072026/10/06 08:16:25 INFO Garbage collection started14082026/10/06 08:16:25 INFO Aborted multipart uploads count=0 kept=014092026/10/06 08:16:25 WARN Force mode enabled - objects will be deleted immediately without grace period14102026/10/06 08:16:25 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=014112026/10/06 08:16:25 INFO Vacuumed table table=pending_closures14122026/10/06 08:16:25 INFO Vacuumed table table=pending_objects14132026/10/06 08:16:25 INFO Vacuumed table table=multipart_uploads14142026/10/06 08:16:25 INFO Vacuumed table table=closures14152026/10/06 08:16:25 INFO Vacuumed table table=objects1416--- PASS: TestObjectStatsTrigger (1.53s)1417=== CONT TestClientErrorHandling1418=== RUN TestClientErrorHandling/InvalidStorePath1419=== PAUSE TestClientErrorHandling/InvalidStorePath1420=== RUN TestClientErrorHandling/InvalidAuthToken1421=== PAUSE TestClientErrorHandling/InvalidAuthToken1422=== RUN TestClientErrorHandling/ServerNotAvailable1423=== PAUSE TestClientErrorHandling/ServerNotAvailable1424=== CONT TestClientCADerivations14252026/10/06 08:16:26 INFO Received uploads request method=POST path=/api/pending_closures14262026/10/06 08:16:26 INFO Received uploads request method=POST path=/api/pending_closures14272026/10/06 08:16:26 INFO Received cleanup request method=DELETE path=/api/pending_closures1428=== NAME TestOrphanedObjectsGC1429 orphaned_objects_gc_test.go:290: GC Test Summary:1430 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1431 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1432 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1433 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1434 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1435--- PASS: TestOrphanedObjectsGC (2.52s)1436=== CONT TestCacheStatsHandler14372026/10/06 08:16:26 INFO Received uploads request method=POST path=/api/pending_closures1438--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (1.85s)1439=== CONT TestService_AuthMiddleware_OIDC14402026/10/06 08:16:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64798/oidc1441--- PASS: TestReadProxyOutlastsServerWriteTimeout (6.15s)1442=== CONT TestService_ReadScope_PublicByDefault1443=== NAME TestPinProtectsFromGC1444 client_integration_test.go:840: Pin successfully protected closure from garbage collection1445--- PASS: TestPinProtectsFromGC (7.38s)1446=== CONT TestService_RequireScope_OIDC14472026/10/06 08:16:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64806/oidc1448=== NAME TestClientIntegration1449 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-18015-426991606/TestClientIntegration3963315638/002/store/s849vm61mscis2pzy67mlc42blc7jz5f-test-file.txt14502026/10/06 08:16:28 INFO Received push request method=POST path=/api/pushes1451=== NAME TestClientMultipleUploads1452 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-18015-426991606/TestClientMultipleUploads742060926/001/store/p777lxdl5lqn5b079nkzwrjc4lb8x1gs-test-file-0.txt1453=== NAME TestClientWithDependencies1454 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-18015-426991606/TestClientWithDependencies53048238/001/store/fi1qafwv6kk6ysrpjgsi6vj081j59s66-test-script14552026/10/06 08:16:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14562026/10/06 08:16:28 INFO Uploading s849vm61mscis2pzy67mlc42blc7jz5f-test-file.txt (152B)14572026/10/06 08:16:28 WARN Failed to register uploaded object key=s849vm61mscis2pzy67mlc42blc7jz5f.ls error="server returned 404: 404 page not found\n"14582026/10/06 08:16:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14592026/10/06 08:16:28 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"14602026/10/06 08:16:28 INFO Signed narinfos id=1 count=114612026/10/06 08:16:28 INFO Uploading 1 narinfos14622026/10/06 08:16:28 INFO Received complete push request method=POST path=/api/pushes/1/complete14632026/10/06 08:16:28 WARN Failed to register uploaded object key=s849vm61mscis2pzy67mlc42blc7jz5f.narinfo error="server returned 404: 404 page not found\n"14642026/10/06 08:16:28 INFO Upload complete. (361ms)1465=== NAME TestClientMultipleUploads1466 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-18015-426991606/TestClientMultipleUploads742060926/001/store/1b2x85d4myrvyimv5nifdc8qf4y1ryaz-test-file-1.txt14672026/10/06 08:16:28 INFO All 1 paths already cached1468=== NAME TestClientIntegration1469 client_integration_test.go:312: Retrieved narinfo from S3:1470 StorePath: /nix/var/nix/builds/nix-18015-426991606/TestClientIntegration3963315638/002/store/s849vm61mscis2pzy67mlc42blc7jz5f-test-file.txt1471 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1472 Compression: zstd1473 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11474 NarSize: 1521475 References: 1476 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11477 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1478 client_integration_test.go:313: Decompressed .ls content (64 bytes):1479 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1480 client_integration_test.go:316: Testing garbage collection...14812026/10/06 08:16:28 INFO Starting cleanup of old closures method=DELETE path=/api/closures14822026/10/06 08:16:28 INFO Garbage collection started1483=== NAME TestClientWithDependencies1484 client_integration_test.go:615: Found 1 dependencies (including self)14852026/10/06 08:16:28 INFO Aborted multipart uploads count=0 kept=014862026/10/06 08:16:28 WARN Force mode enabled - objects will be deleted immediately without grace period1487--- PASS: TestCacheStatsHandler (1.92s)1488=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1489=== NAME TestClientMultipleUploads1490 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-18015-426991606/TestClientMultipleUploads742060926/001/store/731bggbgkx39r51p7j8kxyinrlai4pyz-test-file-2.txt14912026/10/06 08:16:28 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=014922026/10/06 08:16:28 INFO Vacuumed table table=pending_closures14932026/10/06 08:16:28 INFO Vacuumed table table=pending_objects14942026/10/06 08:16:28 INFO Vacuumed table table=multipart_uploads14952026/10/06 08:16:28 INFO Vacuumed table table=closures14962026/10/06 08:16:28 INFO Vacuumed table table=objects14972026/10/06 08:16:28 INFO Received push request method=POST path=/api/pushes14982026/10/06 08:16:28 INFO Received push request method=POST path=/api/pushes14992026/10/06 08:16:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15002026/10/06 08:16:28 INFO Uploading fi1qafwv6kk6ysrpjgsi6vj081j59s66-test-script (136B)15012026/10/06 08:16:28 WARN Failed to register uploaded object key=fi1qafwv6kk6ysrpjgsi6vj081j59s66.ls error="server returned 404: 404 page not found\n"15022026/10/06 08:16:28 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15032026/10/06 08:16:28 INFO Uploading 731bggbgkx39r51p7j8kxyinrlai4pyz-test-file-2.txt (160B)15042026/10/06 08:16:28 INFO Uploading p777lxdl5lqn5b079nkzwrjc4lb8x1gs-test-file-0.txt (160B)15052026/10/06 08:16:28 INFO Uploading 1b2x85d4myrvyimv5nifdc8qf4y1ryaz-test-file-1.txt (160B)15062026/10/06 08:16:28 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15072026/10/06 08:16:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15082026/10/06 08:16:28 WARN Failed to register uploaded object key=log/kwp6lxib5mjwjhxsgydlr3p54s8pmcf9-test-script.drv error="server returned 404: 404 page not found\n"15092026/10/06 08:16:28 INFO Signed narinfos id=1 count=115102026/10/06 08:16:28 INFO Uploading 1 narinfos15112026/10/06 08:16:28 WARN Failed to register uploaded object key=p777lxdl5lqn5b079nkzwrjc4lb8x1gs.ls error="server returned 404: 404 page not found\n"15122026/10/06 08:16:28 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15132026/10/06 08:16:28 WARN Failed to register uploaded object key=731bggbgkx39r51p7j8kxyinrlai4pyz.ls error="server returned 404: 404 page not found\n"15142026/10/06 08:16:28 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15152026/10/06 08:16:28 INFO Received complete push request method=POST path=/api/pushes/1/complete15162026/10/06 08:16:28 WARN Failed to register uploaded object key=fi1qafwv6kk6ysrpjgsi6vj081j59s66.narinfo error="server returned 404: 404 page not found\n"15172026/10/06 08:16:28 WARN Failed to register uploaded object key=1b2x85d4myrvyimv5nifdc8qf4y1ryaz.ls error="server returned 404: 404 page not found\n"15182026/10/06 08:16:29 INFO Upload complete. (171ms)15192026/10/06 08:16:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15202026/10/06 08:16:29 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15212026/10/06 08:16:29 INFO Signed narinfos id=1 count=315222026/10/06 08:16:29 INFO Uploading 3 narinfos1523=== NAME TestClientWithDependencies1524 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-18015-426991606/TestClientWithDependencies53048238/001/store) requires matching store prefix1525=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1526=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1527=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1528=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1529=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1530=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1531=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1532=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1533=== CONT TestService_ReadAuthMiddleware15342026/10/06 08:16:29 WARN Failed to register uploaded object key=p777lxdl5lqn5b079nkzwrjc4lb8x1gs.narinfo error="server returned 404: 404 page not found\n"15352026/10/06 08:16:29 WARN Failed to register uploaded object key=1b2x85d4myrvyimv5nifdc8qf4y1ryaz.narinfo error="server returned 404: 404 page not found\n"15362026/10/06 08:16:29 INFO Received complete push request method=POST path=/api/pushes/1/complete15372026/10/06 08:16:29 WARN Failed to register uploaded object key=731bggbgkx39r51p7j8kxyinrlai4pyz.narinfo error="server returned 404: 404 page not found\n"15382026/10/06 08:16:29 INFO Upload complete. (173ms)1539=== NAME TestClientMultipleUploads1540 client_integration_test.go:369: Uploaded 3 paths in 235.594792ms1541--- PASS: TestClientWithDependencies (3.56s)1542=== CONT TestService_AuthMiddleware_MTLSProxyHeader1543=== NAME TestClientCADerivations1544 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-18015-426991606/TestClientCADerivations2991535925/001/store/k81phd3wa261irjfs3rac32w9a57c9xi-ca-test1545--- PASS: TestClientMultipleUploads (3.55s)1546=== CONT TestMetricsInventory1547=== NAME TestClientCADerivations1548 client_ca_test.go:139: Found 1 dependencies (including self)1549--- PASS: TestService_ReadScope_PublicByDefault (1.99s)1550=== CONT TestServerTLSConfig1551=== RUN TestServerTLSConfig/no_client_CA1552=== PAUSE TestServerTLSConfig/no_client_CA1553=== RUN TestServerTLSConfig/missing_CA_file1554=== PAUSE TestServerTLSConfig/missing_CA_file1555=== RUN TestServerTLSConfig/not_a_PEM_file1556=== PAUSE TestServerTLSConfig/not_a_PEM_file1557=== CONT TestService_NativeMTLS15582026/10/06 08:16:29 INFO Received push request method=POST path=/api/pushes15592026/10/06 08:16:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15602026/10/06 08:16:29 INFO Uploading k81phd3wa261irjfs3rac32w9a57c9xi-ca-test (144B)15612026/10/06 08:16:29 WARN Failed to register uploaded object key=k81phd3wa261irjfs3rac32w9a57c9xi.ls error="server returned 404: 404 page not found\n"15622026/10/06 08:16:29 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"15632026/10/06 08:16:29 WARN Failed to register uploaded object key=log/ra5apf1md49jbn9j5rmqrh62cqphamx1-ca-test.drv error="server returned 404: 404 page not found\n"15642026/10/06 08:16:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15652026/10/06 08:16:29 INFO Signed narinfos id=1 count=115662026/10/06 08:16:29 INFO Uploading 1 narinfos15672026/10/06 08:16:29 INFO Received complete push request method=POST path=/api/pushes/1/complete15682026/10/06 08:16:29 WARN Failed to register uploaded object key=k81phd3wa261irjfs3rac32w9a57c9xi.narinfo error="server returned 404: 404 page not found\n"15692026/10/06 08:16:29 INFO Upload complete. (265ms)1570=== NAME TestClientCADerivations1571 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-18015-426991606/TestClientCADerivations2991535925/001/store/k81phd3wa261irjfs3rac32w9a57c9xi-ca-test1572 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1573 Compression: zstd1574 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1575 NarSize: 1441576 References: 1577 Deriver: /nix/var/nix/builds/nix-18015-426991606/TestClientCADerivations2991535925/001/store/ra5apf1md49jbn9j5rmqrh62cqphamx1-ca-test.drv1578 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1579 client_ca_test.go:185: Checking for realisation files in S3...1580 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1581 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1582=== RUN TestService_RequireScope_OIDC/builder_may_write1583=== PAUSE TestService_RequireScope_OIDC/builder_may_write1584=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1585=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1586=== RUN TestService_RequireScope_OIDC/ops_may_admin1587=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1588=== RUN TestService_RequireScope_OIDC/ops_may_not_write1589=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1590=== RUN TestService_RequireScope_OIDC/reader_may_not_write1591=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1592=== RUN TestService_RequireScope_OIDC/static_token_may_admin1593=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1594=== RUN TestService_RequireScope_OIDC/static_token_may_write1595=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1596=== RUN TestService_RequireScope_OIDC/reader_may_read1597=== PAUSE TestService_RequireScope_OIDC/reader_may_read1598=== RUN TestService_RequireScope_OIDC/writer_implies_read1599=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1600=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1601=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1602=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1603=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1604=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1605=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1606=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1607=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1608=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1609=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1610=== CONT TestCreatePendingClosureRejectsOversizedNAR16112026/10/06 08:16:29 INFO Received uploads request method=POST path=/api/pending_closures1612--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1613=== CONT TestNARDeduplicationMetadataUploadBug1614=== NAME TestClientCADerivations1615 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket73?endpoint=http://localhost:64453®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-18015-426991606/TestClientCADerivations2991535925/001/store'1616 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11617--- PASS: TestClientCADerivations (3.26s)1618=== CONT TestCacheConfigHandlerMaxNarSize1619--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1620=== CONT TestGCEndsOnShutdown/before_the_run16212026/10/06 08:16:30 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01622=== NAME TestClientIntegration1623 client_integration_test.go:323: Objects in database after GC:1624 client_integration_test.go:323: Successfully deleted all objects with GC --force16252026/10/06 08:16:30 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16262026/10/06 08:16:30 WARN mTLS auth: bound subjects configured but subject DN unavailable16272026/10/06 08:16:30 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1628--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.05s)1629=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1630--- PASS: TestClientIntegration (5.21s)1631=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1632--- PASS: TestService_ReadAuthMiddleware (2.48s)1633=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1634--- PASS: TestMetricsInventory (2.74s)1635=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1636--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (3.06s)1637=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16382026/10/06 08:16:32 INFO Received complete multipart upload request method=POST path=/1639=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16402026/10/06 08:16:32 INFO Received uploads request method=POST path=/16412026/10/06 08:16:32 WARN mTLS auth: subject not in bound subjects subject="CN=reader"16422026/10/06 08:16:32 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1643--- PASS: TestService_NativeMTLS (3.24s)1644=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16452026/10/06 08:16:32 INFO Received request for more parts method=POST path=/1646=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16472026/10/06 08:16:32 INFO Received uploads request method=POST path=/1648=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16492026/10/06 08:16:32 INFO Received complete multipart upload request method=POST path=/1650=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16512026/10/06 08:16:32 INFO Received request for more parts method=POST path=/1652=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16532026/10/06 08:16:32 INFO Received uploads request method=POST path=/1654--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1655 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1656 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1657 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1658 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1659=== CONT TestIsValidUploadKey/narinfo1660=== CONT TestIsValidUploadKey/realisation_plus_in_output1661=== CONT TestIsValidUploadKey/unknown_type1662=== CONT TestIsValidUploadKey/empty_key1663=== CONT TestIsValidUploadKey/absolute1664=== CONT TestIsValidUploadKey/traversal_nar1665=== CONT TestIsValidUploadKey/traversal1666=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1667=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1668=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1669=== CONT TestIsValidUploadKey/index.html1670=== CONT TestIsValidUploadKey/nix-cache-info1671=== CONT TestIsValidUploadKey/build_log_home-manager_file1672=== CONT TestIsValidUploadKey/realisation1673=== CONT TestIsValidUploadKey/build_log_equals1674=== CONT TestIsValidUploadKey/build_log_question_mark1675=== CONT TestIsValidUploadKey/build_log_plus_in_name1676=== CONT TestIsValidUploadKey/nar_plain1677=== CONT TestIsValidUploadKey/build_log1678=== CONT TestIsValidUploadKey/listing1679=== CONT TestIsValidUploadKey/nar_xz1680=== CONT TestIsValidUploadKey/nar_zst1681--- PASS: TestIsValidUploadKey (0.00s)1682 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1683 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1684 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1685 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1686 --- PASS: TestIsValidUploadKey/absolute (0.00s)1687 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1688 --- PASS: TestIsValidUploadKey/traversal (0.00s)1689 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1690 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1691 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1692 --- PASS: TestIsValidUploadKey/index.html (0.00s)1693 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1694 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1695 --- PASS: TestIsValidUploadKey/realisation (0.00s)1696 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1697 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1698 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1699 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1700 --- PASS: TestIsValidUploadKey/build_log (0.00s)1701 --- PASS: TestIsValidUploadKey/listing (0.00s)1702 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1703 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1704=== CONT TestPendingClosureWriteTimeout/empty1705=== CONT TestPendingClosureWriteTimeout/670k_objects1706=== CONT TestPendingClosureWriteTimeout/400_objects1707=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1708=== NAME TestOrphanedObjectsGCStressTest1709 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1710=== CONT TestProxyWriteTimeout/narinfo1711--- PASS: TestUploadHandlersRejectOversizedBody (0.02s)1712 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1713 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.03s)1714 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.63s)1715=== CONT TestProxyWriteTimeout/10_GiB_nar1716=== CONT TestProxyWriteTimeout/unknown_size1717=== CONT TestProxyWriteTimeout/1_GiB_nar1718=== CONT TestPush_RejectsBadRequests/no_roots17192026/10/06 08:16:32 INFO Received push request method=POST path=/api/pushes1720=== CONT TestPush_RejectsBadRequests/bad_root17212026/10/06 08:16:32 INFO Received push request method=POST path=/api/pushes1722=== CONT TestPush_RejectsBadRequests/root_not_in_objects1723--- PASS: TestProxyWriteTimeout (0.00s)1724 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1725 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1726 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1727 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)17282026/10/06 08:16:32 INFO Received push request method=POST path=/api/pushes1729=== CONT TestPush_RejectsBadRequests/no_objects17302026/10/06 08:16:32 INFO Received push request method=POST path=/api/pushes1731--- PASS: TestPush_RejectsBadRequests (3.00s)1732 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1733 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1734 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1735 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1736=== CONT TestResolveDBConnectionString/flag_wins1737=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1738=== CONT TestResolveDBConnectionString/nothing_configured1739=== CONT TestResolveDBConnectionString/missing_file_is_an_error1740=== CONT TestResolveDBConnectionString/file_when_flag_empty1741=== CONT TestIsValidCachePath/narinfo1742=== CONT TestIsValidCachePath/index.html1743=== CONT TestIsValidCachePath/short_hash1744=== CONT TestIsValidCachePath/wrong_extension1745=== CONT TestIsValidCachePath/leading_slash1746=== CONT TestIsValidCachePath/empty1747=== CONT TestIsValidCachePath/random_path1748=== CONT TestIsValidCachePath/invalid_char_u1749=== CONT TestIsValidCachePath/invalid_char_e1750=== CONT TestIsValidCachePath/traversal_in_middle1751=== CONT TestIsValidCachePath/traversal_parent1752=== CONT TestIsValidCachePath/nar_uncompressed1753=== CONT TestIsValidCachePath/nix-cache-info1754=== CONT TestIsValidCachePath/realisation1755=== CONT TestIsValidCachePath/log1756=== CONT TestIsValidCachePath/ls1757=== CONT TestIsValidCachePath/nar_xz17582026/10/06 08:16:32 INFO Aborted multipart uploads count=1 kept=01759=== CONT TestIsValidCachePath/nar_bz21760=== CONT TestIsValidCachePath/nar_zst1761=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1762--- PASS: TestIsValidCachePath (0.00s)1763 --- PASS: TestIsValidCachePath/narinfo (0.00s)1764 --- PASS: TestIsValidCachePath/index.html (0.00s)1765 --- PASS: TestIsValidCachePath/short_hash (0.00s)1766 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1767 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1768 --- PASS: TestIsValidCachePath/empty (0.00s)1769 --- PASS: TestIsValidCachePath/random_path (0.00s)1770 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1771 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1772 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1773 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1774 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1775 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1776 --- PASS: TestIsValidCachePath/realisation (0.00s)1777 --- PASS: TestIsValidCachePath/log (0.00s)1778 --- PASS: TestIsValidCachePath/ls (0.00s)1779 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1780 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1781 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1782 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1783=== CONT TestParseSingleRange/none1784=== CONT TestParseSingleRange/open-ended1785=== CONT TestParseSingleRange/start_far_past_EOF1786=== CONT TestParseSingleRange/start_past_EOF1787=== CONT TestParseSingleRange/single_byte1788=== CONT TestParseSingleRange/suffix_exceeds_size1789=== CONT TestParseSingleRange/suffix1790=== CONT TestParseSingleRange/end_clamped_to_size1791=== CONT TestParseSingleRange/malformed_both_empty1792=== CONT TestParseSingleRange/closed1793=== CONT TestParseSingleRange/malformed_end_before_start1794=== CONT TestParseSingleRange/multi-range_ignored1795=== CONT TestParseSingleRange/malformed_no_dash1796=== CONT TestParseSingleRange/unknown_unit1797--- PASS: TestParseSingleRange (0.00s)1798 --- PASS: TestParseSingleRange/none (0.00s)1799 --- PASS: TestParseSingleRange/open-ended (0.00s)1800 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1801 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1802 --- PASS: TestParseSingleRange/single_byte (0.00s)1803 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1804 --- PASS: TestParseSingleRange/suffix (0.00s)1805 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1806 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1807 --- PASS: TestParseSingleRange/closed (0.00s)1808 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1809 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1810 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1811 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1812=== CONT TestCacheConfigHandler/full_config,_no_issuer1813=== CONT TestCacheConfigHandler/no_signing_keys1814=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1815=== CONT TestCacheConfigHandler/no_cache_url_configured1816--- PASS: TestCacheConfigHandler (0.00s)1817 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1818 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1819 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1820 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1821=== CONT TestClientErrorHandling/InvalidStorePath1822--- PASS: TestResolveDBConnectionString (0.01s)1823 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1824 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1825 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1826 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1827 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)18282026/10/06 08:16:32 INFO Received cleanup request method=DELETE path=/api/pending_closures1829=== NAME TestOrphanedObjectsGCStressTest1830 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion18312026/10/06 08:16:32 INFO Aborted multipart uploads count=1 kept=01832--- PASS: TestPendingCleanupUsesOneCutoff (7.95s)1833=== CONT TestClientErrorHandling/ServerNotAvailable1834=== NAME TestNARDeduplicationMetadataUploadBug1835 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-18015-426991606/TestNARDeduplicationMetadataUploadBug2696204073/001/store/i0r5rxjslvlpgc93b9ai3yddw5d0jlx5-file1.txt18362026/10/06 08:16:33 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/present18372026/10/06 08:16:33 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=184.621214ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18382026/10/06 08:16:33 INFO Received push request method=POST path=/api/pushes1839=== CONT TestClientErrorHandling/InvalidAuthToken18402026/10/06 08:16:33 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18412026/10/06 08:16:33 INFO Uploading i0r5rxjslvlpgc93b9ai3yddw5d0jlx5-file1.txt (160B)18422026/10/06 08:16:33 WARN Failed to register uploaded object key=i0r5rxjslvlpgc93b9ai3yddw5d0jlx5.ls error="server returned 404: 404 page not found\n"18432026/10/06 08:16:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18442026/10/06 08:16:33 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"18452026/10/06 08:16:33 INFO Signed narinfos id=1 count=118462026/10/06 08:16:33 INFO Uploading 1 narinfos18472026/10/06 08:16:33 INFO Received complete push request method=POST path=/api/pushes/1/complete18482026/10/06 08:16:33 WARN Failed to register uploaded object key=i0r5rxjslvlpgc93b9ai3yddw5d0jlx5.narinfo error="server returned 404: 404 page not found\n"18492026/10/06 08:16:33 INFO Upload complete. (254ms)1850=== NAME TestNARDeduplicationMetadataUploadBug1851 metadata_upload_test.go:54: Retrieved narinfo from S3:1852 StorePath: /nix/var/nix/builds/nix-18015-426991606/TestNARDeduplicationMetadataUploadBug2696204073/001/store/i0r5rxjslvlpgc93b9ai3yddw5d0jlx5-file1.txt1853 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1854 Compression: zstd1855 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1856 NarSize: 1601857 References: 1858 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1859 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1860 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1861 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}18622026/10/06 08:16:33 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=421.621794ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1863 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-18015-426991606/TestNARDeduplicationMetadataUploadBug2696204073/001/store/8aalrxv3bqkm5kl81fd0llq1i00jdqgr-file2.txt18642026/10/06 08:16:33 INFO Received push request method=POST path=/api/pushes18652026/10/06 08:16:33 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)18662026/10/06 08:16:33 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18672026/10/06 08:16:33 WARN Failed to register uploaded object key=8aalrxv3bqkm5kl81fd0llq1i00jdqgr.ls error="server returned 404: 404 page not found\n"18682026/10/06 08:16:33 INFO Signed narinfos id=2 count=118692026/10/06 08:16:33 INFO Uploading 1 narinfos18702026/10/06 08:16:33 INFO Aborted multipart uploads count=0 kept=018712026/10/06 08:16:33 WARN Force mode enabled - objects will be deleted immediately without grace period18722026/10/06 08:16:33 INFO Received complete push request method=POST path=/api/pushes/2/complete18732026/10/06 08:16:33 WARN Failed to register uploaded object key=8aalrxv3bqkm5kl81fd0llq1i00jdqgr.narinfo error="server returned 404: 404 page not found\n"18742026/10/06 08:16:33 INFO Upload complete. (184ms)1875 metadata_upload_test.go:76: Retrieved narinfo from S3:1876 StorePath: /nix/var/nix/builds/nix-18015-426991606/TestNARDeduplicationMetadataUploadBug2696204073/001/store/8aalrxv3bqkm5kl81fd0llq1i00jdqgr-file2.txt1877 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1878 Compression: zstd1879 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1880 NarSize: 1601881 References: 1882 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1883 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1884 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1885 {"version":1,"root":{"type":"regular","size":44}}18862026-10-06 08:16:33.893 UTC [41742] ERROR: canceling statement due to user request18872026-10-06 08:16:33.893 UTC [41742] STATEMENT: -- name: MarkStaleObjects :execrows1888 WITH RECURSIVE ct AS (1889 SELECT timezone('UTC', now()) AS now1890 ),1891 closure_reach AS (1892 -- Start with all closure keys1893 SELECT o.key, o.refs1894 FROM objects o1895 INNER JOIN closures c ON o.key = c.key1896 UNION1897 -- Recursively add all referenced objects1898 SELECT o.key, o.refs1899 FROM objects o1900 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1901 ),1902 reachable_objects AS (1903 SELECT DISTINCT key FROM closure_reach1904 ),1905 stale_objects AS (1906 SELECT o.key1907 FROM objects AS o, ct1908 WHERE1909 NOT EXISTS (1910 SELECT 11911 FROM reachable_objects ro1912 WHERE ro.key = o.key1913 )1914 AND NOT EXISTS (1915 SELECT 11916 FROM pending_objects AS po1917 WHERE po.key = o.key1918 )1919 AND o.deleted_at IS NULL -- Only mark fresh objects1920 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure1921 FOR UPDATE1922 )1923 UPDATE objects1924 SET1925 deleted_at = ct.now,1926 first_deleted_at = COALESCE(first_deleted_at, ct.now)1927 FROM stale_objects, ct1928 WHERE objects.key = stale_objects.key1929 1930=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1931=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19322026/10/06 08:16:33 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]1933=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1934=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19352026/10/06 08:16:33 WARN Authentication failed token_preview=eyJhbGciOi..._IKhjbKKsA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1936=== CONT TestServerTLSConfig/no_client_CA1937=== CONT TestServerTLSConfig/not_a_PEM_file1938--- PASS: TestService_AuthMiddleware_OIDC (1.95s)1939 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1940 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1941 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1942 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1943=== CONT TestServerTLSConfig/missing_CA_file1944--- PASS: TestServerTLSConfig (0.00s)1945 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1946 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.03s)1947 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1948=== CONT TestService_RequireScope_OIDC/builder_may_write1949=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1950=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19512026/10/06 08:16:33 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]1952=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1953=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1954=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1955=== CONT TestService_RequireScope_OIDC/writer_implies_read1956=== CONT TestService_RequireScope_OIDC/reader_may_read1957=== CONT TestService_RequireScope_OIDC/static_token_may_write1958=== CONT TestService_RequireScope_OIDC/static_token_may_admin1959=== CONT TestService_RequireScope_OIDC/reader_may_not_write1960=== CONT TestService_RequireScope_OIDC/ops_may_not_write1961=== CONT TestService_RequireScope_OIDC/ops_may_admin1962=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1963--- PASS: TestService_RequireScope_OIDC (1.92s)1964 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1965 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1966 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1967 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1968 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1969 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1970 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1971 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1972 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1973 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1974 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1975 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1976 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1977 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)19782026/10/06 08:16:33 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=815.835343ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1979--- PASS: TestNARDeduplicationMetadataUploadBug (4.38s)19802026/10/06 08:16:34 INFO Aborted multipart uploads count=0 kept=019812026/10/06 08:16:34 WARN Force mode enabled - objects will be deleted immediately without grace period19822026/10/06 08:16:34 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:64453/bucket86/?delete=\": context canceled"1983--- PASS: TestGCEndsOnShutdown (0.00s)1984 --- PASS: TestGCEndsOnShutdown/before_the_run (3.72s)1985 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (3.11s)1986 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (3.42s)19872026/10/06 08:16:34 INFO Received uploads request method=POST path=/api/pending_closures19882026/10/06 08:16:34 INFO Aborted multipart uploads count=0 kept=019892026/10/06 08:16:34 WARN Force mode enabled - objects will be deleted immediately without grace period19902026/10/06 08:16:34 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=019912026/10/06 08:16:34 INFO Vacuumed table table=pending_closures19922026/10/06 08:16:34 INFO Vacuumed table table=pending_objects19932026/10/06 08:16:34 INFO Vacuumed table table=multipart_uploads19942026/10/06 08:16:34 INFO Vacuumed table table=closures19952026/10/06 08:16:34 INFO Vacuumed table table=objects19962026/10/06 08:16:34 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.735417935s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19972026/10/06 08:16:34 INFO Received uploads request method=POST path=/api/pending_closures19982026/10/06 08:16:34 INFO Aborted multipart uploads count=0 kept=019992026/10/06 08:16:34 WARN Force mode enabled - objects will be deleted immediately without grace period20002026/10/06 08:16:34 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=020012026/10/06 08:16:34 INFO Vacuumed table table=pending_closures20022026/10/06 08:16:35 INFO Vacuumed table table=pending_objects20032026/10/06 08:16:35 INFO Vacuumed table table=multipart_uploads20042026/10/06 08:16:35 INFO Vacuumed table table=closures20052026/10/06 08:16:35 INFO Vacuumed table table=objects2006--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2007 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (3.37s)2008 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (3.18s)20092026/10/06 08:16:35 INFO Received uploads request method=POST path=/api/pending_closures2010=== NAME TestOrphanedObjectsGCStressTest2011 orphaned_objects_gc_test.go:509: Stress test completed successfully:2012 orphaned_objects_gc_test.go:510: - Active objects preserved: 202013 orphaned_objects_gc_test.go:511: - Objects deleted: 2102014 orphaned_objects_gc_test.go:512: - Total GC'd: 2102015--- PASS: TestOrphanedObjectsGCStressTest (12.00s)20162026/10/06 08:16:36 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20172026/10/06 08:16:36 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2018--- PASS: TestPendingClosureWriteTimeout (0.00s)2019 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2020 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2021 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2022 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (3.81s)20232026/10/06 08:16: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-config20242026/10/06 08:16:36 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=180.138549ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20252026/10/06 08:16:36 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=438.517054ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20262026/10/06 08:16:37 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=747.51301ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20272026/10/06 08:16:38 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.604123772s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20282026/10/06 08:16:39 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"20292026/10/06 08:16:39 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-config20302026/10/06 08:16:39 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=199.725598ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20312026/10/06 08:16:40 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=436.207474ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20322026/10/06 08:16:40 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=824.194104ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20332026/10/06 08:16:41 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.627576565s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20342026/10/06 08:16:42 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_closures20352026/10/06 08:16:43 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=192.016903ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20362026/10/06 08:16:43 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=423.800273ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20372026/10/06 08:16:43 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=766.378312ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20382026/10/06 08:16:44 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.643207051s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2039--- PASS: TestClientErrorHandling (0.00s)2040 --- PASS: TestClientErrorHandling/InvalidStorePath (2.56s)2041 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.86s)2042 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.21s)2043PASS2044{"timestamp":"2026-10-06T08:16:46.052789Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:64540","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(11)"}20452026-10-06 08:16:46.515 UTC [28954] LOG: received smart shutdown request20462026-10-06 08:16:46.517 UTC [28954] LOG: background worker "logical replication launcher" (PID 28974) exited with exit code 120472026-10-06 08:16:46.521 UTC [28967] LOG: shutting down20482026-10-06 08:16:46.521 UTC [28967] LOG: checkpoint starting: shutdown immediate20492026-10-06 08:16:51.780 UTC [28967] LOG: checkpoint complete: wrote 12592 buffers (76.9%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 27 recycled; write=1.249 s, sync=3.983 s, total=5.260 s; sync files=30999, longest=0.116 s, average=0.001 s; distance=435777 kB, estimate=435777 kB; lsn=0/1C11D470, redo lsn=0/1C11D47020502026-10-06 08:16:51.791 UTC [28954] LOG: database system is shut down2051Running OIDC tests...2052=== RUN TestAudienceForIssuer2053=== PAUSE TestAudienceForIssuer2054=== RUN TestGlobMatch2055=== PAUSE TestGlobMatch2056=== RUN TestValidateToken_ValidToken2057=== PAUSE TestValidateToken_ValidToken2058=== RUN TestValidateToken_WrongAudience2059=== PAUSE TestValidateToken_WrongAudience2060=== RUN TestValidateToken_Expired2061=== PAUSE TestValidateToken_Expired2062=== RUN TestValidateToken_BoundClaimsMismatch2063=== PAUSE TestValidateToken_BoundClaimsMismatch2064=== RUN TestValidateToken_BoundSubjectMismatch2065=== PAUSE TestValidateToken_BoundSubjectMismatch2066=== RUN TestValidateToken_MultipleProviders2067=== PAUSE TestValidateToken_MultipleProviders2068=== RUN TestValidateToken_NoMatchingProvider2069=== PAUSE TestValidateToken_NoMatchingProvider2070=== RUN TestValidateToken_KubernetesServiceAccount2071=== PAUSE TestValidateToken_KubernetesServiceAccount2072=== RUN TestNewValidator_KubernetesRequiresCA2073=== PAUSE TestNewValidator_KubernetesRequiresCA2074=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2075=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2076=== RUN TestPins_ReservedForMatchingRule2077=== PAUSE TestPins_ReservedForMatchingRule2078=== RUN TestPins_TopLevelShorthand2079=== PAUSE TestPins_TopLevelShorthand2080=== RUN TestPins_ConfigValidation2081=== PAUSE TestPins_ConfigValidation2082=== RUN TestScopes_LegacyProviderDefaultsToWrite2083=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2084=== RUN TestScopes_Rules2085=== PAUSE TestScopes_Rules2086=== RUN TestScopes_ConfigValidation2087=== PAUSE TestScopes_ConfigValidation2088=== CONT TestAudienceForIssuer2089--- PASS: TestAudienceForIssuer (0.00s)2090=== CONT TestScopes_ConfigValidation2091=== CONT TestValidateToken_KubernetesServiceAccount2092=== CONT TestValidateToken_BoundClaimsMismatch2093=== CONT TestValidateToken_WrongAudience2094=== CONT TestValidateToken_Expired2095=== CONT TestPins_TopLevelShorthand2096--- PASS: TestScopes_ConfigValidation (0.00s)2097=== CONT TestValidateToken_ValidToken2098=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2099=== CONT TestScopes_Rules2100=== CONT TestValidateToken_MultipleProviders2101=== CONT TestValidateToken_NoMatchingProvider21022026/10/06 08:16:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64966/oidc2103--- PASS: TestValidateToken_BoundClaimsMismatch (0.02s)2104=== CONT TestValidateToken_BoundSubjectMismatch21052026/10/06 08:16:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64968/oidc2106--- PASS: TestValidateToken_Expired (0.06s)2107=== CONT TestNewValidator_KubernetesRequiresCA21082026/10/06 08:16:56 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:6497021092026/10/06 08:16:56 http: TLS handshake error from 127.0.0.1:64973: read tcp 127.0.0.1:64972->127.0.0.1:64973: use of closed network connection2110--- PASS: TestNewValidator_KubernetesRequiresCA (0.10s)2111=== CONT TestGlobMatch2112=== RUN TestGlobMatch/foo_foo2113=== PAUSE TestGlobMatch/foo_foo2114=== RUN TestGlobMatch/foo_bar2115=== PAUSE TestGlobMatch/foo_bar2116=== RUN TestGlobMatch/*_2117=== PAUSE TestGlobMatch/*_2118=== RUN TestGlobMatch/*_anything2119=== PAUSE TestGlobMatch/*_anything2120=== RUN TestGlobMatch/foo*_foo2121=== PAUSE TestGlobMatch/foo*_foo2122=== RUN TestGlobMatch/foo*_foobar2123=== PAUSE TestGlobMatch/foo*_foobar2124=== RUN TestGlobMatch/foo*_bar2125=== PAUSE TestGlobMatch/foo*_bar2126=== RUN TestGlobMatch/*bar_bar2127=== PAUSE TestGlobMatch/*bar_bar2128=== RUN TestGlobMatch/*bar_foobar2129=== PAUSE TestGlobMatch/*bar_foobar2130=== RUN TestGlobMatch/*bar_foo2131=== PAUSE TestGlobMatch/*bar_foo2132=== RUN TestGlobMatch/foo*bar_foobar2133=== PAUSE TestGlobMatch/foo*bar_foobar2134=== RUN TestGlobMatch/foo*bar_foo123bar2135=== PAUSE TestGlobMatch/foo*bar_foo123bar2136=== RUN TestGlobMatch/foo*bar_foobarbaz2137=== PAUSE TestGlobMatch/foo*bar_foobarbaz2138=== RUN TestGlobMatch/*/*_foo/bar2139=== PAUSE TestGlobMatch/*/*_foo/bar2140=== RUN TestGlobMatch/*/*_foo2141=== PAUSE TestGlobMatch/*/*_foo2142=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2143=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2144=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02145=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02146=== RUN TestGlobMatch/refs/*/main_refs/heads/main2147=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2148=== RUN TestGlobMatch/fo?_foo2149=== PAUSE TestGlobMatch/fo?_foo2150=== RUN TestGlobMatch/fo?_fo2151=== PAUSE TestGlobMatch/fo?_fo2152=== RUN TestGlobMatch/fo?_fooo2153=== PAUSE TestGlobMatch/fo?_fooo2154=== RUN TestGlobMatch/?oo_foo2155=== PAUSE TestGlobMatch/?oo_foo2156=== RUN TestGlobMatch/?oo_boo2157=== PAUSE TestGlobMatch/?oo_boo2158=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2159=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2160=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2161=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2162=== CONT TestScopes_LegacyProviderDefaultsToWrite2163--- PASS: TestValidateToken_KubernetesServiceAccount (0.17s)2164=== CONT TestPins_ConfigValidation2165--- PASS: TestPins_ConfigValidation (0.00s)2166=== CONT TestPins_ReservedForMatchingRule21672026/10/06 08:16:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64975/oidc2168--- PASS: TestValidateToken_WrongAudience (0.22s)2169=== CONT TestGlobMatch/foo_foo2170=== CONT TestGlobMatch/foo*bar_foobarbaz2171=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2172=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2173=== CONT TestGlobMatch/?oo_boo2174=== CONT TestGlobMatch/?oo_foo2175=== CONT TestGlobMatch/fo?_fooo2176=== CONT TestGlobMatch/fo?_fo2177=== CONT TestGlobMatch/fo?_foo2178=== CONT TestGlobMatch/refs/*/main_refs/heads/main2179=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02180=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2181=== CONT TestGlobMatch/*/*_foo2182=== CONT TestGlobMatch/*/*_foo/bar2183=== CONT TestGlobMatch/foo*_bar2184=== CONT TestGlobMatch/foo*bar_foo123bar2185=== CONT TestGlobMatch/foo*bar_foobar2186=== CONT TestGlobMatch/*bar_foo2187=== CONT TestGlobMatch/*bar_foobar2188=== CONT TestGlobMatch/*bar_bar2189=== CONT TestGlobMatch/*_anything2190=== CONT TestGlobMatch/foo*_foobar2191=== CONT TestGlobMatch/foo*_foo2192=== CONT TestGlobMatch/foo_bar2193=== CONT TestGlobMatch/*_2194--- PASS: TestGlobMatch (0.00s)2195 --- PASS: TestGlobMatch/foo_foo (0.00s)2196 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2197 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2198 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2199 --- PASS: TestGlobMatch/?oo_boo (0.00s)2200 --- PASS: TestGlobMatch/?oo_foo (0.00s)2201 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2202 --- PASS: TestGlobMatch/fo?_fo (0.00s)2203 --- PASS: TestGlobMatch/fo?_foo (0.00s)2204 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2205 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2206 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2207 --- PASS: TestGlobMatch/*/*_foo (0.00s)2208 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2209 --- PASS: TestGlobMatch/foo*_bar (0.00s)2210 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2211 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2212 --- PASS: TestGlobMatch/*bar_foo (0.00s)2213 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2214 --- PASS: TestGlobMatch/*bar_bar (0.00s)2215 --- PASS: TestGlobMatch/*_anything (0.00s)2216 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2217 --- PASS: TestGlobMatch/foo*_foo (0.00s)2218 --- PASS: TestGlobMatch/foo_bar (0.00s)2219 --- PASS: TestGlobMatch/*_ (0.00s)22202026/10/06 08:16:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64977/oidc2221--- PASS: TestScopes_Rules (0.23s)22222026/10/06 08:16:56 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:64974/oidc2223--- PASS: TestValidateToken_NoMatchingProvider (0.25s)22242026/10/06 08:16:56 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232225--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.30s)22262026/10/06 08:16:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64983/oidc2227--- PASS: TestValidateToken_ValidToken (0.38s)22282026/10/06 08:16:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64985/oidc2229--- PASS: TestPins_ReservedForMatchingRule (0.34s)22302026/10/06 08:16:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64988/oidc2231--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.39s)22322026/10/06 08:16:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64991/oidc2233--- PASS: TestValidateToken_BoundSubjectMismatch (0.55s)22342026/10/06 08:16:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64993/oidc2235--- PASS: TestPins_TopLevelShorthand (0.59s)22362026/10/06 08:16:57 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:64990/oidc22372026/10/06 08:16:57 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:64995/oidc2238--- PASS: TestValidateToken_MultipleProviders (0.61s)2239PASS2240Running hook tests...2241=== RUN TestSendPathsEmpty2242=== PAUSE TestSendPathsEmpty2243=== RUN TestQueueEnqueueAndFetch2244=== PAUSE TestQueueEnqueueAndFetch2245=== RUN TestQueueDeduplication2246=== PAUSE TestQueueDeduplication2247=== RUN TestQueueRemove2248=== PAUSE TestQueueRemove2249=== RUN TestQueueFetchBatchLimit2250=== PAUSE TestQueueFetchBatchLimit2251=== RUN TestQueueRetryMovesToBack2252=== PAUSE TestQueueRetryMovesToBack2253=== RUN TestQueueFetchRemoveLifecycle2254=== PAUSE TestQueueFetchRemoveLifecycle2255=== RUN TestQueueConcurrentWriters2256=== PAUSE TestQueueConcurrentWriters2257=== RUN TestQueueRemoveLargeClosure2258=== PAUSE TestQueueRemoveLargeClosure2259=== RUN TestServerClientIntegration2260=== PAUSE TestServerClientIntegration2261=== RUN TestServerQueueError2262=== PAUSE TestServerQueueError2263=== RUN TestGetListenerSocketActivation2264 server_test.go:210: === RUN TestGetListenerSocketActivation2265 --- PASS: TestGetListenerSocketActivation (0.00s)2266 PASS2267 2268--- PASS: TestGetListenerSocketActivation (0.01s)2269=== RUN TestDrainIsolatesPoisonPath2270=== PAUSE TestDrainIsolatesPoisonPath2271=== RUN TestRunNotBlockedByPoisonHead2272=== PAUSE TestRunNotBlockedByPoisonHead2273=== RUN TestDrainGivesUpWhenServerDown2274=== PAUSE TestDrainGivesUpWhenServerDown2275=== RUN TestFailedPathPrunedByLaterClosure2276=== PAUSE TestFailedPathPrunedByLaterClosure2277=== RUN TestWorkerUploadsAndRemoves2278=== PAUSE TestWorkerUploadsAndRemoves2279=== RUN TestWorkerSkipsGCdPaths2280=== PAUSE TestWorkerSkipsGCdPaths2281=== RUN TestWorkerPrunesClosureDeps2282=== PAUSE TestWorkerPrunesClosureDeps2283=== RUN TestDrainTimeout2284=== PAUSE TestDrainTimeout2285=== CONT TestFailedPathPrunedByLaterClosure2286=== CONT TestQueueConcurrentWriters2287=== CONT TestQueueRemove2288=== CONT TestSendPathsEmpty2289--- PASS: TestSendPathsEmpty (0.00s)2290=== CONT TestDrainGivesUpWhenServerDown2291=== CONT TestQueueDeduplication2292=== CONT TestRunNotBlockedByPoisonHead2293=== CONT TestDrainIsolatesPoisonPath2294=== CONT TestServerQueueError2295=== CONT TestServerClientIntegration2296=== CONT TestQueueRemoveLargeClosure22972026/10/06 08:16:57 ERROR Failed to queue paths error="permission denied" count=12298--- PASS: TestServerClientIntegration (0.00s)2299=== CONT TestQueueEnqueueAndFetch2300--- PASS: TestServerQueueError (0.00s)2301=== CONT TestQueueFetchRemoveLifecycle2302--- PASS: TestQueueFetchRemoveLifecycle (0.00s)2303=== CONT TestWorkerPrunesClosureDeps23042026/10/06 08:16:57 INFO Uploading batch count=223052026/10/06 08:16:57 ERROR Upload failed error="upload failed" count=223062026/10/06 08:16:57 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-18015-426991606/TestDrainGivesUpWhenServerDown1969073144/002/a2307--- PASS: TestQueueRemove (0.01s)2308=== CONT TestDrainTimeout23092026/10/06 08:16:57 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-18015-426991606/TestDrainGivesUpWhenServerDown1969073144/002/b23102026/10/06 08:16:57 INFO Uploading batch count=223112026/10/06 08:16:57 ERROR Upload failed error="upload failed" count=223122026/10/06 08:16:57 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-18015-426991606/TestDrainGivesUpWhenServerDown1969073144/002/c23132026/10/06 08:16:57 INFO Upload queue status pending=323142026/10/06 08:16:57 INFO Uploading batch count=123152026/10/06 08:16:57 ERROR Upload failed error="upload failed" count=123162026/10/06 08:16:57 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-18015-426991606/TestDrainGivesUpWhenServerDown1969073144/002/d23172026/10/06 08:16:57 INFO Uploading batch count=123182026/10/06 08:16:57 ERROR Upload failed error="upload failed" count=12319--- PASS: TestQueueEnqueueAndFetch (0.01s)2320=== CONT TestQueueRetryMovesToBack23212026/10/06 08:16:57 INFO Uploading batch count=423222026/10/06 08:16:57 ERROR Upload failed error="upload failed" count=423232026/10/06 08:16:57 INFO Uploading batch count=223242026/10/06 08:16:57 ERROR Upload failed error="upload failed" count=223252026/10/06 08:16:57 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-18015-426991606/TestDrainGivesUpWhenServerDown1969073144/002/e2326--- PASS: TestQueueDeduplication (0.01s)2327=== CONT TestWorkerUploadsAndRemoves23282026/10/06 08:16:57 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-18015-426991606/TestDrainGivesUpWhenServerDown1969073144/002/f23292026/10/06 08:16:57 INFO Uploading batch count=123302026/10/06 08:16:57 INFO Upload queue status pending=223312026/10/06 08:16:57 INFO Uploading batch count=123322026/10/06 08:16:57 INFO Uploading batch count=123332026/10/06 08:16:57 ERROR Drain finished with paths left in queue remaining=1023342026/10/06 08:16:57 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-18015-426991606/TestDrainIsolatesPoisonPath1614878569/002/bbb2335--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)2336=== CONT TestWorkerSkipsGCdPaths23372026/10/06 08:16:57 INFO Uploading batch count=123382026/10/06 08:16:57 ERROR Upload failed error="upload failed" count=123392026/10/06 08:16:57 INFO Uploading batch count=123402026/10/06 08:16:57 ERROR Upload failed error="upload failed" count=123412026/10/06 08:16:57 INFO Uploading batch count=123422026/10/06 08:16:57 ERROR Upload failed error="upload failed" count=123432026/10/06 08:16:57 ERROR Drain finished with paths left in queue remaining=123442026/10/06 08:16:57 INFO Uploading batch count=22345--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2346=== CONT TestQueueFetchBatchLimit2347--- PASS: TestQueueRetryMovesToBack (0.01s)23482026/10/06 08:16:57 INFO Upload queue status pending=223492026/10/06 08:16:57 INFO Uploading batch count=22350--- PASS: TestDrainIsolatesPoisonPath (0.02s)23512026/10/06 08:16:57 INFO Upload queue status pending=223522026/10/06 08:16:57 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-18015-426991606/TestWorkerSkipsGCdPaths585795266/002/nonexistent23532026/10/06 08:16:57 INFO Uploading batch count=12354--- PASS: TestQueueFetchBatchLimit (0.00s)2355--- PASS: TestWorkerPrunesClosureDeps (0.02s)2356--- PASS: TestWorkerUploadsAndRemoves (0.03s)2357--- PASS: TestWorkerSkipsGCdPaths (0.02s)2358--- PASS: TestQueueRemoveLargeClosure (0.07s)2359--- PASS: TestQueueConcurrentWriters (0.15s)23602026/10/06 08:16:57 ERROR Upload failed error="context deadline exceeded" count=223612026/10/06 08:16:57 ERROR Drain finished with paths left in queue remaining=42362--- PASS: TestDrainTimeout (0.21s)23632026/10/06 08:16:58 INFO Uploading batch count=123642026/10/06 08:16:58 INFO Uploading batch count=123652026/10/06 08:16:58 INFO Uploading batch count=123662026/10/06 08:16:58 ERROR Upload failed error="upload failed" count=123672026/10/06 08:16:58 INFO Uploading batch count=123682026/10/06 08:16:58 ERROR Upload failed error="upload failed" count=123692026/10/06 08:16:58 INFO Uploading batch count=123702026/10/06 08:16:58 ERROR Upload failed error="upload failed" count=123712026/10/06 08:16:58 INFO Uploading batch count=123722026/10/06 08:16:58 ERROR Upload failed error="upload failed" count=123732026/10/06 08:16:58 ERROR Drain finished with paths left in queue remaining=12374--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2375PASS2376Running signing tests...2377=== RUN TestExternalSigner2378=== PAUSE TestExternalSigner2379=== RUN TestExternalSignerWrongPublicKey2380=== PAUSE TestExternalSignerWrongPublicKey2381=== RUN TestExternalSignerErrors2382=== PAUSE TestExternalSignerErrors2383=== RUN TestExternalSignerRestartsAfterCrash2384=== PAUSE TestExternalSignerRestartsAfterCrash2385=== RUN TestExternalSignerProgramErrorKeepsProcess2386=== PAUSE TestExternalSignerProgramErrorKeepsProcess2387=== RUN TestExternalSignerClose2388=== PAUSE TestExternalSignerClose2389=== RUN TestExternalSignerRejectsInvalidPublicKey2390=== PAUSE TestExternalSignerRejectsInvalidPublicKey2391=== RUN TestExternalSignerCancellation2392=== PAUSE TestExternalSignerCancellation2393=== RUN TestGenerateFingerprint2394=== PAUSE TestGenerateFingerprint2395=== RUN TestParseSigningKey2396=== PAUSE TestParseSigningKey2397=== RUN TestSign2398=== PAUSE TestSign2399=== RUN TestSignBatch2400=== PAUSE TestSignBatch2401=== RUN TestNilKeyPublicKey2402=== PAUSE TestNilKeyPublicKey2403=== RUN TestSignErrors2404=== PAUSE TestSignErrors2405=== CONT TestExternalSigner2406=== CONT TestExternalSignerCancellation2407=== CONT TestSignBatch2408=== CONT TestSignErrors2409=== CONT TestNilKeyPublicKey2410--- PASS: TestNilKeyPublicKey (0.00s)2411=== CONT TestGenerateFingerprint2412=== RUN TestGenerateFingerprint/basic_with_references2413=== PAUSE TestGenerateFingerprint/basic_with_references2414=== CONT TestParseSigningKey2415=== RUN TestParseSigningKey/valid_32-byte_key2416=== PAUSE TestParseSigningKey/valid_32-byte_key2417=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2418=== RUN TestGenerateFingerprint/no_references2419=== PAUSE TestGenerateFingerprint/no_references2420=== CONT TestSign2421=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2422=== CONT TestExternalSignerRejectsInvalidPublicKey2423=== RUN TestExternalSignerRejectsInvalidPublicKey/#002424=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002425=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2426=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2427=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2428=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2429=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2430=== CONT TestExternalSignerClose2431=== RUN TestParseSigningKey/no_colon2432=== PAUSE TestParseSigningKey/no_colon2433=== RUN TestParseSigningKey/empty_name2434=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2435=== PAUSE TestParseSigningKey/empty_name2436=== RUN TestParseSigningKey/invalid_base642437=== PAUSE TestParseSigningKey/invalid_base642438=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2439=== RUN TestParseSigningKey/wrong_length2440=== PAUSE TestParseSigningKey/wrong_length2441=== CONT TestExternalSignerProgramErrorKeepsProcess2442=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2443=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2444=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2445=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2446=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2447=== CONT TestExternalSignerErrors2448=== RUN TestExternalSignerErrors/invalid_JSON2449=== PAUSE TestExternalSignerErrors/invalid_JSON2450=== RUN TestExternalSignerErrors/exit_on_request2451=== PAUSE TestExternalSignerErrors/exit_on_request2452=== RUN TestExternalSignerErrors/too_few_signatures2453=== PAUSE TestExternalSignerErrors/too_few_signatures2454=== RUN TestExternalSignerErrors/missing_signature_name2455=== PAUSE TestExternalSignerErrors/missing_signature_name2456=== RUN TestExternalSignerErrors/program_error2457=== PAUSE TestExternalSignerErrors/program_error2458=== RUN TestExternalSignerErrors/wrong_shape2459=== PAUSE TestExternalSignerErrors/wrong_shape2460=== RUN TestExternalSignerErrors/wrong_id2461=== PAUSE TestExternalSignerErrors/wrong_id2462=== RUN TestExternalSignerErrors/missing_signatures2463=== PAUSE TestExternalSignerErrors/missing_signatures2464=== RUN TestExternalSignerErrors/null_signatures2465=== PAUSE TestExternalSignerErrors/null_signatures2466=== RUN TestExternalSignerErrors/wrong_signatures_shape2467=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2468=== RUN TestExternalSignerErrors/invalid_signature_base642469=== PAUSE TestExternalSignerErrors/invalid_signature_base642470=== RUN TestExternalSignerErrors/exit_at_startup2471=== PAUSE TestExternalSignerErrors/exit_at_startup2472=== RUN TestExternalSignerErrors/null2473=== PAUSE TestExternalSignerErrors/null2474=== RUN TestExternalSignerErrors/unrequested_key2475=== PAUSE TestExternalSignerErrors/unrequested_key2476=== RUN TestExternalSignerErrors/wrong_signature_name2477=== PAUSE TestExternalSignerErrors/wrong_signature_name2478=== RUN TestExternalSignerErrors/wrong_signature_length2479=== PAUSE TestExternalSignerErrors/wrong_signature_length2480=== CONT TestExternalSignerRestartsAfterCrash2481=== RUN TestSignErrors/nil_key2482=== PAUSE TestSignErrors/nil_key2483=== CONT TestExternalSignerWrongPublicKey2484--- PASS: TestSignBatch (0.00s)2485=== CONT TestParseSigningKey/valid_32-byte_key2486=== CONT TestExternalSignerRejectsInvalidPublicKey/#002487=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2488=== CONT TestParseSigningKey/wrong_length2489=== CONT TestParseSigningKey/invalid_base642490=== CONT TestParseSigningKey/empty_name2491=== CONT TestParseSigningKey/no_colon2492--- PASS: TestParseSigningKey (0.00s)2493 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2494 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2495 --- PASS: TestParseSigningKey/wrong_length (0.00s)2496 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2497 --- PASS: TestParseSigningKey/empty_name (0.00s)2498 --- PASS: TestParseSigningKey/no_colon (0.00s)2499=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2500=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2501=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2502=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2503=== CONT TestExternalSignerErrors/wrong_signatures_shape2504--- PASS: TestSign (0.00s)2505=== RUN TestSignErrors/nil_narinfo2506=== PAUSE TestSignErrors/nil_narinfo2507=== RUN TestSignErrors/invalid_narinfo2508=== PAUSE TestSignErrors/invalid_narinfo2509=== RUN TestSignErrors/canceled2510=== PAUSE TestSignErrors/canceled2511=== CONT TestExternalSignerErrors/invalid_JSON2512=== CONT TestExternalSignerErrors/missing_signatures2513--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2514 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2515 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2516 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2517 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2518 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2519=== RUN TestGenerateFingerprint/invalid_nar_hash_length2520=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2521=== RUN TestGenerateFingerprint/invalid_store_path_prefix2522=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2523=== RUN TestGenerateFingerprint/invalid_reference_prefix2524=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2525=== CONT TestExternalSignerErrors/null_signatures2526--- PASS: TestExternalSigner (0.21s)2527=== CONT TestExternalSignerErrors/wrong_shape2528--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.38s)2529=== CONT TestExternalSignerErrors/wrong_id2530--- PASS: TestExternalSignerCancellation (0.59s)2531=== CONT TestExternalSignerErrors/exit_on_request2532--- PASS: TestExternalSignerClose (0.75s)2533=== CONT TestExternalSignerErrors/program_error2534--- PASS: TestExternalSignerWrongPublicKey (0.93s)2535=== CONT TestExternalSignerErrors/unrequested_key2536--- PASS: TestExternalSignerRestartsAfterCrash (1.14s)2537=== CONT TestExternalSignerErrors/wrong_signature_length2538/nix/var/nix/builds/nix-18015-426991606/TestExternalSignerRestartsAfterCrash1177866213/001/sign program: line 7: /nix/var/nix/builds/nix-18015-426991606/TestExternalSignerRestartsAfterCrash1177866213/001/sign program.starts: No such file or directory2539=== CONT TestExternalSignerErrors/wrong_signature_name2540=== CONT TestExternalSignerErrors/exit_at_startup2541=== CONT TestExternalSignerErrors/null2542=== CONT TestExternalSignerErrors/invalid_signature_base642543=== CONT TestExternalSignerErrors/too_few_signatures2544=== CONT TestExternalSignerErrors/missing_signature_name2545=== CONT TestSignErrors/nil_key2546=== CONT TestSignErrors/invalid_narinfo2547=== CONT TestSignErrors/canceled2548=== CONT TestSignErrors/nil_narinfo2549--- PASS: TestSignErrors (0.00s)2550 --- PASS: TestSignErrors/nil_key (0.00s)2551 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2552 --- PASS: TestSignErrors/canceled (0.00s)2553 --- PASS: TestSignErrors/nil_narinfo (0.00s)2554=== CONT TestGenerateFingerprint/basic_with_references2555=== CONT TestGenerateFingerprint/invalid_nar_hash_length2556=== CONT TestGenerateFingerprint/invalid_reference_prefix2557=== CONT TestGenerateFingerprint/invalid_store_path_prefix2558=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2559=== CONT TestGenerateFingerprint/no_references2560=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2561--- PASS: TestGenerateFingerprint (0.00s)2562 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2563 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2564 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2565 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2566 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2567 --- PASS: TestGenerateFingerprint/no_references (0.00s)2568 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2569--- PASS: TestExternalSignerErrors (0.00s)2570 --- PASS: TestExternalSignerErrors/missing_signatures (1.30s)2571 --- PASS: TestExternalSignerErrors/null_signatures (1.48s)2572 --- PASS: TestExternalSignerErrors/invalid_JSON (1.66s)2573 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (1.84s)2574 --- PASS: TestExternalSignerErrors/wrong_shape (1.81s)2575 --- PASS: TestExternalSignerErrors/wrong_id (2.34s)2576 --- PASS: TestExternalSignerErrors/exit_on_request (2.32s)2577 --- PASS: TestExternalSignerErrors/program_error (2.34s)2578 --- PASS: TestExternalSignerErrors/unrequested_key (2.33s)2579 --- PASS: TestExternalSignerErrors/wrong_signature_length (2.32s)2580 --- PASS: TestExternalSignerErrors/wrong_signature_name (2.35s)2581 --- PASS: TestExternalSignerErrors/exit_at_startup (2.35s)2582 --- PASS: TestExternalSignerErrors/null (2.38s)2583 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (2.37s)2584 --- PASS: TestExternalSignerErrors/too_few_signatures (2.39s)2585 --- PASS: TestExternalSignerErrors/missing_signature_name (2.08s)2586PASS2587Running OpenBao signer tests...2588=== RUN TestSign2589=== PAUSE TestSign2590=== RUN TestSignErrors2591=== PAUSE TestSignErrors2592=== RUN TestServe2593=== PAUSE TestServe2594=== RUN TestServeRejectsGarbage2595=== PAUSE TestServeRejectsGarbage2596=== CONT TestSign2597=== CONT TestServe2598=== CONT TestSignErrors2599=== RUN TestSignErrors/http_error2600=== PAUSE TestSignErrors/http_error2601=== RUN TestSignErrors/invalid_json2602=== PAUSE TestSignErrors/invalid_json2603=== RUN TestSignErrors/no_prefix2604=== PAUSE TestSignErrors/no_prefix2605=== RUN TestSignErrors/invalid_base642606=== PAUSE TestSignErrors/invalid_base642607=== CONT TestSignErrors/http_error2608=== CONT TestServeRejectsGarbage2609--- PASS: TestServeRejectsGarbage (0.00s)2610=== CONT TestSignErrors/no_prefix2611=== CONT TestSignErrors/invalid_base642612--- PASS: TestServe (0.00s)2613=== CONT TestSignErrors/invalid_json2614--- PASS: TestSign (0.00s)2615--- PASS: TestSignErrors (0.00s)2616 --- PASS: TestSignErrors/no_prefix (0.00s)2617 --- PASS: TestSignErrors/http_error (0.00s)2618 --- PASS: TestSignErrors/invalid_json (0.00s)2619 --- PASS: TestSignErrors/invalid_base64 (0.00s)2620PASS