niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #388
· 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 (0.05s)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 TestDoWithRetry_BodyReplayedViaGetBody100=== CONT TestResolveStorePath101=== CONT TestSetClientTLSErrors102=== CONT TestEncodeNixBase32103=== RUN TestEncodeNixBase32/test_string_hash104=== CONT TestUploadMultipart_PartsInParallel105=== PAUSE TestEncodeNixBase32/test_string_hash106=== RUN TestEncodeNixBase32/empty_input107=== PAUSE TestEncodeNixBase32/empty_input108=== CONT TestSetClientTLSDoesNotMutateDefaultTransport109=== CONT TestSetClientTLS110=== CONT TestClientSignaturesByStorePath111=== CONT TestStreamPushReportsSignatures112--- PASS: TestClientSignaturesByStorePath (0.00s)113=== CONT TestStreamPushGivesUpOnDeadServer114=== CONT TestStreamPushRequestLine115--- PASS: TestResolveStorePath (0.00s)116=== CONT TestStreamPushIsolatesFailures1172026/10/06 21:27:28 ERROR Upload failed error="connection refused" count=201182026/10/06 21:27:28 ERROR Server seems unavailable, giving up on batch untried=171192026/10/06 21:27:28 ERROR Upload failed error="bad path" count=3120=== CONT TestStreamPushBatchesUnderLoad121--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)1222026/10/06 21:27:28 ERROR Upload failed error=boom count=1123--- PASS: TestStreamPushReportsSignatures (0.00s)124=== CONT TestStreamPushReportsEveryPath1252026/10/06 21:27:28 ERROR Upload failed error=boom count=1126--- PASS: TestStreamPushReportsEveryPath (0.00s)127=== CONT TestShellSplitErrors128--- PASS: TestShellSplitErrors (0.00s)129=== CONT TestShellSplit130--- PASS: TestShellSplit (0.00s)131=== CONT TestRateLimiterFeedback132=== RUN TestRateLimiterFeedback/429_enables_limiter133=== PAUSE TestRateLimiterFeedback/429_enables_limiter134=== RUN TestRateLimiterFeedback/503_enables_limiter135=== PAUSE TestRateLimiterFeedback/503_enables_limiter136=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter137=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter138=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter139=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter140=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1412026/10/06 21:27:28 WARN Rate limiter enabled after throttle name=server-test rate=5142--- PASS: TestStreamPushIsolatesFailures (0.00s)143=== CONT TestDumpPathMatchesNix1442026/10/06 21:27:28 WARN Rate limiter enabled after throttle name=server-test rate=51452026/10/06 21:27:28 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:534201462026/10/06 21:27:28 WARN Rate limiter backed off name=server-test rate=51472026/10/06 21:27:28 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:53420148--- PASS: TestDoServerRequestAttachesToken (0.01s)149=== CONT TestDumpPathWriterError150--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)151=== CONT TestDumpPathSingleFile152=== RUN TestSetClientTLSErrors/missing_cert_file153=== PAUSE TestSetClientTLSErrors/missing_cert_file154=== RUN TestSetClientTLSErrors/missing_key_file155=== PAUSE TestSetClientTLSErrors/missing_key_file156=== RUN TestSetClientTLSErrors/missing_ca_file157=== PAUSE TestSetClientTLSErrors/missing_ca_file158=== RUN TestSetClientTLSErrors/invalid_ca_file159=== PAUSE TestSetClientTLSErrors/invalid_ca_file160=== CONT TestPathInfoCACompatibility161=== RUN TestPathInfoCACompatibility/null_ca_field162=== PAUSE TestPathInfoCACompatibility/null_ca_field163=== RUN TestPathInfoCACompatibility/old_string_format_-_text164=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text165=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive166=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive167=== RUN TestPathInfoCACompatibility/new_structured_format_-_text168=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text169=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method170=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method171=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun172--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)173=== CONT TestFilterOversizedClosures174=== RUN TestFilterOversizedClosures/no_limit_keeps_everything175=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything176=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped177=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped178=== RUN TestFilterOversizedClosures/all_closures_skipped179=== PAUSE TestFilterOversizedClosures/all_closures_skipped180=== CONT TestCaseHackSuffix181=== RUN TestSetClientTLS/rejects_connection_without_client_cert182=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert183=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA184=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA185=== RUN TestSetClientTLS/preserves_debug_logging_transport186=== PAUSE TestSetClientTLS/preserves_debug_logging_transport187=== CONT TestGetStorePathHash188=== RUN TestGetStorePathHash/valid_store_path189=== PAUSE TestGetStorePathHash/valid_store_path190=== RUN TestGetStorePathHash/basename_without_hyphen_should_error191=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error192=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error193=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error194=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error195=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error196=== CONT TestPathInfoHashCompatibility197=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)198=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)199=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon200=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon201=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI202=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI203=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512204=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512205=== CONT TestUploadMultipart_SupersededByPeer206=== RUN TestUploadMultipart_SupersededByPeer/exists207=== PAUSE TestUploadMultipart_SupersededByPeer/exists208=== RUN TestUploadMultipart_SupersededByPeer/missing209=== PAUSE TestUploadMultipart_SupersededByPeer/missing210=== CONT TestScriptTokenCachesUntilRefresh2112026/10/06 21:27:28 INFO Garbage collection started212--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)213=== CONT TestScriptTokenEmptyCommand214--- PASS: TestScriptTokenEmptyCommand (0.00s)215=== CONT TestScriptTokenScriptFails216--- PASS: TestScriptTokenScriptFails (0.00s)217=== CONT TestScriptTokenBadJSON218--- PASS: TestStreamPushRequestLine (0.02s)219=== CONT TestScriptTokenEmptyToken220--- PASS: TestScriptTokenBadJSON (0.01s)221=== CONT TestFileTokenMissing222--- PASS: TestFileTokenMissing (0.00s)223=== CONT TestScriptTokenNoExpiryRerunsEveryCall224--- PASS: TestScriptTokenEmptyToken (0.01s)225=== CONT TestFileTokenEmpty226--- PASS: TestFileTokenEmpty (0.00s)227=== CONT TestParsePathInfoJSONMultiplePaths228=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths229=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths230=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths231=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths232=== CONT TestPartSizeForNAR233=== RUN TestPartSizeForNAR/zero_stays_at_minimum234=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum235=== RUN TestPartSizeForNAR/small_stays_at_minimum236=== PAUSE TestPartSizeForNAR/small_stays_at_minimum237=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum238=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum239=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts240=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts241=== RUN TestPartSizeForNAR/1_TiB242=== PAUSE TestPartSizeForNAR/1_TiB243=== RUN TestPartSizeForNAR/5_TiB_S3_max_object244=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object245=== RUN TestPartSizeForNAR/capped_at_5_GiB246=== PAUSE TestPartSizeForNAR/capped_at_5_GiB247=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica2482026/10/06 21:27:28 INFO Garbage collection started249--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)250=== CONT TestFileTokenReadsAndCaches251--- PASS: TestFileTokenReadsAndCaches (0.00s)252=== CONT TestConvertHashToNix32253=== RUN TestConvertHashToNix32/SRI_format_to_Nix32254=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32255=== RUN TestConvertHashToNix32/already_Nix32_format256=== PAUSE TestConvertHashToNix32/already_Nix32_format257=== RUN TestConvertHashToNix32/invalid_format258=== PAUSE TestConvertHashToNix32/invalid_format259=== CONT TestRegisterUploadedObjectReusesConnections2602026/10/06 21:27:28 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=02612026/10/06 21:27:28 WARN Garbage collection finished on another replica. Its statistics are not available here262--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)263=== CONT TestEncodeNixBase32WithRealHash264--- PASS: TestEncodeNixBase32WithRealHash (0.00s)265=== CONT TestStaticToken266--- PASS: TestStaticToken (0.00s)267=== CONT TestParsePathInfoJSON268=== RUN TestParsePathInfoJSON/Nix_format269=== PAUSE TestParsePathInfoJSON/Nix_format270=== RUN TestParsePathInfoJSON/Lix_format271=== PAUSE TestParsePathInfoJSON/Lix_format272=== RUN TestParsePathInfoJSON/empty_input273=== PAUSE TestParsePathInfoJSON/empty_input274=== RUN TestParsePathInfoJSON/whitespace_only275=== PAUSE TestParsePathInfoJSON/whitespace_only276=== RUN TestParsePathInfoJSON/invalid_JSON277=== PAUSE TestParsePathInfoJSON/invalid_JSON278=== CONT TestEncodeNixBase32/test_string_hash279=== CONT TestEncodeNixBase32/empty_input280--- PASS: TestEncodeNixBase32 (0.00s)281 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)282 --- PASS: TestEncodeNixBase32/empty_input (0.00s)283=== CONT TestRateLimiterFeedback/429_enables_limiter2842026/10/06 21:27:28 WARN Rate limiter enabled after throttle name=server-test rate=52852026/10/06 21:27:28 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:534992862026/10/06 21:27:28 WARN Rate limiter backed off name=server-test rate=5287=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter288=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter289=== CONT TestRateLimiterFeedback/503_enables_limiter2902026/10/06 21:27:28 WARN Rate limiter enabled after throttle name=server-test rate=52912026/10/06 21:27:28 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:535052922026/10/06 21:27:28 WARN Rate limiter backed off name=server-test rate=5293--- PASS: TestRateLimiterFeedback (0.00s)294 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)295 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)296 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)297 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)298=== CONT TestSetClientTLSErrors/missing_cert_file299=== CONT TestSetClientTLSErrors/missing_ca_file300=== CONT TestSetClientTLSErrors/missing_key_file301=== CONT TestSetClientTLSErrors/invalid_ca_file302--- PASS: TestDumpPathWriterError (0.04s)303=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method304=== CONT TestPathInfoCACompatibility/new_structured_format_-_text305=== CONT TestPathInfoCACompatibility/null_ca_field306=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive307=== CONT TestPathInfoCACompatibility/old_string_format_-_text308=== CONT TestFilterOversizedClosures/no_limit_keeps_everything309=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3102026/10/06 21:27:28 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=2000311--- PASS: TestPathInfoCACompatibility (0.00s)312 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)313 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)314 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)315 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)316 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)317=== CONT TestSetClientTLS/rejects_connection_without_client_cert318=== CONT TestFilterOversizedClosures/all_closures_skipped3192026/10/06 21:27:28 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=50320=== CONT TestSetClientTLS/preserves_debug_logging_transport321--- PASS: TestSetClientTLSErrors (0.01s)322 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)323 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)324 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)325 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)326--- PASS: TestFilterOversizedClosures (0.00s)327 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)328 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)329 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)330=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA331=== CONT TestGetStorePathHash/valid_store_path332=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error333=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error334=== CONT TestGetStorePathHash/basename_without_hyphen_should_error335--- PASS: TestGetStorePathHash (0.00s)336 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)337 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)338 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)339 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)340=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)341=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI342=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512343=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon344--- PASS: TestPathInfoHashCompatibility (0.00s)345 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)346 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)347 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)348 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)349=== CONT TestUploadMultipart_SupersededByPeer/exists350=== CONT TestUploadMultipart_SupersededByPeer/missing351--- PASS: TestRegisterUploadedObjectReusesConnections (0.02s)352=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths353=== CONT TestPartSizeForNAR/zero_stays_at_minimum354=== CONT TestPartSizeForNAR/1_TiB355=== CONT TestPartSizeForNAR/capped_at_5_GiB356=== CONT TestPartSizeForNAR/5_TiB_S3_max_object357=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths358--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)359 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)360 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)361=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum362--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)363 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)364 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)365=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts366=== CONT TestConvertHashToNix32/SRI_format_to_Nix32367=== CONT TestConvertHashToNix32/invalid_format368=== CONT TestConvertHashToNix32/already_Nix32_format369--- PASS: TestConvertHashToNix32 (0.00s)370 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)371 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)372 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)373=== CONT TestPartSizeForNAR/small_stays_at_minimum374=== CONT TestParsePathInfoJSON/Nix_format375=== CONT TestParsePathInfoJSON/whitespace_only376--- 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 TestParsePathInfoJSON/invalid_JSON385=== CONT TestParsePathInfoJSON/empty_input386=== CONT TestParsePathInfoJSON/Lix_format387--- PASS: TestParsePathInfoJSON (0.00s)388 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)389 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)390 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)391 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)392 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)3932026/10/06 21:27:28 http: TLS handshake error from 127.0.0.1:53507: remote error: tls: bad certificate394--- PASS: TestDumpPathSingleFile (0.05s)395--- PASS: TestCaseHackSuffix (0.05s)396--- PASS: TestSetClientTLS (0.01s)397 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)398 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)399 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)400--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)401--- PASS: TestDumpPathMatchesNix (0.07s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestUploadMultipart_PartsInParallel (0.61s)404--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)405PASS406Running server tests...407The files belonging to this database system will be owned by user "_nixbld1".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-54176-1079888160/postgres2150334831/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-54176-1079888160/postgres2150334831/data -l logfile start433434/nix/var/nix/builds/nix-54176-1079888160/postgres2150334831:5432 - no response4352026-10-06 21:27:30.229 UTC [54213] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4362026-10-06 21:27:30.229 UTC [54213] LOG: listening on Unix socket "/nix/var/nix/builds/nix-54176-1079888160/postgres2150334831/.s.PGSQL.5432"4372026-10-06 21:27:30.231 UTC [54220] LOG: database system was shut down at 2026-10-06 21:27:30 UTC4382026-10-06 21:27:30.232 UTC [54213] LOG: database system is ready to accept connections439/nix/var/nix/builds/nix-54176-1079888160/postgres2150334831:5432 - accepting connections440{"timestamp":"2026-10-06T21:27:30.446315Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"a8afe0df-39e9-4127-bad2-58212a222fc4","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)"}441{"timestamp":"2026-10-06T21:27:30.550271Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"28b14be4-0a4b-4a85-a0a4-2e9e3539d6cc","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 TestDeleteClosuresRacingPins479=== PAUSE TestDeleteClosuresRacingPins480=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock481=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock482=== RUN TestResolveDBConnectionString483=== PAUSE TestResolveDBConnectionString484=== RUN TestConnectWaitsForAPeerMigration485=== PAUSE TestConnectWaitsForAPeerMigration486=== RUN TestLeadElectsOneAndHandsOver487=== PAUSE TestLeadElectsOneAndHandsOver488=== RUN TestLeadIncumbentWinsAfterRestart4892026/10/06 21:27:30 INFO lead: acquired remote=192.0.2.1:12344902026/10/06 21:27:31 INFO lead: released remote=192.0.2.1:12344912026/10/06 21:27:31 INFO lead: acquired remote=192.0.2.1:12344922026/10/06 21:27:32 INFO lead: released remote=192.0.2.1:1234493--- PASS: TestLeadIncumbentWinsAfterRestart (1.89s)494=== RUN TestLeadIncumbentAnnouncesAtOnce495=== PAUSE TestLeadIncumbentAnnouncesAtOnce496=== RUN TestLeadEndsOnShutdown497=== PAUSE TestLeadEndsOnShutdown498=== RUN TestLeadEndsWhenItsConnectionHangs4992026/10/06 21:27:32 INFO lead: acquired remote=192.0.2.1:12345002026-10-06 21:27:33.901 UTC [54255] FATAL: terminating connection due to administrator command5012026/10/06 21:27:34 INFO lead: acquired remote=192.0.2.1:12345022026/10/06 21:27:35 WARN lead: lock connection lost error="timeout: context deadline exceeded"5032026/10/06 21:27:35 INFO lead: released remote=192.0.2.1:12345042026/10/06 21:27:35 INFO lead: released remote=192.0.2.1:1234505--- PASS: TestLeadEndsWhenItsConnectionHangs (2.76s)506=== RUN TestGCAdvisoryLockBlocksConcurrentRun507=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun508=== RUN TestGCBugBareHashReferences509=== PAUSE TestGCBugBareHashReferences510=== RUN TestGCMetrics511=== PAUSE TestGCMetrics512=== RUN TestPushDedupSurvivesConcurrentGC513=== PAUSE TestPushDedupSurvivesConcurrentGC514=== RUN TestDeduplicatedObjectsRecordedAsPending515=== PAUSE TestDeduplicatedObjectsRecordedAsPending516=== RUN TestGCSweepSkipsPendingObjects517=== PAUSE TestGCSweepSkipsPendingObjects518=== RUN TestTombstonedObjectOfferedWithoutWaiting519=== PAUSE TestTombstonedObjectOfferedWithoutWaiting520=== RUN TestGCSweepDeliversEachKeyOnce521=== PAUSE TestGCSweepDeliversEachKeyOnce522=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection524=== RUN TestForceGCDuringPushOffersSweptObject525=== PAUSE TestForceGCDuringPushOffersSweptObject526=== RUN TestFailedS3DeleteKeepsTombstone527=== PAUSE TestFailedS3DeleteKeepsTombstone528=== RUN TestSweepSkipsRowsLockedByPush529=== PAUSE TestSweepSkipsRowsLockedByPush530=== RUN TestRegisterCompletedObjectNeedsPendingRow531=== PAUSE TestRegisterCompletedObjectNeedsPendingRow532=== RUN TestGetExistingObjectsLocksRows533=== PAUSE TestGetExistingObjectsLocksRows534=== RUN TestSweepRechecksPendingAfterLocking535=== PAUSE TestSweepRechecksPendingAfterLocking536=== RUN TestPushWaitsForSweepHoldingRow537=== PAUSE TestPushWaitsForSweepHoldingRow538=== RUN TestCommitRacingPendingCleanupKeepsObjects539=== PAUSE TestCommitRacingPendingCleanupKeepsObjects540=== RUN TestGCEndsOnShutdown541=== PAUSE TestGCEndsOnShutdown542=== RUN TestGCTaskStore_StartNew543=== PAUSE TestGCTaskStore_StartNew544=== RUN TestGCTaskStore_DeduplicateSameParams545=== PAUSE TestGCTaskStore_DeduplicateSameParams546=== RUN TestGCTaskStore_ConflictDifferentParams547=== PAUSE TestGCTaskStore_ConflictDifferentParams548=== RUN TestGCTaskStore_GetEmpty549=== PAUSE TestGCTaskStore_GetEmpty550=== RUN TestGCTaskStore_GetReturnsLatest551=== PAUSE TestGCTaskStore_GetReturnsLatest552=== RUN TestGCTaskStore_CompletedAllowsNewTask553=== PAUSE TestGCTaskStore_CompletedAllowsNewTask554=== RUN TestGCTaskStore_PhaseUpdates555=== PAUSE TestGCTaskStore_PhaseUpdates556=== RUN TestGCTaskStore_Fail557=== PAUSE TestGCTaskStore_Fail558=== RUN TestGracefulShutdownDrainsInflight559=== PAUSE TestGracefulShutdownDrainsInflight560=== RUN TestService_healthCheckHandler561=== PAUSE TestService_healthCheckHandler562=== RUN TestService_readinessHandler563=== PAUSE TestService_readinessHandler564=== RUN TestGenerateLandingPage565=== PAUSE TestGenerateLandingPage566=== RUN TestCacheConfigHandlerMaxNarSize567=== PAUSE TestCacheConfigHandlerMaxNarSize568=== RUN TestCreatePendingClosureRejectsOversizedNAR569=== PAUSE TestCreatePendingClosureRejectsOversizedNAR570=== RUN TestNARDeduplicationMetadataUploadBug571=== PAUSE TestNARDeduplicationMetadataUploadBug572=== RUN TestMetricsInventory573=== PAUSE TestMetricsInventory574=== RUN TestService_NativeMTLS575=== PAUSE TestService_NativeMTLS576=== RUN TestServerTLSConfig577=== PAUSE TestServerTLSConfig578=== RUN TestMultipartCleanup579=== PAUSE TestMultipartCleanup580=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded581=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded582=== RUN TestPendingCleanupUsesOneCutoff583=== PAUSE TestPendingCleanupUsesOneCutoff584=== RUN TestObjectStatsTrigger585=== PAUSE TestObjectStatsTrigger586=== RUN TestOrphanedObjectsGC587=== PAUSE TestOrphanedObjectsGC588=== RUN TestOrphanedObjectsGCStressTest589=== PAUSE TestOrphanedObjectsGCStressTest590=== RUN TestCreatePin_ReservedPins591=== PAUSE TestCreatePin_ReservedPins592=== RUN TestPresentReportsOnlyClosureRoots593=== PAUSE TestPresentReportsOnlyClosureRoots594=== RUN TestPresentRefreshesOnlyStaleClosures595=== PAUSE TestPresentRefreshesOnlyStaleClosures596=== RUN TestPresentNotReportedWhileGCDeletesClosure597=== PAUSE TestPresentNotReportedWhileGCDeletesClosure598=== RUN TestParseSingleRange599=== PAUSE TestParseSingleRange600=== RUN TestProxyHeadersOnlyTrustedOnSocket601=== PAUSE TestProxyHeadersOnlyTrustedOnSocket602=== RUN TestIsValidCachePath603=== PAUSE TestIsValidCachePath604=== RUN TestReadProxyNarinfo605=== PAUSE TestReadProxyNarinfo606=== RUN TestReadProxyNarinfoAlreadyDecompressed607=== PAUSE TestReadProxyNarinfoAlreadyDecompressed608=== RUN TestReadProxyContentNegotiation609=== PAUSE TestReadProxyContentNegotiation610=== RUN TestReadProxyNarStreaming611=== PAUSE TestReadProxyNarStreaming612=== RUN TestReadProxy404613=== PAUSE TestReadProxy404614=== RUN TestReadProxyInvalidPath615=== PAUSE TestReadProxyInvalidPath616=== RUN TestReadProxyHead617=== PAUSE TestReadProxyHead618=== RUN TestReadProxyOutlastsServerWriteTimeout619=== PAUSE TestReadProxyOutlastsServerWriteTimeout620=== RUN TestReadProxyConditionalGet621=== PAUSE TestReadProxyConditionalGet622=== RUN TestReadProxyRootRedirectsToIndexHTML623=== PAUSE TestReadProxyRootRedirectsToIndexHTML624=== RUN TestReadProxyDisabled625=== PAUSE TestReadProxyDisabled626=== RUN TestReadRedirectNar627=== PAUSE TestReadRedirectNar628=== RUN TestReadRedirectKeepsNarinfoProxied629=== PAUSE TestReadRedirectKeepsNarinfoProxied630=== RUN TestReadProxyRangeRequest631=== PAUSE TestReadProxyRangeRequest632=== RUN TestReadRedirectUsesPublicS3URL633=== PAUSE TestReadRedirectUsesPublicS3URL634=== RUN TestPush_OverlappingRootsStoreOneRowPerKey635=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey636=== RUN TestPush_CompleteCommitsEveryRoot637=== PAUSE TestPush_CompleteCommitsEveryRoot638=== RUN TestPush_RepeatedRootCommitsOnce639=== PAUSE TestPush_RepeatedRootCommitsOnce640=== RUN TestPush_CompleteWaitsForCleanupOfThePush641=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush642=== RUN TestPush_RootsAreLockedInByteOrder643=== PAUSE TestPush_RootsAreLockedInByteOrder644=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit645=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit646=== RUN TestPush_RejectsBadRequests647=== PAUSE TestPush_RejectsBadRequests648=== RUN TestPush_SignsNarinfosOfItsPendingObjects649=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects650=== RUN TestRedundantMultipartUpload651=== PAUSE TestRedundantMultipartUpload652=== RUN TestCompleteMultipartUpload_ErrorButObjectExists653=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists654=== RUN TestCompletedNarNotReofferedAcrossClosures655=== PAUSE TestCompletedNarNotReofferedAcrossClosures656=== RUN TestPresignedUploadRegisteredBeforeCommit657=== PAUSE TestPresignedUploadRegisteredBeforeCommit658=== RUN TestService_Rustfstest659=== PAUSE TestService_Rustfstest660=== RUN TestParseSize661=== PAUSE TestParseSize662=== RUN TestSkippedUploadsHandler663=== PAUSE TestSkippedUploadsHandler664=== RUN TestSystemdListenerNotActivated665--- PASS: TestSystemdListenerNotActivated (0.00s)666=== RUN TestWatchdogBeatsWhenHealthy667--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)668=== RUN TestWatchdogSkipsWhenUnhealthy6692026/10/06 21:27:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6702026/10/06 21:27:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6712026/10/06 21:27:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6722026/10/06 21:27:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6732026/10/06 21:27:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6742026/10/06 21:27:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6752026/10/06 21:27:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6762026/10/06 21:27:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6772026/10/06 21:27:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"678--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)679=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle680=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle681=== RUN TestProxyWriteTimeout682=== PAUSE TestProxyWriteTimeout683=== RUN TestPendingClosureWriteTimeout684=== PAUSE TestPendingClosureWriteTimeout685=== RUN TestIsValidUploadKey686=== PAUSE TestIsValidUploadKey687=== RUN TestUploadHandlersRejectInvalidKeys688=== PAUSE TestUploadHandlersRejectInvalidKeys689=== RUN TestUploadHandlersRejectOversizedBody690=== PAUSE TestUploadHandlersRejectOversizedBody691=== RUN TestService_cleanupPendingClosuresHandler692=== PAUSE TestService_cleanupPendingClosuresHandler693=== RUN TestService_createPendingClosureHandler694=== PAUSE TestService_createPendingClosureHandler695=== RUN TestService_verifyS3Integrity696=== PAUSE TestService_verifyS3Integrity697=== RUN TestCompleteMultipartUnregistered698=== PAUSE TestCompleteMultipartUnregistered699=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT700=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT701=== CONT TestReadProxyDisabled702=== CONT TestReadProxyOutlastsServerWriteTimeout703=== CONT TestCommitRacingPendingCleanupKeepsObjects704=== CONT TestPresignedUploadRegisteredBeforeCommit705=== CONT TestPush_CompleteWaitsForCleanupOfThePush706=== CONT TestUploadHandlersRejectInvalidKeys707=== CONT TestPush_SignsNarinfosOfItsPendingObjects708=== CONT TestService_AuthMiddleware709=== CONT TestReadProxyRootRedirectsToIndexHTML710=== CONT TestReadProxyConditionalGet711=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info712=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info713=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal714=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal715=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key716=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key717=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key718=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key719=== CONT TestIsValidUploadKey720=== RUN TestIsValidUploadKey/narinfo721=== PAUSE TestIsValidUploadKey/narinfo722=== RUN TestIsValidUploadKey/nar_zst723=== PAUSE TestIsValidUploadKey/nar_zst724=== RUN TestIsValidUploadKey/nar_xz725=== PAUSE TestIsValidUploadKey/nar_xz726=== RUN TestIsValidUploadKey/nar_plain727=== PAUSE TestIsValidUploadKey/nar_plain728=== RUN TestIsValidUploadKey/listing729=== PAUSE TestIsValidUploadKey/listing730=== RUN TestIsValidUploadKey/build_log731=== PAUSE TestIsValidUploadKey/build_log732=== RUN TestIsValidUploadKey/build_log_home-manager_file733=== PAUSE TestIsValidUploadKey/build_log_home-manager_file734=== RUN TestIsValidUploadKey/build_log_plus_in_name735=== PAUSE TestIsValidUploadKey/build_log_plus_in_name736=== RUN TestIsValidUploadKey/build_log_question_mark737=== PAUSE TestIsValidUploadKey/build_log_question_mark738=== RUN TestIsValidUploadKey/build_log_equals739=== PAUSE TestIsValidUploadKey/build_log_equals740=== RUN TestIsValidUploadKey/realisation741=== PAUSE TestIsValidUploadKey/realisation742=== RUN TestIsValidUploadKey/realisation_plus_in_output743=== PAUSE TestIsValidUploadKey/realisation_plus_in_output744=== RUN TestIsValidUploadKey/nix-cache-info745=== PAUSE TestIsValidUploadKey/nix-cache-info746=== RUN TestIsValidUploadKey/index.html747=== PAUSE TestIsValidUploadKey/index.html748=== RUN TestIsValidUploadKey/narinfo_key,_nar_type749=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type750=== RUN TestIsValidUploadKey/nar_key,_narinfo_type751=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type752=== RUN TestIsValidUploadKey/listing_key,_narinfo_type753=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type754=== RUN TestIsValidUploadKey/traversal755=== PAUSE TestIsValidUploadKey/traversal756=== RUN TestIsValidUploadKey/traversal_nar757=== PAUSE TestIsValidUploadKey/traversal_nar758=== RUN TestIsValidUploadKey/absolute759=== PAUSE TestIsValidUploadKey/absolute760=== RUN TestIsValidUploadKey/empty_key761=== PAUSE TestIsValidUploadKey/empty_key762=== RUN TestIsValidUploadKey/unknown_type763=== PAUSE TestIsValidUploadKey/unknown_type764=== CONT TestPendingClosureWriteTimeout765=== RUN TestPendingClosureWriteTimeout/empty766=== PAUSE TestPendingClosureWriteTimeout/empty767=== RUN TestPendingClosureWriteTimeout/400_objects768=== PAUSE TestPendingClosureWriteTimeout/400_objects769=== RUN TestPendingClosureWriteTimeout/670k_objects770=== PAUSE TestPendingClosureWriteTimeout/670k_objects771=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline772=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline773=== CONT TestProxyWriteTimeout774=== RUN TestProxyWriteTimeout/narinfo775=== PAUSE TestProxyWriteTimeout/narinfo776=== RUN TestProxyWriteTimeout/1_GiB_nar777=== PAUSE TestProxyWriteTimeout/1_GiB_nar778=== RUN TestProxyWriteTimeout/10_GiB_nar779=== PAUSE TestProxyWriteTimeout/10_GiB_nar780=== RUN TestProxyWriteTimeout/unknown_size781=== PAUSE TestProxyWriteTimeout/unknown_size782=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle7832026/10/06 21:27:36 INFO Aborted multipart uploads count=0 kept=07842026/10/06 21:27:36 WARN Force mode enabled - objects will be deleted immediately without grace period7852026/10/06 21:27:36 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=07862026/10/06 21:27:36 INFO Vacuumed table table=pending_closures7872026/10/06 21:27:36 INFO Vacuumed table table=pending_objects7882026/10/06 21:27:36 INFO Vacuumed table table=multipart_uploads7892026/10/06 21:27:36 INFO Vacuumed table table=closures7902026/10/06 21:27:36 INFO Vacuumed table table=objects791--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.52s)792=== CONT TestSkippedUploadsHandler7932026/10/06 21:27:36 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000794--- PASS: TestSkippedUploadsHandler (0.00s)795=== CONT TestParseSize796--- PASS: TestParseSize (0.00s)797=== CONT TestService_Rustfstest7982026/10/06 21:27:36 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"799--- PASS: TestService_AuthMiddleware (0.56s)800=== CONT TestMultipartCleanup801--- PASS: TestReadProxyConditionalGet (0.88s)802=== CONT TestReadProxyHead803--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.01s)804=== CONT TestReadProxyInvalidPath805--- PASS: TestReadProxyDisabled (1.14s)806=== CONT TestReadProxy4048072026/10/06 21:27:36 INFO Received uploads request method=POST path=/api/pending_closures8082026/10/06 21:27:36 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst8092026/10/06 21:27:36 INFO Received uploads request method=POST path=/api/pending_closures810--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.31s)811=== CONT TestReadProxyNarStreaming8122026/10/06 21:27:36 INFO Received push request method=POST path=/api/pushes8132026/10/06 21:27:37 INFO Received uploads request method=POST path=/api/pending_closures8142026/10/06 21:27:37 INFO Received push request method=POST path=/api/pushes8152026-10-06 21:27:37.323 UTC [54322] ERROR: Push does not exist: id=18162026-10-06 21:27:37.323 UTC [54322] CONTEXT: PL/pgSQL function commit_push(bigint) line 10 at RAISE8172026-10-06 21:27:37.323 UTC [54322] STATEMENT: SELECT commit_push($1)818--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.79s)819=== CONT TestReadProxyContentNegotiation8202026/10/06 21:27:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8212026/10/06 21:27:37 INFO Signed narinfos id=1 count=18222026/10/06 21:27:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8232026/10/06 21:27:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8242026/10/06 21:27:37 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"8252026/10/06 21:27:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8262026/10/06 21:27:37 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"8272026/10/06 21:27:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8282026/10/06 21:27:37 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=18292026/10/06 21:27:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8302026/10/06 21:27:37 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo831--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (1.84s)832=== CONT TestReadProxyNarinfoAlreadyDecompressed8332026/10/06 21:27:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8342026/10/06 21:27:37 INFO Received uploads request method=POST path=/api/pending_closures835--- PASS: TestService_Rustfstest (1.60s)836=== CONT TestReadProxyNarinfo8372026/10/06 21:27:37 INFO Received cleanup request method=DELETE path=/api/pending_closures8382026/10/06 21:27:37 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket13/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""8392026/10/06 21:27:37 INFO Aborted multipart uploads count=0 kept=18402026/10/06 21:27:37 INFO Received cleanup request method=DELETE path=/api/pending_closures8412026/10/06 21:27:37 INFO Aborted multipart uploads count=1 kept=0842--- PASS: TestMultipartCleanup (1.59s)843=== CONT TestIsValidCachePath844=== RUN TestIsValidCachePath/narinfo845=== PAUSE TestIsValidCachePath/narinfo846=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars847=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars848=== RUN TestIsValidCachePath/nar_zst849=== PAUSE TestIsValidCachePath/nar_zst850=== RUN TestIsValidCachePath/nar_xz851=== PAUSE TestIsValidCachePath/nar_xz852=== RUN TestIsValidCachePath/nar_bz2853=== PAUSE TestIsValidCachePath/nar_bz2854=== RUN TestIsValidCachePath/nar_uncompressed855=== PAUSE TestIsValidCachePath/nar_uncompressed856=== RUN TestIsValidCachePath/ls857=== PAUSE TestIsValidCachePath/ls858=== RUN TestIsValidCachePath/log859=== PAUSE TestIsValidCachePath/log860=== RUN TestIsValidCachePath/realisation861=== PAUSE TestIsValidCachePath/realisation862=== RUN TestIsValidCachePath/nix-cache-info863=== PAUSE TestIsValidCachePath/nix-cache-info864=== RUN TestIsValidCachePath/index.html865=== PAUSE TestIsValidCachePath/index.html866=== RUN TestIsValidCachePath/traversal_parent867=== PAUSE TestIsValidCachePath/traversal_parent868=== RUN TestIsValidCachePath/traversal_in_middle869=== PAUSE TestIsValidCachePath/traversal_in_middle870=== RUN TestIsValidCachePath/invalid_char_e871=== PAUSE TestIsValidCachePath/invalid_char_e872=== RUN TestIsValidCachePath/invalid_char_u873=== PAUSE TestIsValidCachePath/invalid_char_u874=== RUN TestIsValidCachePath/random_path875=== PAUSE TestIsValidCachePath/random_path876=== RUN TestIsValidCachePath/empty877=== PAUSE TestIsValidCachePath/empty878=== RUN TestIsValidCachePath/leading_slash879=== PAUSE TestIsValidCachePath/leading_slash880=== RUN TestIsValidCachePath/wrong_extension881=== PAUSE TestIsValidCachePath/wrong_extension882=== RUN TestIsValidCachePath/short_hash883=== PAUSE TestIsValidCachePath/short_hash884=== CONT TestProxyHeadersOnlyTrustedOnSocket885--- PASS: TestReadProxyHead (1.41s)886=== CONT TestParseSingleRange887=== RUN TestParseSingleRange/none888=== PAUSE TestParseSingleRange/none889=== RUN TestParseSingleRange/unknown_unit890=== PAUSE TestParseSingleRange/unknown_unit891=== RUN TestParseSingleRange/multi-range_ignored892=== PAUSE TestParseSingleRange/multi-range_ignored893=== RUN TestParseSingleRange/malformed_no_dash894=== PAUSE TestParseSingleRange/malformed_no_dash895=== RUN TestParseSingleRange/malformed_both_empty896=== PAUSE TestParseSingleRange/malformed_both_empty897=== RUN TestParseSingleRange/malformed_end_before_start898=== PAUSE TestParseSingleRange/malformed_end_before_start899=== RUN TestParseSingleRange/closed900=== PAUSE TestParseSingleRange/closed901=== RUN TestParseSingleRange/open-ended902=== PAUSE TestParseSingleRange/open-ended903=== RUN TestParseSingleRange/end_clamped_to_size904=== PAUSE TestParseSingleRange/end_clamped_to_size905=== RUN TestParseSingleRange/suffix906=== PAUSE TestParseSingleRange/suffix907=== RUN TestParseSingleRange/suffix_exceeds_size908=== PAUSE TestParseSingleRange/suffix_exceeds_size909=== RUN TestParseSingleRange/single_byte910=== PAUSE TestParseSingleRange/single_byte911=== RUN TestParseSingleRange/start_past_EOF912=== PAUSE TestParseSingleRange/start_past_EOF913=== RUN TestParseSingleRange/start_far_past_EOF914=== PAUSE TestParseSingleRange/start_far_past_EOF915=== CONT TestPresentNotReportedWhileGCDeletesClosure916=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale917=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale918=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh919=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh920=== CONT TestPresentRefreshesOnlyStaleClosures921--- PASS: TestReadProxyInvalidPath (1.41s)922=== CONT TestPresentReportsOnlyClosureRoots923--- PASS: TestReadProxy404 (1.49s)924=== CONT TestCreatePin_ReservedPins9252026/10/06 21:27:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53588/oidc926--- PASS: TestReadProxyNarStreaming (1.53s)927=== CONT TestOrphanedObjectsGCStressTest928--- PASS: TestReadProxyContentNegotiation (1.30s)929=== CONT TestOrphanedObjectsGC930--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.40s)931=== CONT TestObjectStatsTrigger9322026/10/06 21:27:39 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>933--- PASS: TestReadProxyNarinfo (1.41s)934=== CONT TestPendingCleanupUsesOneCutoff935--- PASS: TestPresentRefreshesOnlyStaleClosures (1.40s)936=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded937--- PASS: TestPresentReportsOnlyClosureRoots (1.43s)938=== CONT TestServerTLSConfig939=== RUN TestServerTLSConfig/no_client_CA940=== PAUSE TestServerTLSConfig/no_client_CA941=== RUN TestServerTLSConfig/missing_CA_file942=== PAUSE TestServerTLSConfig/missing_CA_file943=== RUN TestServerTLSConfig/not_a_PEM_file944=== PAUSE TestServerTLSConfig/not_a_PEM_file945=== CONT TestService_NativeMTLS9462026/10/06 21:27:39 INFO Starting HTTP server address=/nix/var/nix/builds/nix-54176-1079888160/TestProxyHeadersOnlyTrustedOnSocket1841689557/001/proxy.sock9472026/10/06 21:27:39 INFO Starting HTTP server address=127.0.0.1:536119482026/10/06 21:27:39 WARN mTLS auth: subject not in bound subjects subject="CN=someone"9492026/10/06 21:27:39 INFO Shutdown signal received, draining in-flight requests timeout=10s950--- PASS: TestProxyHeadersOnlyTrustedOnSocket (1.83s)951=== CONT TestMetricsInventory9522026/10/06 21:27:39 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux9532026/10/06 21:27:39 WARN Refused reserved pin name=worker-x86_64-linux9542026/10/06 21:27:39 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux9552026/10/06 21:27:39 INFO Received create pin request method=POST path=/api/pins/my-app9562026/10/06 21:27:39 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux957--- PASS: TestCreatePin_ReservedPins (1.55s)958=== CONT TestNARDeduplicationMetadataUploadBug959--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.97s)960=== CONT TestCreatePendingClosureRejectsOversizedNAR9612026/10/06 21:27:40 INFO Received uploads request method=POST path=/api/pending_closures962--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)963=== CONT TestCacheConfigHandlerMaxNarSize964--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)965=== CONT TestGenerateLandingPage966--- PASS: TestGenerateLandingPage (0.00s)967=== CONT TestService_readinessHandler968--- PASS: TestObjectStatsTrigger (1.72s)969=== CONT TestService_healthCheckHandler970=== NAME TestOrphanedObjectsGC971 orphaned_objects_gc_test.go:287: GC Test Summary:972 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A973 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B974 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)975 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)976 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects977--- PASS: TestOrphanedObjectsGC (2.21s)978=== CONT TestGracefulShutdownDrainsInflight9792026/10/06 21:27:40 INFO Starting HTTP server address=127.0.0.1:536259802026/10/06 21:27:40 INFO Shutdown signal received, draining in-flight requests timeout=10s981--- PASS: TestGracefulShutdownDrainsInflight (0.07s)982=== CONT TestGCTaskStore_Fail983--- PASS: TestGCTaskStore_Fail (0.00s)984=== CONT TestGCTaskStore_PhaseUpdates985--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)986=== CONT TestGCTaskStore_CompletedAllowsNewTask987--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)988=== CONT TestGCTaskStore_GetReturnsLatest989--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)990=== CONT TestGCTaskStore_GetEmpty991--- PASS: TestGCTaskStore_GetEmpty (0.00s)992=== CONT TestGCTaskStore_ConflictDifferentParams993--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)994=== CONT TestGCTaskStore_DeduplicateSameParams995--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)996=== CONT TestGCTaskStore_StartNew997--- PASS: TestGCTaskStore_StartNew (0.00s)998=== CONT TestGCEndsOnShutdown999=== RUN TestGCEndsOnShutdown/before_the_run1000=== PAUSE TestGCEndsOnShutdown/before_the_run1001=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1002=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1003=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1004=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1005=== CONT TestConnectWaitsForAPeerMigration10062026/10/06 21:27:40 INFO Received uploads request method=POST path=/api/pending_closures10072026/10/06 21:27:41 INFO Received uploads request method=POST path=/api/pending_closures10082026/10/06 21:27:41 INFO Received cleanup request method=DELETE path=/api/pending_closures10092026/10/06 21:27:41 INFO Received uploads request method=POST path=/api/pending_closures1010--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (2.08s)1011=== CONT TestPushWaitsForSweepHoldingRow10122026/10/06 21:27:41 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10132026/10/06 21:27:41 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1014--- PASS: TestService_NativeMTLS (2.08s)1015=== CONT TestSweepRechecksPendingAfterLocking1016--- PASS: TestMetricsInventory (2.24s)1017=== CONT TestGetExistingObjectsLocksRows10182026/10/06 21:27:42 WARN Rate limiter enabled after throttle name=s3-test rate=510192026/10/06 21:27:42 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1020=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1021 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101022 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001023--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.75s)1024=== CONT TestRegisterCompletedObjectNeedsPendingRow1025=== NAME TestNARDeduplicationMetadataUploadBug1026 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-54176-1079888160/TestNARDeduplicationMetadataUploadBug3688190431/001/store/b3zihzjc93h37kxigg2vjcbiqnj19cl5-file1.txt10272026/10/06 21:27:42 INFO Received push request method=POST path=/api/pushes10282026/10/06 21:27:42 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10292026/10/06 21:27:42 INFO Uploading b3zihzjc93h37kxigg2vjcbiqnj19cl5-file1.txt (160B)10302026/10/06 21:27:42 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"10312026/10/06 21:27:42 WARN Failed to register uploaded object key=b3zihzjc93h37kxigg2vjcbiqnj19cl5.ls error="server returned 404: 404 page not found\n"10322026/10/06 21:27:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10332026/10/06 21:27:42 INFO Signed narinfos id=1 count=110342026/10/06 21:27:42 INFO Uploading 1 narinfos10352026/10/06 21:27:42 INFO Received complete push request method=POST path=/api/pushes/1/complete10362026/10/06 21:27:42 WARN Failed to register uploaded object key=b3zihzjc93h37kxigg2vjcbiqnj19cl5.narinfo error="server returned 404: 404 page not found\n"10372026/10/06 21:27:42 INFO Completed push id=110382026/10/06 21:27:42 INFO Upload complete. (142ms)1039 metadata_upload_test.go:54: Retrieved narinfo from S3:1040 StorePath: /nix/var/nix/builds/nix-54176-1079888160/TestNARDeduplicationMetadataUploadBug3688190431/001/store/b3zihzjc93h37kxigg2vjcbiqnj19cl5-file1.txt1041 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1042 Compression: zstd1043 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1044 NarSize: 1601045 References: 1046 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1047 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1048 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1049 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1050 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-54176-1079888160/TestNARDeduplicationMetadataUploadBug3688190431/001/store/a4ilkfs2prn6gp2ds3sf0khfgvgqnihg-file2.txt10512026/10/06 21:27:42 INFO Received push request method=POST path=/api/pushes10522026/10/06 21:27:42 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)10532026/10/06 21:27:42 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign10542026/10/06 21:27:42 INFO Signed narinfos id=2 count=110552026/10/06 21:27:42 WARN Failed to register uploaded object key=a4ilkfs2prn6gp2ds3sf0khfgvgqnihg.ls error="server returned 404: 404 page not found\n"10562026/10/06 21:27:42 INFO Uploading 1 narinfos10572026/10/06 21:27:42 INFO Received complete push request method=POST path=/api/pushes/2/complete10582026/10/06 21:27:42 WARN Failed to register uploaded object key=a4ilkfs2prn6gp2ds3sf0khfgvgqnihg.narinfo error="server returned 404: 404 page not found\n"10592026/10/06 21:27:42 INFO Completed push id=210602026/10/06 21:27:42 INFO Upload complete. (99ms)1061 metadata_upload_test.go:76: Retrieved narinfo from S3:1062 StorePath: /nix/var/nix/builds/nix-54176-1079888160/TestNARDeduplicationMetadataUploadBug3688190431/001/store/a4ilkfs2prn6gp2ds3sf0khfgvgqnihg-file2.txt1063 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1064 Compression: zstd1065 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1066 NarSize: 1601067 References: 1068 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1069 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1070 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1071 {"version":1,"root":{"type":"regular","size":44}}1072--- PASS: TestNARDeduplicationMetadataUploadBug (3.35s)1073=== CONT TestSweepSkipsRowsLockedByPush1074--- PASS: TestService_healthCheckHandler (2.79s)1075=== CONT TestFailedS3DeleteKeepsTombstone10762026/10/06 21:27:43 WARN readiness check failed error="closed pool"1077--- PASS: TestService_readinessHandler (3.08s)1078=== CONT TestForceGCDuringPushOffersSweptObject1079=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1080=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1081=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1082=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1083=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10842026/10/06 21:27:44 INFO Received uploads request method=POST path=/api/pending_closures10852026/10/06 21:27:44 INFO Aborted multipart uploads count=0 kept=010862026/10/06 21:27:44 WARN Force mode enabled - objects will be deleted immediately without grace period10872026/10/06 21:27:44 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 21:27:44 INFO Vacuumed table table=pending_closures10892026/10/06 21:27:44 INFO Vacuumed table table=pending_objects10902026/10/06 21:27:44 INFO Vacuumed table table=multipart_uploads10912026/10/06 21:27:44 INFO Vacuumed table table=closures10922026/10/06 21:27:44 INFO Vacuumed table table=objects1093--- PASS: TestSweepRechecksPendingAfterLocking (3.13s)1094=== CONT TestGCSweepDeliversEachKeyOnce1095--- PASS: TestGetExistingObjectsLocksRows (2.94s)1096=== CONT TestTombstonedObjectOfferedWithoutWaiting1097--- PASS: TestPushWaitsForSweepHoldingRow (3.41s)1098=== CONT TestGCSweepSkipsPendingObjects1099--- PASS: TestRegisterCompletedObjectNeedsPendingRow (2.69s)1100=== CONT TestDeduplicatedObjectsRecordedAsPending1101=== NAME TestOrphanedObjectsGCStressTest1102 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1103 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion11042026/10/06 21:27:45 INFO Aborted multipart uploads count=0 kept=011052026/10/06 21:27:45 WARN Force mode enabled - objects will be deleted immediately without grace period11062026/10/06 21:27:45 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011072026/10/06 21:27:45 INFO Vacuumed table table=pending_closures11082026/10/06 21:27:45 INFO Vacuumed table table=pending_objects11092026/10/06 21:27:45 INFO Vacuumed table table=multipart_uploads11102026/10/06 21:27:45 INFO Vacuumed table table=closures11112026/10/06 21:27:45 INFO Vacuumed table table=objects11122026/10/06 21:27:45 INFO Aborted multipart uploads count=0 kept=011132026/10/06 21:27:45 WARN Force mode enabled - objects will be deleted immediately without grace period11142026/10/06 21:27:45 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=011152026/10/06 21:27:45 INFO Vacuumed table table=pending_closures11162026/10/06 21:27:45 INFO Vacuumed table table=pending_objects11172026/10/06 21:27:45 INFO Vacuumed table table=multipart_uploads11182026/10/06 21:27:45 INFO Vacuumed table table=closures11192026/10/06 21:27:45 INFO Vacuumed table table=objects1120--- PASS: TestSweepSkipsRowsLockedByPush (2.94s)1121=== CONT TestPushDedupSurvivesConcurrentGC11222026/10/06 21:27:46 INFO Received uploads request method=POST path=/api/pending_closures11232026/10/06 21:27:46 INFO Aborted multipart uploads count=0 kept=011242026/10/06 21:27:46 WARN Force mode enabled - objects will be deleted immediately without grace period11252026/10/06 21:27:46 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."11262026/10/06 21:27:46 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1127--- PASS: TestFailedS3DeleteKeepsTombstone (2.98s)1128=== CONT TestGCMetrics11292026/10/06 21:27:46 INFO Received uploads request method=POST path=/api/pending_closures1130--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (3.00s)1131=== CONT TestGCBugBareHashReferences11322026/10/06 21:27:46 INFO Received uploads request method=POST path=/api/pending_closures11332026/10/06 21:27:46 INFO Aborted multipart uploads count=0 kept=011342026/10/06 21:27:46 WARN Force mode enabled - objects will be deleted immediately without grace period11352026/10/06 21:27:46 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=011362026/10/06 21:27:46 INFO Vacuumed table table=pending_closures11372026/10/06 21:27:46 INFO Vacuumed table table=pending_objects11382026/10/06 21:27:46 INFO Vacuumed table table=multipart_uploads11392026/10/06 21:27:46 INFO Vacuumed table table=closures11402026/10/06 21:27:46 INFO Vacuumed table table=objects1141--- PASS: TestGCSweepSkipsPendingObjects (2.00s)1142=== CONT TestGCAdvisoryLockBlocksConcurrentRun11432026/10/06 21:27:46 INFO Aborted multipart uploads count=0 kept=011442026/10/06 21:27:46 WARN Force mode enabled - objects will be deleted immediately without grace period11452026/10/06 21:27:46 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=011462026/10/06 21:27:46 INFO Vacuumed table table=pending_closures11472026/10/06 21:27:46 INFO Vacuumed table table=pending_objects11482026/10/06 21:27:46 INFO Vacuumed table table=multipart_uploads11492026/10/06 21:27:46 INFO Vacuumed table table=closures11502026/10/06 21:27:46 INFO Vacuumed table table=objects1151--- PASS: TestGCSweepDeliversEachKeyOnce (2.39s)1152=== CONT TestLeadEndsOnShutdown11532026/10/06 21:27:47 INFO Received uploads request method=POST path=/api/pending_closures1154--- PASS: TestTombstonedObjectOfferedWithoutWaiting (2.38s)1155=== CONT TestLeadIncumbentAnnouncesAtOnce11562026/10/06 21:27:47 INFO Aborted multipart uploads count=1 kept=011572026/10/06 21:27:47 INFO Received cleanup request method=DELETE path=/api/pending_closures11582026/10/06 21:27:47 INFO Aborted multipart uploads count=1 kept=01159--- PASS: TestPendingCleanupUsesOneCutoff (8.13s)1160=== CONT TestLeadElectsOneAndHandsOver11612026/10/06 21:27:47 INFO Received uploads request method=POST path=/api/pending_closures1162--- PASS: TestDeduplicatedObjectsRecordedAsPending (2.29s)1163=== CONT TestPush_RootsAreLockedInByteOrder1164=== NAME TestOrphanedObjectsGCStressTest1165 orphaned_objects_gc_test.go:503: Stress test completed successfully:1166 orphaned_objects_gc_test.go:504: - Active objects preserved: 201167 orphaned_objects_gc_test.go:505: - Objects deleted: 2101168 orphaned_objects_gc_test.go:506: - Total GC'd: 2101169--- PASS: TestOrphanedObjectsGCStressTest (9.17s)1170=== CONT TestClientIntegration11712026/10/06 21:27:47 INFO Received uploads request method=POST path=/api/pending_closures11722026/10/06 21:27:47 INFO Aborted multipart uploads count=0 kept=011732026/10/06 21:27:47 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=011742026/10/06 21:27:47 INFO Vacuumed table table=pending_closures11752026/10/06 21:27:47 INFO Vacuumed table table=pending_objects11762026/10/06 21:27:47 INFO Vacuumed table table=multipart_uploads11772026/10/06 21:27:47 INFO Vacuumed table table=closures11782026/10/06 21:27:47 INFO Aborted multipart uploads count=0 kept=011792026/10/06 21:27:47 WARN Force mode enabled - objects will be deleted immediately without grace period11802026/10/06 21:27:47 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=011812026/10/06 21:27:47 INFO Vacuumed table table=objects11822026/10/06 21:27:47 INFO Vacuumed table table=pending_closures11832026/10/06 21:27:47 INFO Vacuumed table table=pending_objects11842026/10/06 21:27:47 INFO Vacuumed table table=multipart_uploads11852026/10/06 21:27:47 INFO Vacuumed table table=closures11862026/10/06 21:27:47 INFO Vacuumed table table=objects1187--- PASS: TestGCMetrics (1.54s)1188=== CONT TestResolveDBConnectionString1189=== RUN TestResolveDBConnectionString/flag_wins1190=== PAUSE TestResolveDBConnectionString/flag_wins1191=== RUN TestResolveDBConnectionString/file_when_flag_empty1192=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1193=== RUN TestResolveDBConnectionString/missing_file_is_an_error1194=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1195=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1196=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1197=== RUN TestResolveDBConnectionString/nothing_configured1198=== PAUSE TestResolveDBConnectionString/nothing_configured1199=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock12002026/10/06 21:27:47 INFO Aborted multipart uploads count=0 kept=012012026/10/06 21:27:47 WARN Force mode enabled - objects will be deleted immediately without grace period12022026/10/06 21:27:47 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=012032026/10/06 21:27:47 INFO Vacuumed table table=pending_closures12042026/10/06 21:27:47 INFO Vacuumed table table=pending_objects12052026/10/06 21:27:47 INFO Vacuumed table table=multipart_uploads12062026/10/06 21:27:47 INFO Vacuumed table table=closures12072026/10/06 21:27:47 INFO Vacuumed table table=objects1208--- PASS: TestPushDedupSurvivesConcurrentGC (1.84s)1209=== CONT TestDeleteClosuresRacingPins1210--- PASS: TestGCBugBareHashReferences (1.73s)1211=== CONT TestClientFallsBackToClosures12122026/10/06 21:27:48 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_nixbld1 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1213--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (1.61s)1214=== CONT TestClientPushesUseOnePush1215--- PASS: TestConnectWaitsForAPeerMigration (7.59s)1216=== CONT TestPinProtectsFromGC12172026/10/06 21:27:48 INFO lead: acquired remote=192.0.2.1:123412182026/10/06 21:27:48 INFO lead: acquired remote=192.0.2.1:123412192026/10/06 21:27:48 INFO lead: released remote=192.0.2.1:12341220--- PASS: TestLeadIncumbentAnnouncesAtOnce (1.70s)1221=== CONT TestClientSharedPathCommittedMidPush12222026/10/06 21:27:48 INFO lead: acquired remote=192.0.2.1:123412232026/10/06 21:27:49 INFO Received push request method=POST path=/api/pushes12242026-10-06 21:27:49.347 UTC [54492] ERROR: could not obtain lock on row in relation "closures"12252026-10-06 21:27:49.347 UTC [54492] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12262026-10-06 21:27:49.347 UTC [54492] ERROR: could not obtain lock on row in relation "closures"12272026-10-06 21:27:49.347 UTC [54492] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12282026-10-06 21:27:49.347 UTC [54492] ERROR: could not obtain lock on row in relation "closures"12292026-10-06 21:27:49.347 UTC [54492] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12302026-10-06 21:27:49.347 UTC [54492] ERROR: could not obtain lock on row in relation "closures"12312026-10-06 21:27:49.347 UTC [54492] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12322026-10-06 21:27:49.348 UTC [54492] ERROR: could not obtain lock on row in relation "closures"12332026-10-06 21:27:49.348 UTC [54492] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1234--- PASS: TestPush_RootsAreLockedInByteOrder (2.08s)1235=== CONT TestClientWithDependencies12362026/10/06 21:27:49 INFO lead: released remote=192.0.2.1:12341237--- PASS: TestLeadEndsOnShutdown (2.61s)1238=== CONT TestClientMultipleUploads1239=== NAME TestClientIntegration1240 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-54176-1079888160/TestClientIntegration294138009/002/store/0g2m05kkifik5barlik0grv398iwvkam-test-file.txt12412026/10/06 21:27:49 INFO Received push request method=POST path=/api/pushes12422026/10/06 21:27:49 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12432026/10/06 21:27:49 INFO Uploading 0g2m05kkifik5barlik0grv398iwvkam-test-file.txt (152B)12442026/10/06 21:27:49 WARN Failed to register uploaded object key=0g2m05kkifik5barlik0grv398iwvkam.ls error="server returned 404: 404 page not found\n"12452026/10/06 21:27:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12462026/10/06 21:27:49 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12472026/10/06 21:27:49 INFO Signed narinfos id=1 count=112482026/10/06 21:27:49 INFO Uploading 1 narinfos12492026/10/06 21:27:49 INFO Received complete push request method=POST path=/api/pushes/1/complete12502026/10/06 21:27:49 WARN Failed to register uploaded object key=0g2m05kkifik5barlik0grv398iwvkam.narinfo error="server returned 404: 404 page not found\n"12512026/10/06 21:27:49 INFO Completed push id=112522026/10/06 21:27:49 INFO Upload complete. (81ms)12532026/10/06 21:27:49 INFO All 1 paths already cached1254 client_integration_test.go:312: Retrieved narinfo from S3:1255 StorePath: /nix/var/nix/builds/nix-54176-1079888160/TestClientIntegration294138009/002/store/0g2m05kkifik5barlik0grv398iwvkam-test-file.txt1256 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1257 Compression: zstd1258 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11259 NarSize: 1521260 References: 1261 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11262 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1263 client_integration_test.go:313: Decompressed .ls content (64 bytes):1264 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1265 client_integration_test.go:316: Testing garbage collection...12662026/10/06 21:27:49 INFO Starting cleanup of old closures method=DELETE path=/api/closures12672026/10/06 21:27:49 INFO Garbage collection started12682026/10/06 21:27:49 INFO Aborted multipart uploads count=0 kept=012692026/10/06 21:27:49 WARN Force mode enabled - objects will be deleted immediately without grace period12702026/10/06 21:27:49 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=012712026/10/06 21:27:49 INFO Vacuumed table table=pending_closures12722026/10/06 21:27:49 INFO Vacuumed table table=pending_objects12732026/10/06 21:27:49 INFO Vacuumed table table=multipart_uploads12742026/10/06 21:27:49 INFO Vacuumed table table=closures12752026/10/06 21:27:50 INFO Vacuumed table table=objects12762026/10/06 21:27:50 INFO lead: released remote=192.0.2.1:123412772026/10/06 21:27:50 INFO lead: acquired remote=192.0.2.1:123412782026/10/06 21:27:50 INFO Received push request method=POST path=/api/pushes12792026/10/06 21:27:50 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12802026/10/06 21:27:50 INFO Uploading qsnmaaig70qqjc9yc2v5w7jj6jqrxm5g-a (248B)12812026/10/06 21:27:50 INFO Uploading 7y4zr3s1bf4vr1rkr828gjmbdl26wdaj-shared-dep (136B)12822026/10/06 21:27:50 WARN Failed to register uploaded object key=nar/0m4v11r8cnwv8jmda5l19zcwd4drcxdxbzxrdanr41jn16fv6k0b.nar.zst error="server returned 404: 404 page not found\n"12832026/10/06 21:27:50 WARN Failed to register uploaded object key=qsnmaaig70qqjc9yc2v5w7jj6jqrxm5g.ls error="server returned 404: 404 page not found\n"12842026/10/06 21:27:50 WARN Failed to register uploaded object key=7y4zr3s1bf4vr1rkr828gjmbdl26wdaj.ls error="server returned 404: 404 page not found\n"12852026/10/06 21:27:50 WARN Failed to register uploaded object key=dvrrwr6ys6kqmj6zs6yi29s7x3h517ig.ls error="server returned 404: 404 page not found\n"12862026/10/06 21:27:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12872026/10/06 21:27:50 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12882026/10/06 21:27:50 INFO Signed narinfos id=1 count=312892026/10/06 21:27:50 INFO Uploading 3 narinfos12902026/10/06 21:27:50 WARN Failed to register uploaded object key=7y4zr3s1bf4vr1rkr828gjmbdl26wdaj.narinfo error="server returned 404: 404 page not found\n"12912026/10/06 21:27:50 WARN Failed to register uploaded object key=qsnmaaig70qqjc9yc2v5w7jj6jqrxm5g.narinfo error="server returned 404: 404 page not found\n"12922026/10/06 21:27:50 INFO Received complete push request method=POST path=/api/pushes/1/complete12932026/10/06 21:27:50 WARN Failed to register uploaded object key=dvrrwr6ys6kqmj6zs6yi29s7x3h517ig.narinfo error="server returned 404: 404 page not found\n"12942026/10/06 21:27:50 INFO Completed push id=112952026/10/06 21:27:50 INFO Upload complete. (119ms)1296=== NAME TestClientPushesUseOnePush1297 client_pushes_test.go:97: Retrieved narinfo from S3:1298 StorePath: /nix/var/nix/builds/nix-54176-1079888160/TestClientPushesUseOnePush3648186607/001/store/7y4zr3s1bf4vr1rkr828gjmbdl26wdaj-shared-dep1299 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1300 Compression: zstd1301 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821302 NarSize: 1361303 References: 1304 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1305 client_pushes_test.go:97: Retrieved narinfo from S3:1306 StorePath: /nix/var/nix/builds/nix-54176-1079888160/TestClientPushesUseOnePush3648186607/001/store/qsnmaaig70qqjc9yc2v5w7jj6jqrxm5g-a1307 URL: nar/0m4v11r8cnwv8jmda5l19zcwd4drcxdxbzxrdanr41jn16fv6k0b.nar.zst1308 Compression: zstd1309 NarHash: sha256:0m4v11r8cnwv8jmda5l19zcwd4drcxdxbzxrdanr41jn16fv6k0b1310 NarSize: 2481311 References: /nix/var/nix/builds/nix-54176-1079888160/TestClientPushesUseOnePush3648186607/001/store/7y4zr3s1bf4vr1rkr828gjmbdl26wdaj-shared-dep1312 CA: text:sha256:0vfc1h9xdhnbnqzr0n1465lab11wsbj659m4j61i5hc65b4fkcdr1313 client_pushes_test.go:97: Retrieved narinfo from S3:1314 StorePath: /nix/var/nix/builds/nix-54176-1079888160/TestClientPushesUseOnePush3648186607/001/store/dvrrwr6ys6kqmj6zs6yi29s7x3h517ig-b1315 URL: nar/0m4v11r8cnwv8jmda5l19zcwd4drcxdxbzxrdanr41jn16fv6k0b.nar.zst1316 Compression: zstd1317 NarHash: sha256:0m4v11r8cnwv8jmda5l19zcwd4drcxdxbzxrdanr41jn16fv6k0b1318 NarSize: 2481319 References: /nix/var/nix/builds/nix-54176-1079888160/TestClientPushesUseOnePush3648186607/001/store/7y4zr3s1bf4vr1rkr828gjmbdl26wdaj-shared-dep1320 CA: text:sha256:0vfc1h9xdhnbnqzr0n1465lab11wsbj659m4j61i5hc65b4fkcdr1321--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (2.70s)1322=== CONT TestService_verifyS3Integrity1323--- PASS: TestClientPushesUseOnePush (2.21s)1324=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT13252026/10/06 21:27:50 INFO Received uploads request method=POST path=/api/pending_closures13262026/10/06 21:27:50 INFO Received uploads request method=POST path=/api/pending_closures13272026/10/06 21:27:50 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13282026/10/06 21:27:50 INFO Uploading kb65pzz4kw9b7xhix630vhaznap0fnd2-b (248B)13292026/10/06 21:27:50 INFO Uploading 0rhrhqdd324lgx7r7iw6ap91fbv70ss6-shared-dep (136B)13302026/10/06 21:27:50 WARN Failed to register uploaded object key=hjn2jg0k8dmr78djx38wv4r2ijjxdqcy.ls error="server returned 404: 404 page not found\n"13312026/10/06 21:27:50 WARN Failed to register uploaded object key=kb65pzz4kw9b7xhix630vhaznap0fnd2.ls error="server returned 404: 404 page not found\n"13322026/10/06 21:27:50 WARN Failed to register uploaded object key=0rhrhqdd324lgx7r7iw6ap91fbv70ss6.ls error="server returned 404: 404 page not found\n"13332026/10/06 21:27:50 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13342026/10/06 21:27:50 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13352026/10/06 21:27:50 WARN Failed to register uploaded object key=nar/1i40m55qcjiagf347zly301870qxikksyljkj3fkc3n7n81nrrqn.nar.zst error="server returned 404: 404 page not found\n"13362026/10/06 21:27:50 INFO Signed narinfos id=1 count=213372026/10/06 21:27:50 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13382026/10/06 21:27:50 INFO Signed narinfos id=2 count=213392026/10/06 21:27:50 INFO Uploading 4 narinfos1340=== NAME TestPinProtectsFromGC1341 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-54176-1079888160/TestPinProtectsFromGC302931430/001/store/q7lsdmkyvgdzy5imsy6cvrzrl9qlhxpi-pinned-file.txt1342 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-54176-1079888160/TestPinProtectsFromGC302931430/001/store/5nwr6n5pr4ryb6z1iaq69asixqw9bd3n-unpinned-file.txt13432026/10/06 21:27:50 WARN Failed to register uploaded object key=kb65pzz4kw9b7xhix630vhaznap0fnd2.narinfo error="server returned 404: 404 page not found\n"13442026/10/06 21:27:50 WARN Failed to register uploaded object key=hjn2jg0k8dmr78djx38wv4r2ijjxdqcy.narinfo error="server returned 404: 404 page not found\n"13452026/10/06 21:27:50 WARN Failed to register uploaded object key=0rhrhqdd324lgx7r7iw6ap91fbv70ss6.narinfo error="server returned 404: 404 page not found\n"13462026/10/06 21:27:50 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13472026/10/06 21:27:50 WARN Failed to register uploaded object key=0rhrhqdd324lgx7r7iw6ap91fbv70ss6.narinfo error="server returned 404: 404 page not found\n"13482026/10/06 21:27:50 INFO Completed upload id=113492026/10/06 21:27:50 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13502026/10/06 21:27:50 INFO Completed upload id=213512026/10/06 21:27:50 INFO Upload complete. (193ms)1352=== NAME TestClientFallsBackToClosures1353 client_pushes_test.go:112: Retrieved narinfo from S3:1354 StorePath: /nix/var/nix/builds/nix-54176-1079888160/TestClientFallsBackToClosures32076825/001/store/0rhrhqdd324lgx7r7iw6ap91fbv70ss6-shared-dep1355 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1356 Compression: zstd1357 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821358 NarSize: 1361359 References: 1360 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1361 client_pushes_test.go:112: Retrieved narinfo from S3:1362 StorePath: /nix/var/nix/builds/nix-54176-1079888160/TestClientFallsBackToClosures32076825/001/store/hjn2jg0k8dmr78djx38wv4r2ijjxdqcy-a1363 URL: nar/1i40m55qcjiagf347zly301870qxikksyljkj3fkc3n7n81nrrqn.nar.zst1364 Compression: zstd1365 NarHash: sha256:1i40m55qcjiagf347zly301870qxikksyljkj3fkc3n7n81nrrqn1366 NarSize: 2481367 References: /nix/var/nix/builds/nix-54176-1079888160/TestClientFallsBackToClosures32076825/001/store/0rhrhqdd324lgx7r7iw6ap91fbv70ss6-shared-dep1368 CA: text:sha256:1wlca4p4bjzm5cnhd805i691wyqr4qv1w2waf2lkk7il1dmn1y601369 client_pushes_test.go:112: Retrieved narinfo from S3:1370 StorePath: /nix/var/nix/builds/nix-54176-1079888160/TestClientFallsBackToClosures32076825/001/store/kb65pzz4kw9b7xhix630vhaznap0fnd2-b1371 URL: nar/1i40m55qcjiagf347zly301870qxikksyljkj3fkc3n7n81nrrqn.nar.zst1372 Compression: zstd1373 NarHash: sha256:1i40m55qcjiagf347zly301870qxikksyljkj3fkc3n7n81nrrqn1374 NarSize: 2481375 References: /nix/var/nix/builds/nix-54176-1079888160/TestClientFallsBackToClosures32076825/001/store/0rhrhqdd324lgx7r7iw6ap91fbv70ss6-shared-dep1376 CA: text:sha256:1wlca4p4bjzm5cnhd805i691wyqr4qv1w2waf2lkk7il1dmn1y6013772026/10/06 21:27:50 INFO Received push request method=POST path=/api/pushes13782026/10/06 21:27:50 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13792026/10/06 21:27:50 INFO Uploading q7lsdmkyvgdzy5imsy6cvrzrl9qlhxpi-pinned-file.txt (128B)13802026/10/06 21:27:50 WARN Failed to register uploaded object key=q7lsdmkyvgdzy5imsy6cvrzrl9qlhxpi.ls error="server returned 404: 404 page not found\n"13812026/10/06 21:27:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13822026/10/06 21:27:50 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"13832026/10/06 21:27:50 INFO Signed narinfos id=1 count=113842026/10/06 21:27:50 INFO Uploading 1 narinfos1385--- PASS: TestClientFallsBackToClosures (2.54s)1386=== CONT TestCompleteMultipartUnregistered13872026/10/06 21:27:50 INFO Received complete push request method=POST path=/api/pushes/1/complete13882026/10/06 21:27:50 WARN Failed to register uploaded object key=q7lsdmkyvgdzy5imsy6cvrzrl9qlhxpi.narinfo error="server returned 404: 404 page not found\n"13892026/10/06 21:27:50 INFO Completed push id=113902026/10/06 21:27:50 INFO Upload complete. (172ms)13912026/10/06 21:27:50 INFO Received push request method=POST path=/api/pushes13922026/10/06 21:27:50 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13932026/10/06 21:27:50 INFO Uploading 5nwr6n5pr4ryb6z1iaq69asixqw9bd3n-unpinned-file.txt (128B)13942026/10/06 21:27:51 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"13952026/10/06 21:27:51 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13962026/10/06 21:27:51 INFO Signed narinfos id=2 count=113972026/10/06 21:27:51 WARN Failed to register uploaded object key=5nwr6n5pr4ryb6z1iaq69asixqw9bd3n.ls error="server returned 404: 404 page not found\n"13982026/10/06 21:27:51 INFO Uploading 1 narinfos13992026/10/06 21:27:51 INFO Received complete push request method=POST path=/api/pushes/2/complete14002026/10/06 21:27:51 WARN Failed to register uploaded object key=5nwr6n5pr4ryb6z1iaq69asixqw9bd3n.narinfo error="server returned 404: 404 page not found\n"14012026/10/06 21:27:51 INFO Completed push id=214022026/10/06 21:27:51 INFO Upload complete. (91ms)14032026/10/06 21:27:51 INFO Starting cleanup of old closures method=DELETE path=/api/closures14042026/10/06 21:27:51 INFO Garbage collection started14052026/10/06 21:27:51 INFO Aborted multipart uploads count=0 kept=014062026/10/06 21:27:51 WARN Force mode enabled - objects will be deleted immediately without grace period14072026/10/06 21:27:51 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=014082026/10/06 21:27:51 INFO Vacuumed table table=pending_closures14092026/10/06 21:27:51 INFO Received push request method=POST path=/api/pushes14102026/10/06 21:27:51 INFO Vacuumed table table=pending_objects14112026/10/06 21:27:51 INFO Vacuumed table table=multipart_uploads14122026/10/06 21:27:51 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)14132026/10/06 21:27:51 INFO Uploading k7210bigli3sxdn8gh9hi2mw2w7zqklz-top (256B)14142026/10/06 21:27:51 INFO Uploading d3y0h7abhzmrzrdknq1v69ph9dv9ypgf-shared-dep (136B)14152026/10/06 21:27:51 WARN Failed to register uploaded object key=k7210bigli3sxdn8gh9hi2mw2w7zqklz.ls error="server returned 404: 404 page not found\n"14162026/10/06 21:27:51 WARN Failed to register uploaded object key=nar/0kymlcrxpgj3h1szs9n1ma3fqfl7xhyxn4nznv0zbldszh9ahwki.nar.zst error="server returned 404: 404 page not found\n"14172026/10/06 21:27:51 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14182026/10/06 21:27:51 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14192026/10/06 21:27:51 WARN Failed to register uploaded object key=d3y0h7abhzmrzrdknq1v69ph9dv9ypgf.ls error="server returned 404: 404 page not found\n"14202026/10/06 21:27:51 INFO Signed narinfos id=1 count=214212026/10/06 21:27:51 INFO Uploading 2 narinfos14222026/10/06 21:27:51 INFO Received complete push request method=POST path=/api/pushes/1/complete14232026/10/06 21:27:51 WARN Failed to register uploaded object key=k7210bigli3sxdn8gh9hi2mw2w7zqklz.narinfo error="server returned 404: 404 page not found\n"14242026/10/06 21:27:51 WARN Failed to register uploaded object key=d3y0h7abhzmrzrdknq1v69ph9dv9ypgf.narinfo error="server returned 404: 404 page not found\n"14252026/10/06 21:27:51 INFO Vacuumed table table=closures14262026/10/06 21:27:51 INFO Completed push id=114272026/10/06 21:27:51 INFO Upload complete. (139ms)1428=== NAME TestClientSharedPathCommittedMidPush1429 client_integration_test.go:680: Retrieved narinfo from S3:1430 StorePath: /nix/var/nix/builds/nix-54176-1079888160/TestClientSharedPathCommittedMidPush1969413375/001/store/d3y0h7abhzmrzrdknq1v69ph9dv9ypgf-shared-dep1431 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1432 Compression: zstd1433 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821434 NarSize: 1361435 References: 1436 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1437 client_integration_test.go:680: Retrieved narinfo from S3:1438 StorePath: /nix/var/nix/builds/nix-54176-1079888160/TestClientSharedPathCommittedMidPush1969413375/001/store/k7210bigli3sxdn8gh9hi2mw2w7zqklz-top1439 URL: nar/0kymlcrxpgj3h1szs9n1ma3fqfl7xhyxn4nznv0zbldszh9ahwki.nar.zst1440 Compression: zstd1441 NarHash: sha256:0kymlcrxpgj3h1szs9n1ma3fqfl7xhyxn4nznv0zbldszh9ahwki1442 NarSize: 2561443 References: /nix/var/nix/builds/nix-54176-1079888160/TestClientSharedPathCommittedMidPush1969413375/001/store/d3y0h7abhzmrzrdknq1v69ph9dv9ypgf-shared-dep1444 CA: text:sha256:0msgbak7kp435c6bm9hhdiyipw3nl1mjl2j8nnna1c4zkrrh338x14452026/10/06 21:27:51 INFO Vacuumed table table=objects14462026/10/06 21:27:51 INFO lead: released remote=192.0.2.1:12341447--- PASS: TestLeadElectsOneAndHandsOver (4.10s)1448=== CONT TestService_ReadScope_PublicByDefault1449--- PASS: TestClientSharedPathCommittedMidPush (2.56s)1450=== CONT TestClientErrorHandling1451=== RUN TestClientErrorHandling/InvalidStorePath1452=== PAUSE TestClientErrorHandling/InvalidStorePath1453=== RUN TestClientErrorHandling/InvalidAuthToken1454=== PAUSE TestClientErrorHandling/InvalidAuthToken1455=== RUN TestClientErrorHandling/ServerNotAvailable1456=== PAUSE TestClientErrorHandling/ServerNotAvailable1457=== CONT TestService_RequireScope_OIDC14582026/10/06 21:27:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53797/oidc1459=== NAME TestClientWithDependencies1460 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-54176-1079888160/TestClientWithDependencies3459799229/001/store/6r6pjddfxnc1msply1klp8hx62ld4j7x-test-script1461 client_integration_test.go:615: Found 1 dependencies (including self)1462=== NAME TestClientMultipleUploads1463 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-54176-1079888160/TestClientMultipleUploads2116464694/001/store/hklr33zivv6kpyar3psypyab1s74sw2b-test-file-0.txt14642026/10/06 21:27:51 INFO Received push request method=POST path=/api/pushes14652026/10/06 21:27:51 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14662026/10/06 21:27:51 INFO Uploading 6r6pjddfxnc1msply1klp8hx62ld4j7x-test-script (136B)14672026/10/06 21:27:51 WARN Failed to register uploaded object key=6r6pjddfxnc1msply1klp8hx62ld4j7x.ls error="server returned 404: 404 page not found\n"14682026/10/06 21:27:51 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"1469 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-54176-1079888160/TestClientMultipleUploads2116464694/001/store/hx86hh65iif4xjs7i61g3934ln335lz0-test-file-1.txt14702026/10/06 21:27:51 WARN Failed to register uploaded object key=log/is9rfyq325d1zz6lcl2bp2cv4224g49i-test-script.drv error="server returned 404: 404 page not found\n"14712026/10/06 21:27:51 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14722026/10/06 21:27:51 INFO Signed narinfos id=1 count=114732026/10/06 21:27:51 INFO Uploading 1 narinfos14742026/10/06 21:27:51 INFO Received complete push request method=POST path=/api/pushes/1/complete14752026/10/06 21:27:51 WARN Failed to register uploaded object key=6r6pjddfxnc1msply1klp8hx62ld4j7x.narinfo error="server returned 404: 404 page not found\n"14762026/10/06 21:27:51 INFO Completed push id=114772026/10/06 21:27:51 INFO Upload complete. (106ms)1478=== NAME TestClientWithDependencies1479 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-54176-1079888160/TestClientWithDependencies3459799229/001/store) requires matching store prefix1480=== NAME TestClientMultipleUploads1481 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-54176-1079888160/TestClientMultipleUploads2116464694/001/store/df8khmx05wbxyiviirjcbw96xc8c5gg8-test-file-2.txt1482--- PASS: TestClientWithDependencies (2.30s)1483=== CONT TestService_AuthMiddleware_OIDC14842026/10/06 21:27:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53809/oidc14852026/10/06 21:27:51 INFO Received push request method=POST path=/api/pushes14862026/10/06 21:27:51 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)14872026/10/06 21:27:51 INFO Uploading hx86hh65iif4xjs7i61g3934ln335lz0-test-file-1.txt (160B)14882026/10/06 21:27:51 INFO Uploading df8khmx05wbxyiviirjcbw96xc8c5gg8-test-file-2.txt (160B)14892026/10/06 21:27:51 INFO Uploading hklr33zivv6kpyar3psypyab1s74sw2b-test-file-0.txt (160B)14902026/10/06 21:27:51 WARN Failed to register uploaded object key=df8khmx05wbxyiviirjcbw96xc8c5gg8.ls error="server returned 404: 404 page not found\n"14912026/10/06 21:27:51 WARN Failed to register uploaded object key=hx86hh65iif4xjs7i61g3934ln335lz0.ls error="server returned 404: 404 page not found\n"14922026/10/06 21:27:51 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14932026/10/06 21:27:51 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"14942026/10/06 21:27:51 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"14952026/10/06 21:27:51 WARN Failed to register uploaded object key=hklr33zivv6kpyar3psypyab1s74sw2b.ls error="server returned 404: 404 page not found\n"14962026/10/06 21:27:51 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"14972026/10/06 21:27:51 INFO Signed narinfos id=1 count=314982026/10/06 21:27:51 INFO Uploading 3 narinfos14992026/10/06 21:27:51 WARN Failed to register uploaded object key=df8khmx05wbxyiviirjcbw96xc8c5gg8.narinfo error="server returned 404: 404 page not found\n"15002026/10/06 21:27:51 WARN Failed to register uploaded object key=hx86hh65iif4xjs7i61g3934ln335lz0.narinfo error="server returned 404: 404 page not found\n"15012026/10/06 21:27:51 INFO Received complete push request method=POST path=/api/pushes/1/complete15022026/10/06 21:27:51 WARN Failed to register uploaded object key=hklr33zivv6kpyar3psypyab1s74sw2b.narinfo error="server returned 404: 404 page not found\n"15032026/10/06 21:27:51 INFO Completed push id=115042026/10/06 21:27:51 INFO Upload complete. (123ms)1505=== NAME TestClientMultipleUploads1506 client_integration_test.go:369: Uploaded 3 paths in 157.124375ms1507--- PASS: TestClientMultipleUploads (2.26s)1508=== CONT TestClientCADerivations15092026/10/06 21:27:51 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01510=== NAME TestClientIntegration1511 client_integration_test.go:323: Objects in database after GC:1512 client_integration_test.go:323: Successfully deleted all objects with GC --force1513--- PASS: TestClientIntegration (4.35s)1514=== CONT TestService_ReadAuthMiddleware15152026/10/06 21:27:52 INFO Received uploads request method=POST path=/api/pending_closures1516--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.71s)1517=== CONT TestCacheStatsHandler15182026/10/06 21:27:52 INFO Received uploads request method=POST path=/api/pending_closures15192026/10/06 21:27:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15202026/10/06 21:27:52 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1521--- PASS: TestCompleteMultipartUnregistered (1.82s)1522=== CONT TestCacheConfigHandler1523=== RUN TestCacheConfigHandler/full_config,_no_issuer1524=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1525=== RUN TestCacheConfigHandler/no_cache_url_configured1526=== PAUSE TestCacheConfigHandler/no_cache_url_configured1527=== RUN TestCacheConfigHandler/no_signing_keys1528=== PAUSE TestCacheConfigHandler/no_signing_keys1529=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1530=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1531=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1532--- PASS: TestDeleteClosuresRacingPins (5.17s)1533=== CONT TestCompleteMultipartUpload_ErrorButObjectExists15342026/10/06 21:27:53 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=015352026/10/06 21:27:53 INFO Received create pin request method=POST path=/api/pins/myapp15362026/10/06 21:27:53 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-54176-1079888160/TestPinProtectsFromGC302931430/001/store/q7lsdmkyvgdzy5imsy6cvrzrl9qlhxpi-pinned-file.txt narinfo_key=q7lsdmkyvgdzy5imsy6cvrzrl9qlhxpi.narinfo15372026/10/06 21:27:53 INFO Starting cleanup of old closures method=DELETE path=/api/closures15382026/10/06 21:27:53 INFO Garbage collection started15392026/10/06 21:27:53 INFO Aborted multipart uploads count=0 kept=015402026/10/06 21:27:53 WARN Force mode enabled - objects will be deleted immediately without grace period15412026/10/06 21:27:53 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=015422026/10/06 21:27:53 INFO Vacuumed table table=pending_closures15432026/10/06 21:27:53 INFO Vacuumed table table=pending_objects15442026/10/06 21:27:53 INFO Vacuumed table table=multipart_uploads15452026/10/06 21:27:53 INFO Vacuumed table table=closures15462026/10/06 21:27:53 INFO Vacuumed table table=objects1547--- PASS: TestService_ReadScope_PublicByDefault (2.01s)1548=== CONT TestService_AuthMiddleware_MTLSProxyHeader1549=== RUN TestService_RequireScope_OIDC/builder_may_write1550=== PAUSE TestService_RequireScope_OIDC/builder_may_write1551=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1552=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1553=== RUN TestService_RequireScope_OIDC/ops_may_admin1554=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1555=== RUN TestService_RequireScope_OIDC/ops_may_not_write1556=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1557=== RUN TestService_RequireScope_OIDC/reader_may_not_write1558=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1559=== RUN TestService_RequireScope_OIDC/static_token_may_admin1560=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1561=== RUN TestService_RequireScope_OIDC/static_token_may_write1562=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1563=== RUN TestService_RequireScope_OIDC/reader_may_read1564=== PAUSE TestService_RequireScope_OIDC/reader_may_read1565=== RUN TestService_RequireScope_OIDC/writer_implies_read1566=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1567=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1568=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1569=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1570=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1571=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1572=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1573=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1574=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1575=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1576=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1577=== CONT TestCompletedNarNotReofferedAcrossClosures15782026/10/06 21:27:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15792026/10/06 21:27:53 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZjUyM2Q4ZjUtODgzNS00ZmRkLWFjOGUtZjg0NmQ0ODIwOGM3LjcyZTczZThhLWQ3MjEtNDE4OS04NTVhLTQzMDIxNTFjMzg0MngxNzkxMzIyMDcyNDQ2MzA2MDAw parts=1015802026/10/06 21:27:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1581=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1582=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1583=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1584=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1585=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1586=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1587=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1588=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1589=== CONT TestPush_RejectsBadRequests15902026/10/06 21:27:53 INFO Completed upload id=115912026/10/06 21:27:53 INFO Received uploads request method=POST path=/api/pending_closures15922026/10/06 21:27:53 INFO Received uploads request method=POST path=/api/pending_closures15932026/10/06 21:27:53 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo15942026/10/06 21:27:53 WARN Found objects in DB but missing from S3, will re-upload count=11595--- PASS: TestService_verifyS3Integrity (3.46s)1596=== CONT TestRedundantMultipartUpload1597--- PASS: TestService_ReadAuthMiddleware (2.76s)1598=== CONT TestReadRedirectUsesPublicS3URL1599=== NAME TestClientCADerivations1600 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-54176-1079888160/TestClientCADerivations811830758/001/store/0i50hd2vhr00riympalh780si3k88c3k-ca-test1601 client_ca_test.go:139: Found 1 dependencies (including self)16022026/10/06 21:27:55 INFO Received push request method=POST path=/api/pushes1603--- PASS: TestCacheStatsHandler (2.79s)1604=== CONT TestService_cleanupPendingClosuresHandler16052026/10/06 21:27:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16062026/10/06 21:27:55 INFO Uploading 0i50hd2vhr00riympalh780si3k88c3k-ca-test (144B)16072026/10/06 21:27:55 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16082026/10/06 21:27:55 WARN Failed to register uploaded object key=0i50hd2vhr00riympalh780si3k88c3k.ls error="server returned 404: 404 page not found\n"16092026/10/06 21:27:55 WARN Failed to register uploaded object key=log/i370w65fmdl1l7440b1gnj79d5zsz5h5-ca-test.drv error="server returned 404: 404 page not found\n"16102026/10/06 21:27:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16112026/10/06 21:27:55 INFO Signed narinfos id=1 count=116122026/10/06 21:27:55 INFO Uploading 1 narinfos16132026/10/06 21:27:55 INFO Received complete push request method=POST path=/api/pushes/1/complete16142026/10/06 21:27:55 WARN Failed to register uploaded object key=0i50hd2vhr00riympalh780si3k88c3k.narinfo error="server returned 404: 404 page not found\n"1615=== NAME TestPinProtectsFromGC1616 client_integration_test.go:840: Pin successfully protected closure from garbage collection16172026/10/06 21:27:55 INFO Completed push id=116182026/10/06 21:27:55 INFO Upload complete. (229ms)1619=== NAME TestClientCADerivations1620 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-54176-1079888160/TestClientCADerivations811830758/001/store/0i50hd2vhr00riympalh780si3k88c3k-ca-test1621 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1622 Compression: zstd1623 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1624 NarSize: 1441625 References: 1626 Deriver: /nix/var/nix/builds/nix-54176-1079888160/TestClientCADerivations811830758/001/store/i370w65fmdl1l7440b1gnj79d5zsz5h5-ca-test.drv1627 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1628 client_ca_test.go:185: Checking for realisation files in S3...1629 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1630 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1631--- PASS: TestPinProtectsFromGC (6.71s)1632=== CONT TestService_createPendingClosureHandler16332026/10/06 21:27:55 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16342026/10/06 21:27:55 WARN mTLS auth: bound subjects configured but subject DN unavailable16352026/10/06 21:27:55 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1636--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.59s)1637=== CONT TestPush_RepeatedRootCommitsOnce1638=== NAME TestClientCADerivations1639 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket70?endpoint=http://localhost:53516®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-54176-1079888160/TestClientCADerivations811830758/001/store'1640 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11641--- PASS: TestClientCADerivations (3.46s)1642=== CONT TestPush_CompleteCommitsEveryRoot16432026/10/06 21:27:55 INFO Received uploads request method=POST path=/api/pending_closures16442026/10/06 21:27:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16452026/10/06 21:27:56 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZjUyM2Q4ZjUtODgzNS00ZmRkLWFjOGUtZjg0NmQ0ODIwOGM3LjQyMzI4YmRjLWJhNzctNDkxMi04Mjc1LTRkNGNkNzZmNGY4OHgxNzkxMzIyMDc1ODIxMDE3MDAw1646--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (2.80s)1647=== CONT TestPush_OverlappingRootsStoreOneRowPerKey16482026/10/06 21:27:56 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZjUyM2Q4ZjUtODgzNS00ZmRkLWFjOGUtZjg0NmQ0ODIwOGM3LjQyMzI4YmRjLWJhNzctNDkxMi04Mjc1LTRkNGNkNzZmNGY4OHgxNzkxMzIyMDc1ODIxMDE3MDAw parts=11649--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (3.12s)1650=== CONT TestReadRedirectKeepsNarinfoProxied16512026/10/06 21:27:56 INFO Received uploads request method=POST path=/api/pending_closures1652=== RUN TestPush_RejectsBadRequests/no_roots1653=== PAUSE TestPush_RejectsBadRequests/no_roots1654=== RUN TestPush_RejectsBadRequests/no_objects1655=== PAUSE TestPush_RejectsBadRequests/no_objects1656=== RUN TestPush_RejectsBadRequests/bad_root1657=== PAUSE TestPush_RejectsBadRequests/bad_root1658=== RUN TestPush_RejectsBadRequests/root_not_in_objects1659=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1660=== CONT TestReadRedirectNar16612026/10/06 21:27:57 INFO Received uploads request method=POST path=/api/pending_closures16622026/10/06 21:27:57 INFO Received uploads request method=POST path=/api/pending_closures1663--- PASS: TestReadRedirectUsesPublicS3URL (2.96s)1664=== CONT TestReadProxyRangeRequest16652026/10/06 21:27:58 INFO Received cleanup request method=DELETE path=/api/pending_closures16662026/10/06 21:27:58 INFO Aborted multipart uploads count=0 kept=016672026/10/06 21:27:58 INFO Received uploads request method=POST path=/api/pending_closures16682026/10/06 21:27:58 INFO Received cleanup request method=DELETE path=/api/pending_closures16692026/10/06 21:27:58 INFO Aborted multipart uploads count=1 kept=016702026/10/06 21:27:58 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16712026-10-06 21:27:58.153 UTC [54728] ERROR: Closure does not exist: id=116722026-10-06 21:27:58.153 UTC [54728] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE16732026-10-06 21:27:58.153 UTC [54728] STATEMENT: -- name: CommitPendingClosure :exec1674 SELECT commit_pending_closure($1::bigint)1675 1676--- PASS: TestService_cleanupPendingClosuresHandler (3.13s)1677=== CONT TestUploadHandlersRejectOversizedBody1678=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1679=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1680=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1681=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1682=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1683=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1684=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16852026/10/06 21:27:58 INFO Received uploads request method=POST path=/1686=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit16872026/10/06 21:27:58 INFO Received uploads request method=POST path=/api/pending_closures16882026/10/06 21:27:58 INFO Received uploads request method=POST path=/api/pending_closures16892026/10/06 21:27:58 INFO Received uploads request method=POST path=/api/pending_closures16902026/10/06 21:27:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16912026/10/06 21:27:58 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZjUyM2Q4ZjUtODgzNS00ZmRkLWFjOGUtZjg0NmQ0ODIwOGM3LmY1Mzg0ZWI3LTJmMjMtNDQ1MC1hMThiLTliZjVmNWRmNDQ3MXgxNzkxMzIyMDc2NDk0NjU2MDAw parts=1216922026/10/06 21:27:58 INFO Received uploads request method=POST path=/api/pending_closures1693--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.89s)1694=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16952026/10/06 21:27:58 INFO Received complete multipart upload request method=POST path=/1696=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16972026/10/06 21:27:58 INFO Received request for more parts method=POST path=/1698=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16992026/10/06 21:27:58 INFO Received uploads request method=POST path=/1700--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1701 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1702 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1703 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1704 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1705=== CONT TestIsValidUploadKey/narinfo1706=== CONT TestIsValidUploadKey/realisation_plus_in_output1707=== CONT TestIsValidUploadKey/realisation1708=== CONT TestIsValidUploadKey/build_log_equals1709=== CONT TestIsValidUploadKey/build_log_question_mark1710=== CONT TestIsValidUploadKey/build_log_plus_in_name1711=== CONT TestIsValidUploadKey/build_log_home-manager_file1712=== CONT TestIsValidUploadKey/build_log1713=== CONT TestIsValidUploadKey/listing1714=== CONT TestIsValidUploadKey/nar_plain1715=== CONT TestIsValidUploadKey/nar_xz1716=== CONT TestIsValidUploadKey/nar_zst1717=== CONT TestIsValidUploadKey/traversal_nar1718=== CONT TestIsValidUploadKey/nix-cache-info1719=== CONT TestIsValidUploadKey/traversal1720=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1721=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1722=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1723=== CONT TestIsValidUploadKey/index.html1724=== CONT TestIsValidUploadKey/empty_key1725=== CONT TestIsValidUploadKey/unknown_type1726=== CONT TestIsValidUploadKey/absolute1727--- PASS: TestIsValidUploadKey (0.00s)1728 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1729 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1730 --- PASS: TestIsValidUploadKey/realisation (0.00s)1731 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1732 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1733 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1734 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1735 --- PASS: TestIsValidUploadKey/build_log (0.00s)1736 --- PASS: TestIsValidUploadKey/listing (0.00s)1737 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1738 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1739 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1740 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1741 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1742 --- PASS: TestIsValidUploadKey/traversal (0.00s)1743 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1744 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1745 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1746 --- PASS: TestIsValidUploadKey/index.html (0.00s)1747 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1748 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1749 --- PASS: TestIsValidUploadKey/absolute (0.00s)1750=== CONT TestPendingClosureWriteTimeout/empty1751=== CONT TestPendingClosureWriteTimeout/670k_objects1752=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline17532026/10/06 21:27:58 INFO Received push request method=POST path=/api/pushes17542026/10/06 21:27:58 INFO Received complete push request method=POST path=/api/pushes/1/complete17552026/10/06 21:27:58 INFO Completed push id=11756--- PASS: TestPush_CompleteCommitsEveryRoot (3.63s)1757=== CONT TestPendingClosureWriteTimeout/400_objects1758=== CONT TestProxyWriteTimeout/narinfo1759=== CONT TestProxyWriteTimeout/10_GiB_nar1760=== CONT TestProxyWriteTimeout/unknown_size1761=== CONT TestProxyWriteTimeout/1_GiB_nar1762--- PASS: TestProxyWriteTimeout (0.00s)1763 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1764 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1765 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1766 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1767=== CONT TestIsValidCachePath/narinfo1768=== CONT TestIsValidCachePath/index.html1769=== CONT TestIsValidCachePath/short_hash1770=== CONT TestIsValidCachePath/wrong_extension1771=== CONT TestIsValidCachePath/leading_slash1772=== CONT TestIsValidCachePath/empty1773=== CONT TestIsValidCachePath/random_path1774=== CONT TestIsValidCachePath/invalid_char_u1775=== CONT TestIsValidCachePath/invalid_char_e1776=== CONT TestIsValidCachePath/traversal_in_middle1777=== CONT TestIsValidCachePath/traversal_parent1778=== CONT TestIsValidCachePath/nar_uncompressed1779=== CONT TestIsValidCachePath/nix-cache-info1780=== CONT TestIsValidCachePath/realisation1781=== CONT TestIsValidCachePath/log1782=== CONT TestIsValidCachePath/ls1783=== CONT TestIsValidCachePath/nar_xz1784=== CONT TestIsValidCachePath/nar_bz21785=== CONT TestIsValidCachePath/nar_zst1786=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1787=== CONT TestParseSingleRange/none1788--- PASS: TestIsValidCachePath (0.00s)1789 --- PASS: TestIsValidCachePath/narinfo (0.00s)1790 --- PASS: TestIsValidCachePath/index.html (0.00s)1791 --- PASS: TestIsValidCachePath/short_hash (0.00s)1792 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1793 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1794 --- PASS: TestIsValidCachePath/empty (0.00s)1795 --- PASS: TestIsValidCachePath/random_path (0.00s)1796 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1797 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1798 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1799 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1800 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1801 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1802 --- PASS: TestIsValidCachePath/realisation (0.00s)1803 --- PASS: TestIsValidCachePath/log (0.00s)1804 --- PASS: TestIsValidCachePath/ls (0.00s)1805 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1806 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1807 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1808 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1809=== CONT TestParseSingleRange/open-ended1810=== CONT TestParseSingleRange/closed1811=== CONT TestParseSingleRange/end_clamped_to_size1812=== CONT TestParseSingleRange/malformed_end_before_start1813=== CONT TestParseSingleRange/malformed_both_empty1814=== CONT TestParseSingleRange/malformed_no_dash1815=== CONT TestParseSingleRange/multi-range_ignored1816=== CONT TestParseSingleRange/unknown_unit1817=== CONT TestParseSingleRange/single_byte1818=== CONT TestParseSingleRange/start_far_past_EOF1819=== CONT TestParseSingleRange/start_past_EOF1820=== CONT TestParseSingleRange/suffix_exceeds_size1821=== CONT TestParseSingleRange/suffix1822--- PASS: TestParseSingleRange (0.00s)1823 --- PASS: TestParseSingleRange/none (0.00s)1824 --- PASS: TestParseSingleRange/open-ended (0.00s)1825 --- PASS: TestParseSingleRange/closed (0.00s)1826 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1827 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1828 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1829 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1830 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1831 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1832 --- PASS: TestParseSingleRange/single_byte (0.00s)1833 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1834 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1835 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1836 --- PASS: TestParseSingleRange/suffix (0.00s)1837=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale18382026/10/06 21:27:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18392026/10/06 21:27:59 INFO Received push request method=POST path=/api/pushes18402026/10/06 21:27:59 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZjUyM2Q4ZjUtODgzNS00ZmRkLWFjOGUtZjg0NmQ0ODIwOGM3LmViNTZlZjk2LTE1MjktNGM3Ni05NjA4LTMzODMyZWE4NGJlMXgxNzkxMzIyMDc3MTQ2MzA1MDAw parts=1218412026/10/06 21:27:59 INFO Received uploads request method=POST path=/api/pending_closures18422026/10/06 21:27:59 INFO Received complete push request method=POST path=/api/pushes/1/complete18432026/10/06 21:27:59 INFO Received uploads request method=POST path=/api/pending_closures18442026/10/06 21:27:59 INFO Completed push id=11845--- PASS: TestPush_RepeatedRootCommitsOnce (4.03s)1846=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh18472026/10/06 21:27:59 INFO Received push request method=POST path=/api/pushes1848--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (3.76s)1849=== CONT TestServerTLSConfig/no_client_CA1850=== CONT TestServerTLSConfig/not_a_PEM_file1851=== CONT TestServerTLSConfig/missing_CA_file1852--- PASS: TestServerTLSConfig (0.00s)1853 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1854 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1855 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1856=== CONT TestGCEndsOnShutdown/before_the_run18572026/10/06 21:28:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18582026/10/06 21:28:00 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZjUyM2Q4ZjUtODgzNS00ZmRkLWFjOGUtZjg0NmQ0ODIwOGM3LjZjNDc3NDhjLWFkYTItNGNjOS04NjA4LWQyMThhOTAyNTcwZngxNzkxMzIyMDc4NDI4MDIwMDAw parts=1018592026/10/06 21:28:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18602026/10/06 21:28:00 INFO Completed upload id=118612026/10/06 21:28:00 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000018622026/10/06 21:28:00 INFO Received uploads request method=POST path=/api/pending_closures18632026/10/06 21:28:00 INFO Starting cleanup of old closures method=DELETE path=/api/closures18642026/10/06 21:28:00 INFO Aborted multipart uploads count=0 kept=018652026/10/06 21:28:00 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=018662026/10/06 21:28:00 INFO Vacuumed table table=pending_closures18672026/10/06 21:28:00 INFO Vacuumed table table=pending_objects1868--- PASS: TestReadRedirectKeepsNarinfoProxied (4.02s)1869=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark18702026/10/06 21:28:00 INFO Vacuumed table table=multipart_uploads18712026/10/06 21:28:00 INFO Vacuumed table table=closures18722026/10/06 21:28:00 INFO Vacuumed table table=objects18732026/10/06 21:28:00 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001874--- PASS: TestService_createPendingClosureHandler (5.10s)1875=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1876--- PASS: TestReadRedirectNar (3.67s)1877=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1878--- PASS: TestReadProxyRangeRequest (3.27s)1879=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check18802026/10/06 21:28:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18812026/10/06 21:28:00 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZjUyM2Q4ZjUtODgzNS00ZmRkLWFjOGUtZjg0NmQ0ODIwOGM3LmI0MjJlNDM5LThmMmYtNDQ4Ni04MGJjLWNhNzVhNjM4OTQ5MngxNzkxMzIyMDc5Mjk5NjU0MDAw error="Get \"http://127.0.0.1:1/bucket78/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"18822026/10/06 21:28:00 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZjUyM2Q4ZjUtODgzNS00ZmRkLWFjOGUtZjg0NmQ0ODIwOGM3LjdmMmVhMGQxLTgwMzUtNDYwMi1iNzVlLTdjZDE4NWE0ZTg5OHgxNzkxMzIyMDc5MjU5MDQ0MDAw parts=1218832026/10/06 21:28:00 INFO Received cleanup request method=DELETE path=/api/pending_closures18842026/10/06 21:28:00 INFO Aborted multipart uploads count=1 kept=01885--- PASS: TestRedundantMultipartUpload (7.01s)1886=== CONT TestResolveDBConnectionString/flag_wins1887=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1888=== CONT TestResolveDBConnectionString/nothing_configured1889=== CONT TestResolveDBConnectionString/missing_file_is_an_error1890=== CONT TestResolveDBConnectionString/file_when_flag_empty1891=== CONT TestClientErrorHandling/InvalidStorePath1892--- PASS: TestResolveDBConnectionString (0.01s)1893 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1894 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1895 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1896 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1897 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)18982026/10/06 21:28:01 INFO Received push request method=POST path=/api/pushes18992026/10/06 21:28:01 INFO Received complete push request method=POST path=/api/pushes/1/complete19002026/10/06 21:28:01 INFO Completed push id=119012026/10/06 21:28:01 INFO Received push request method=POST path=/api/pushes19022026/10/06 21:28:01 INFO Aborted multipart uploads count=0 kept=019032026/10/06 21:28:01 WARN Force mode enabled - objects will be deleted immediately without grace period19042026/10/06 21:28:01 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=019052026/10/06 21:28:01 INFO Vacuumed table table=pending_closures19062026/10/06 21:28:01 INFO Received uploads request method=POST path=/api/pending_closures19072026/10/06 21:28:01 INFO Vacuumed table table=pending_objects19082026/10/06 21:28:01 INFO Vacuumed table table=multipart_uploads19092026/10/06 21:28:01 INFO Vacuumed table table=closures19102026/10/06 21:28:01 INFO Vacuumed table table=objects19112026/10/06 21:28:01 INFO Received complete push request method=POST path=/api/pushes/2/complete19122026/10/06 21:28:01 INFO Completed push id=21913--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (3.26s)1914=== CONT TestClientErrorHandling/ServerNotAvailable19152026/10/06 21:28:01 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/present19162026/10/06 21:28:01 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=180.857295ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19172026/10/06 21:28:01 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=421.484125ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1918=== CONT TestClientErrorHandling/InvalidAuthToken1919--- PASS: TestPendingClosureWriteTimeout (0.00s)1920 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1921 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1922 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1923 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (3.68s)1924=== CONT TestCacheConfigHandler/full_config,_no_issuer1925=== CONT TestCacheConfigHandler/no_signing_keys1926=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1927=== CONT TestCacheConfigHandler/no_cache_url_configured1928--- PASS: TestCacheConfigHandler (0.00s)1929 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1930 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1931 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1932 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1933=== CONT TestService_RequireScope_OIDC/builder_may_write1934=== CONT TestService_RequireScope_OIDC/reader_may_read1935=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1936=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19372026/10/06 21:28:02 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]1938=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1939=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1940=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1941=== CONT TestService_RequireScope_OIDC/writer_implies_read1942=== CONT TestService_RequireScope_OIDC/reader_may_not_write1943=== CONT TestService_RequireScope_OIDC/static_token_may_write1944=== CONT TestService_RequireScope_OIDC/static_token_may_admin1945=== CONT TestService_RequireScope_OIDC/ops_may_admin1946=== CONT TestService_RequireScope_OIDC/ops_may_not_write1947=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1948=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1949=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19502026/10/06 21:28:02 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]1951=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1952=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1953--- PASS: TestService_RequireScope_OIDC (2.29s)1954 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1955 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1956 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1957 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1958 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1959 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1960 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1961 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1962 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1963 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1964 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1965 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1966 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1967 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)19682026/10/06 21:28:02 WARN Authentication failed token_preview=eyJhbGciOi...sGeiS_ZPCw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1969=== CONT TestPush_RejectsBadRequests/no_roots19702026/10/06 21:28:02 INFO Received push request method=POST path=/api/pushes1971=== CONT TestPush_RejectsBadRequests/bad_root19722026/10/06 21:28:02 INFO Received push request method=POST path=/api/pushes1973=== CONT TestPush_RejectsBadRequests/root_not_in_objects19742026/10/06 21:28:02 INFO Received push request method=POST path=/api/pushes1975=== CONT TestPush_RejectsBadRequests/no_objects19762026/10/06 21:28:02 INFO Received push request method=POST path=/api/pushes1977=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts19782026/10/06 21:28:02 INFO Received request for more parts method=POST path=/1979--- PASS: TestPush_RejectsBadRequests (2.83s)1980 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1981 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1982 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1983 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1984--- PASS: TestService_AuthMiddleware_OIDC (2.29s)1985 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1986 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1987 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1988 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1989=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19902026/10/06 21:28:02 INFO Received complete multipart upload request method=POST path=/1991=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19922026/10/06 21:28:02 INFO Received uploads request method=POST path=/19932026/10/06 21:28:02 INFO Aborted multipart uploads count=0 kept=019942026/10/06 21:28:02 WARN Force mode enabled - objects will be deleted immediately without grace period19952026-10-06 21:28:02.307 UTC [54797] ERROR: canceling statement due to user request19962026-10-06 21:28:02.307 UTC [54797] STATEMENT: -- name: MarkStaleObjects :execrows1997 WITH RECURSIVE ct AS (1998 SELECT timezone('UTC', now()) AS now1999 ),2000 closure_reach AS (2001 -- Start with all closure keys2002 SELECT o.key, o.refs2003 FROM objects o2004 INNER JOIN closures c ON o.key = c.key2005 UNION2006 -- Recursively add all referenced objects2007 SELECT o.key, o.refs2008 FROM objects o2009 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2010 ),2011 reachable_objects AS (2012 SELECT DISTINCT key FROM closure_reach2013 ),2014 stale_objects AS (2015 SELECT o.key2016 FROM objects AS o, ct2017 WHERE2018 NOT EXISTS (2019 SELECT 12020 FROM reachable_objects ro2021 WHERE ro.key = o.key2022 )2023 AND NOT EXISTS (2024 SELECT 12025 FROM pending_objects AS po2026 WHERE po.key = o.key2027 )2028 AND o.deleted_at IS NULL -- Only mark fresh objects2029 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2030 FOR UPDATE2031 )2032 UPDATE objects2033 SET2034 deleted_at = ct.now,2035 first_deleted_at = COALESCE(first_deleted_at, ct.now)2036 FROM stale_objects, ct2037 WHERE objects.key = stale_objects.key2038 20392026/10/06 21:28:02 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=876.953797ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2040--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2041 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (3.28s)2042 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (3.09s)20432026/10/06 21:28:02 INFO Aborted multipart uploads count=0 kept=020442026/10/06 21:28:02 WARN Force mode enabled - objects will be deleted immediately without grace period20452026/10/06 21:28:02 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:53516/bucket94/?delete=\": context canceled"2046--- PASS: TestGCEndsOnShutdown (0.00s)2047 --- PASS: TestGCEndsOnShutdown/before_the_run (2.22s)2048 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (2.17s)2049 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (2.15s)2050--- PASS: TestUploadHandlersRejectOversizedBody (0.04s)2051 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.03s)2052 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)2053 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.27s)20542026/10/06 21:28:02 INFO Received uploads request method=POST path=/api/pending_closures20552026/10/06 21:28:02 INFO Aborted multipart uploads count=0 kept=020562026/10/06 21:28:02 WARN Force mode enabled - objects will be deleted immediately without grace period20572026/10/06 21:28:02 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=020582026/10/06 21:28:02 INFO Vacuumed table table=pending_closures20592026/10/06 21:28:02 INFO Vacuumed table table=pending_objects20602026/10/06 21:28:02 INFO Vacuumed table table=multipart_uploads20612026/10/06 21:28:02 INFO Vacuumed table table=closures20622026/10/06 21:28:02 INFO Vacuumed table table=objects20632026/10/06 21:28:02 INFO Received uploads request method=POST path=/api/pending_closures20642026/10/06 21:28:02 INFO Aborted multipart uploads count=0 kept=020652026/10/06 21:28:02 WARN Force mode enabled - objects will be deleted immediately without grace period20662026/10/06 21:28:02 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=020672026/10/06 21:28:02 INFO Vacuumed table table=pending_closures20682026/10/06 21:28:02 INFO Vacuumed table table=pending_objects20692026/10/06 21:28:02 INFO Vacuumed table table=multipart_uploads20702026/10/06 21:28:02 INFO Vacuumed table table=closures20712026/10/06 21:28:02 INFO Vacuumed table table=objects2072--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2073 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (2.26s)2074 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (2.03s)20752026/10/06 21:28:03 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20762026/10/06 21:28:03 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20772026/10/06 21:28:03 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.60030883s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20782026/10/06 21:28:04 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-config20792026/10/06 21:28:05 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=184.566717ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20802026/10/06 21:28:05 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=371.964725ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20812026/10/06 21:28:05 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=827.682743ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20822026/10/06 21:28:06 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.608182929s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20832026/10/06 21:28:08 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"20842026/10/06 21:28:08 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-config20852026/10/06 21:28:08 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=207.311834ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20862026/10/06 21:28:08 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=389.684838ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20872026/10/06 21:28:08 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=858.062461ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20882026/10/06 21:28:09 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.674456769s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20892026/10/06 21:28:11 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_closures20902026/10/06 21:28:11 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=194.291319ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20912026/10/06 21:28:11 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=364.668273ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20922026/10/06 21:28:11 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=747.548399ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20932026/10/06 21:28:12 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.657791821s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2094--- PASS: TestClientErrorHandling (0.00s)2095 --- PASS: TestClientErrorHandling/InvalidStorePath (2.08s)2096 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.13s)2097 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.92s)2098PASS2099{"timestamp":"2026-10-06T21:28:14.381261Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:53848","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(6)"}21002026-10-06 21:28:14.530 UTC [54213] LOG: received smart shutdown request21012026-10-06 21:28:14.531 UTC [54213] LOG: background worker "logical replication launcher" (PID 54223) exited with exit code 121022026-10-06 21:28:14.533 UTC [54218] LOG: shutting down21032026-10-06 21:28:14.533 UTC [54218] LOG: checkpoint starting: shutdown immediate21042026-10-06 21:28:15.852 UTC [54218] LOG: checkpoint complete: wrote 12534 buffers (76.5%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 30 recycled; write=0.689 s, sync=0.577 s, total=1.320 s; sync files=33373, longest=0.001 s, average=0.001 s; distance=492017 kB, estimate=492017 kB; lsn=0/1F809718, redo lsn=0/1F80971821052026-10-06 21:28:15.859 UTC [54213] LOG: database system is shut down2106Running OIDC tests...2107=== RUN TestAudienceForIssuer2108=== PAUSE TestAudienceForIssuer2109=== RUN TestGlobMatch2110=== PAUSE TestGlobMatch2111=== RUN TestValidateToken_ValidToken2112=== PAUSE TestValidateToken_ValidToken2113=== RUN TestValidateToken_WrongAudience2114=== PAUSE TestValidateToken_WrongAudience2115=== RUN TestValidateToken_Expired2116=== PAUSE TestValidateToken_Expired2117=== RUN TestValidateToken_BoundClaimsMismatch2118=== PAUSE TestValidateToken_BoundClaimsMismatch2119=== RUN TestValidateToken_BoundSubjectMismatch2120=== PAUSE TestValidateToken_BoundSubjectMismatch2121=== RUN TestValidateToken_MultipleProviders2122=== PAUSE TestValidateToken_MultipleProviders2123=== RUN TestValidateToken_NoMatchingProvider2124=== PAUSE TestValidateToken_NoMatchingProvider2125=== RUN TestValidateToken_KubernetesServiceAccount2126=== PAUSE TestValidateToken_KubernetesServiceAccount2127=== RUN TestNewValidator_KubernetesRequiresCA2128=== PAUSE TestNewValidator_KubernetesRequiresCA2129=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2130=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2131=== RUN TestPins_ReservedForMatchingRule2132=== PAUSE TestPins_ReservedForMatchingRule2133=== RUN TestPins_TopLevelShorthand2134=== PAUSE TestPins_TopLevelShorthand2135=== RUN TestPins_ConfigValidation2136=== PAUSE TestPins_ConfigValidation2137=== RUN TestScopes_LegacyProviderDefaultsToWrite2138=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2139=== RUN TestScopes_Rules2140=== PAUSE TestScopes_Rules2141=== RUN TestScopes_ConfigValidation2142=== PAUSE TestScopes_ConfigValidation2143=== CONT TestAudienceForIssuer2144--- PASS: TestAudienceForIssuer (0.00s)2145=== CONT TestValidateToken_NoMatchingProvider2146=== CONT TestValidateToken_Expired2147=== CONT TestValidateToken_KubernetesServiceAccount2148=== CONT TestPins_TopLevelShorthand2149=== CONT TestPins_ReservedForMatchingRule2150=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2151=== CONT TestNewValidator_KubernetesRequiresCA2152=== CONT TestValidateToken_ValidToken2153=== CONT TestValidateToken_WrongAudience2154=== CONT TestScopes_Rules21552026/10/06 21:28:17 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12321562026/10/06 21:28:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54008/oidc2157--- PASS: TestValidateToken_WrongAudience (0.04s)2158=== CONT TestScopes_ConfigValidation2159--- PASS: TestScopes_ConfigValidation (0.00s)2160=== CONT TestScopes_LegacyProviderDefaultsToWrite2161--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.04s)2162=== CONT TestGlobMatch2163=== RUN TestGlobMatch/foo_foo2164=== PAUSE TestGlobMatch/foo_foo2165=== RUN TestGlobMatch/foo_bar2166=== PAUSE TestGlobMatch/foo_bar2167=== RUN TestGlobMatch/*_2168=== PAUSE TestGlobMatch/*_2169=== RUN TestGlobMatch/*_anything2170=== PAUSE TestGlobMatch/*_anything2171=== RUN TestGlobMatch/foo*_foo2172=== PAUSE TestGlobMatch/foo*_foo2173=== RUN TestGlobMatch/foo*_foobar2174=== PAUSE TestGlobMatch/foo*_foobar2175=== RUN TestGlobMatch/foo*_bar2176=== PAUSE TestGlobMatch/foo*_bar2177=== RUN TestGlobMatch/*bar_bar2178=== PAUSE TestGlobMatch/*bar_bar2179=== RUN TestGlobMatch/*bar_foobar2180=== PAUSE TestGlobMatch/*bar_foobar2181=== RUN TestGlobMatch/*bar_foo2182=== PAUSE TestGlobMatch/*bar_foo2183=== RUN TestGlobMatch/foo*bar_foobar2184=== PAUSE TestGlobMatch/foo*bar_foobar2185=== RUN TestGlobMatch/foo*bar_foo123bar2186=== PAUSE TestGlobMatch/foo*bar_foo123bar2187=== RUN TestGlobMatch/foo*bar_foobarbaz2188=== PAUSE TestGlobMatch/foo*bar_foobarbaz2189=== RUN TestGlobMatch/*/*_foo/bar2190=== PAUSE TestGlobMatch/*/*_foo/bar2191=== RUN TestGlobMatch/*/*_foo2192=== PAUSE TestGlobMatch/*/*_foo2193=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2194=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2195=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02196=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02197=== RUN TestGlobMatch/refs/*/main_refs/heads/main2198=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2199=== RUN TestGlobMatch/fo?_foo2200=== PAUSE TestGlobMatch/fo?_foo2201=== RUN TestGlobMatch/fo?_fo2202=== PAUSE TestGlobMatch/fo?_fo2203=== RUN TestGlobMatch/fo?_fooo2204=== PAUSE TestGlobMatch/fo?_fooo2205=== RUN TestGlobMatch/?oo_foo2206=== PAUSE TestGlobMatch/?oo_foo2207=== RUN TestGlobMatch/?oo_boo2208=== PAUSE TestGlobMatch/?oo_boo2209=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2210=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2211=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2212=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2213=== CONT TestValidateToken_BoundSubjectMismatch22142026/10/06 21:28:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54011/oidc22152026/10/06 21:28:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54013/oidc2216--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.02s)2217=== CONT TestValidateToken_MultipleProviders22182026/10/06 21:28:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54016/oidc2219--- PASS: TestScopes_Rules (0.06s)2220=== CONT TestValidateToken_BoundClaimsMismatch22212026/10/06 21:28:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54018/oidc22222026/10/06 21:28:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54020/oidc2223--- PASS: TestPins_ReservedForMatchingRule (0.07s)2224=== CONT TestPins_ConfigValidation2225--- PASS: TestPins_TopLevelShorthand (0.07s)2226=== CONT TestGlobMatch/foo_foo2227=== CONT TestGlobMatch/*/*_foo/bar2228=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2229=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2230=== CONT TestGlobMatch/?oo_boo2231=== CONT TestGlobMatch/?oo_foo2232=== CONT TestGlobMatch/fo?_fooo2233=== CONT TestGlobMatch/fo?_fo2234=== CONT TestGlobMatch/fo?_foo2235=== CONT TestGlobMatch/refs/*/main_refs/heads/main2236=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02237=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2238=== CONT TestGlobMatch/*/*_foo2239=== CONT TestGlobMatch/*bar_bar2240=== CONT TestGlobMatch/foo*bar_foobarbaz2241=== CONT TestGlobMatch/foo*bar_foo123bar2242=== CONT TestGlobMatch/foo*bar_foobar2243=== CONT TestGlobMatch/*bar_foo2244=== CONT TestGlobMatch/*bar_foobar2245=== CONT TestGlobMatch/foo*_foo2246=== CONT TestGlobMatch/foo*_bar2247=== CONT TestGlobMatch/foo*_foobar2248=== CONT TestGlobMatch/*_2249=== CONT TestGlobMatch/*_anything2250=== CONT TestGlobMatch/foo_bar2251--- PASS: TestGlobMatch (0.00s)2252 --- PASS: TestGlobMatch/foo_foo (0.00s)2253 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2254 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2255 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2256 --- PASS: TestGlobMatch/?oo_boo (0.00s)2257 --- PASS: TestGlobMatch/?oo_foo (0.00s)2258 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2259 --- PASS: TestGlobMatch/fo?_fo (0.00s)2260 --- PASS: TestGlobMatch/fo?_foo (0.00s)2261 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2262 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2263 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2264 --- PASS: TestGlobMatch/*/*_foo (0.00s)2265 --- PASS: TestGlobMatch/*bar_bar (0.00s)2266 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2267 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2268 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2269 --- PASS: TestGlobMatch/*bar_foo (0.00s)2270 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2271 --- PASS: TestGlobMatch/foo*_foo (0.00s)2272 --- PASS: TestGlobMatch/foo*_bar (0.00s)2273 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2274 --- PASS: TestGlobMatch/*_ (0.00s)2275 --- PASS: TestGlobMatch/*_anything (0.00s)2276 --- PASS: TestGlobMatch/foo_bar (0.00s)2277--- PASS: TestPins_ConfigValidation (0.00s)2278--- PASS: TestValidateToken_Expired (0.07s)22792026/10/06 21:28:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54022/oidc2280--- PASS: TestValidateToken_ValidToken (0.07s)22812026/10/06 21:28:17 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:5402422822026/10/06 21:28:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54026/oidc2283--- PASS: TestValidateToken_KubernetesServiceAccount (0.09s)2284--- PASS: TestValidateToken_BoundClaimsMismatch (0.03s)22852026/10/06 21:28:17 http: TLS handshake error from 127.0.0.1:54030: remote error: tls: bad certificate2286--- PASS: TestNewValidator_KubernetesRequiresCA (0.11s)22872026/10/06 21:28:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54031/oidc2288--- PASS: TestValidateToken_BoundSubjectMismatch (0.07s)22892026/10/06 21:28:17 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:54015/oidc2290--- PASS: TestValidateToken_NoMatchingProvider (0.13s)22912026/10/06 21:28:17 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:54035/oidc22922026/10/06 21:28:17 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:54036/oidc2293--- PASS: TestValidateToken_MultipleProviders (0.14s)2294PASS2295Running hook tests...2296=== RUN TestSendPathsEmpty2297=== PAUSE TestSendPathsEmpty2298=== RUN TestQueueEnqueueAndFetch2299=== PAUSE TestQueueEnqueueAndFetch2300=== RUN TestQueueDeduplication2301=== PAUSE TestQueueDeduplication2302=== RUN TestQueueRemove2303=== PAUSE TestQueueRemove2304=== RUN TestQueueFetchBatchLimit2305=== PAUSE TestQueueFetchBatchLimit2306=== RUN TestQueueRetryMovesToBack2307=== PAUSE TestQueueRetryMovesToBack2308=== RUN TestQueueFetchRemoveLifecycle2309=== PAUSE TestQueueFetchRemoveLifecycle2310=== RUN TestQueueConcurrentWriters2311=== PAUSE TestQueueConcurrentWriters2312=== RUN TestQueueRemoveLargeClosure2313=== PAUSE TestQueueRemoveLargeClosure2314=== RUN TestServerClientIntegration2315=== PAUSE TestServerClientIntegration2316=== RUN TestServerQueueError2317=== PAUSE TestServerQueueError2318=== RUN TestGetListenerSocketActivation2319 server_test.go:210: === RUN TestGetListenerSocketActivation2320 --- PASS: TestGetListenerSocketActivation (0.00s)2321 PASS2322 2323--- PASS: TestGetListenerSocketActivation (0.01s)2324=== RUN TestDrainIsolatesPoisonPath2325=== PAUSE TestDrainIsolatesPoisonPath2326=== RUN TestRunNotBlockedByPoisonHead2327=== PAUSE TestRunNotBlockedByPoisonHead2328=== RUN TestDrainGivesUpWhenServerDown2329=== PAUSE TestDrainGivesUpWhenServerDown2330=== RUN TestFailedPathPrunedByLaterClosure2331=== PAUSE TestFailedPathPrunedByLaterClosure2332=== RUN TestWorkerUploadsAndRemoves2333=== PAUSE TestWorkerUploadsAndRemoves2334=== RUN TestWorkerSkipsGCdPaths2335=== PAUSE TestWorkerSkipsGCdPaths2336=== RUN TestWorkerPrunesClosureDeps2337=== PAUSE TestWorkerPrunesClosureDeps2338=== RUN TestDrainTimeout2339=== PAUSE TestDrainTimeout2340=== CONT TestSendPathsEmpty2341--- PASS: TestSendPathsEmpty (0.00s)2342=== CONT TestServerQueueError2343=== CONT TestQueueRetryMovesToBack2344=== CONT TestQueueFetchBatchLimit2345=== CONT TestQueueRemove2346=== CONT TestQueueDeduplication2347=== CONT TestQueueEnqueueAndFetch2348=== CONT TestWorkerUploadsAndRemoves2349=== CONT TestDrainTimeout2350=== CONT TestWorkerPrunesClosureDeps2351=== CONT TestWorkerSkipsGCdPaths23522026/10/06 21:28:17 ERROR Failed to queue paths error="permission denied" count=12353--- PASS: TestServerQueueError (0.00s)2354=== CONT TestDrainGivesUpWhenServerDown23552026/10/06 21:28:17 INFO Upload queue status pending=223562026/10/06 21:28:17 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-54176-1079888160/TestWorkerSkipsGCdPaths1070065047/002/nonexistent23572026/10/06 21:28:17 INFO Uploading batch count=223582026/10/06 21:28:17 INFO Upload queue status pending=223592026/10/06 21:28:17 INFO Uploading batch count=12360--- PASS: TestQueueEnqueueAndFetch (0.01s)2361=== CONT TestFailedPathPrunedByLaterClosure23622026/10/06 21:28:17 INFO Uploading batch count=223632026/10/06 21:28:17 INFO Uploading batch count=22364--- PASS: TestQueueFetchBatchLimit (0.01s)2365=== CONT TestQueueRemoveLargeClosure23662026/10/06 21:28:17 ERROR Upload failed error="upload failed" count=223672026/10/06 21:28:17 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-54176-1079888160/TestDrainGivesUpWhenServerDown76184480/002/a23682026/10/06 21:28:17 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-54176-1079888160/TestDrainGivesUpWhenServerDown76184480/002/b23692026/10/06 21:28:17 INFO Upload queue status pending=223702026/10/06 21:28:17 INFO Uploading batch count=223712026/10/06 21:28:17 ERROR Upload failed error="upload failed" count=223722026/10/06 21:28:17 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-54176-1079888160/TestDrainGivesUpWhenServerDown76184480/002/c23732026/10/06 21:28:17 INFO Uploading batch count=123742026/10/06 21:28:17 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-54176-1079888160/TestDrainGivesUpWhenServerDown76184480/002/d2375--- PASS: TestQueueDeduplication (0.01s)2376=== CONT TestServerClientIntegration2377--- PASS: TestQueueRemove (0.01s)2378=== CONT TestQueueConcurrentWriters2379--- PASS: TestQueueRetryMovesToBack (0.01s)2380=== CONT TestRunNotBlockedByPoisonHead23812026/10/06 21:28:17 INFO Uploading batch count=223822026/10/06 21:28:17 ERROR Upload failed error="upload failed" count=223832026/10/06 21:28:17 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-54176-1079888160/TestDrainGivesUpWhenServerDown76184480/002/e23842026/10/06 21:28:17 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-54176-1079888160/TestDrainGivesUpWhenServerDown76184480/002/f2385--- PASS: TestServerClientIntegration (0.00s)2386=== CONT TestQueueFetchRemoveLifecycle23872026/10/06 21:28:17 ERROR Drain finished with paths left in queue remaining=1023882026/10/06 21:28:17 INFO Uploading batch count=123892026/10/06 21:28:17 ERROR Upload failed error="upload failed" count=123902026/10/06 21:28:17 INFO Uploading batch count=123912026/10/06 21:28:17 INFO Uploading batch count=123922026/10/06 21:28:17 INFO Upload queue status pending=323932026/10/06 21:28:17 INFO Uploading batch count=123942026/10/06 21:28:17 ERROR Upload failed error="upload failed" count=12395--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2396=== CONT TestDrainIsolatesPoisonPath2397--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)2398--- PASS: TestQueueFetchRemoveLifecycle (0.00s)23992026/10/06 21:28:17 INFO Uploading batch count=424002026/10/06 21:28:17 ERROR Upload failed error="upload failed" count=424012026/10/06 21:28:17 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-54176-1079888160/TestDrainIsolatesPoisonPath1439064430/002/bbb24022026/10/06 21:28:17 INFO Uploading batch count=124032026/10/06 21:28:17 ERROR Upload failed error="upload failed" count=124042026/10/06 21:28:17 INFO Uploading batch count=124052026/10/06 21:28:17 ERROR Upload failed error="upload failed" count=124062026/10/06 21:28:17 INFO Uploading batch count=124072026/10/06 21:28:17 ERROR Upload failed error="upload failed" count=124082026/10/06 21:28:17 ERROR Drain finished with paths left in queue remaining=12409--- PASS: TestDrainIsolatesPoisonPath (0.00s)2410--- PASS: TestWorkerUploadsAndRemoves (0.03s)2411--- PASS: TestWorkerSkipsGCdPaths (0.03s)2412--- PASS: TestWorkerPrunesClosureDeps (0.03s)2413--- PASS: TestQueueRemoveLargeClosure (0.03s)2414--- PASS: TestQueueConcurrentWriters (0.15s)24152026/10/06 21:28:18 ERROR Upload failed error="context deadline exceeded" count=224162026/10/06 21:28:18 ERROR Drain finished with paths left in queue remaining=42417--- PASS: TestDrainTimeout (0.21s)24182026/10/06 21:28:18 INFO Uploading batch count=124192026/10/06 21:28:18 INFO Uploading batch count=124202026/10/06 21:28:18 INFO Uploading batch count=124212026/10/06 21:28:18 ERROR Upload failed error="upload failed" count=124222026/10/06 21:28:18 INFO Uploading batch count=124232026/10/06 21:28:18 ERROR Upload failed error="upload failed" count=124242026/10/06 21:28:18 INFO Uploading batch count=124252026/10/06 21:28:18 ERROR Upload failed error="upload failed" count=124262026/10/06 21:28:18 INFO Uploading batch count=124272026/10/06 21:28:18 ERROR Upload failed error="upload failed" count=124282026/10/06 21:28:18 ERROR Drain finished with paths left in queue remaining=12429--- PASS: TestRunNotBlockedByPoisonHead (1.01s)2430PASS2431Running signing tests...2432=== RUN TestExternalSigner2433=== PAUSE TestExternalSigner2434=== RUN TestExternalSignerWrongPublicKey2435=== PAUSE TestExternalSignerWrongPublicKey2436=== RUN TestExternalSignerErrors2437=== PAUSE TestExternalSignerErrors2438=== RUN TestExternalSignerRestartsAfterCrash2439=== PAUSE TestExternalSignerRestartsAfterCrash2440=== RUN TestExternalSignerProgramErrorKeepsProcess2441=== PAUSE TestExternalSignerProgramErrorKeepsProcess2442=== RUN TestExternalSignerClose2443=== PAUSE TestExternalSignerClose2444=== RUN TestExternalSignerRejectsInvalidPublicKey2445=== PAUSE TestExternalSignerRejectsInvalidPublicKey2446=== RUN TestExternalSignerCancellation2447=== PAUSE TestExternalSignerCancellation2448=== RUN TestGenerateFingerprint2449=== PAUSE TestGenerateFingerprint2450=== RUN TestParseSigningKey2451=== PAUSE TestParseSigningKey2452=== RUN TestSign2453=== PAUSE TestSign2454=== RUN TestSignBatch2455=== PAUSE TestSignBatch2456=== RUN TestNilKeyPublicKey2457=== PAUSE TestNilKeyPublicKey2458=== RUN TestSignErrors2459=== PAUSE TestSignErrors2460=== CONT TestExternalSigner2461=== CONT TestExternalSignerCancellation2462=== CONT TestExternalSignerProgramErrorKeepsProcess2463=== CONT TestSignBatch2464=== CONT TestExternalSignerErrors2465=== CONT TestExternalSignerWrongPublicKey2466=== RUN TestExternalSignerErrors/exit_on_request2467=== PAUSE TestExternalSignerErrors/exit_on_request2468=== RUN TestExternalSignerErrors/invalid_JSON2469=== PAUSE TestExternalSignerErrors/invalid_JSON2470=== RUN TestExternalSignerErrors/wrong_shape2471=== PAUSE TestExternalSignerErrors/wrong_shape2472=== RUN TestExternalSignerErrors/wrong_id2473=== PAUSE TestExternalSignerErrors/wrong_id2474=== RUN TestExternalSignerErrors/missing_signatures2475=== CONT TestExternalSignerRestartsAfterCrash2476=== PAUSE TestExternalSignerErrors/missing_signatures2477=== RUN TestExternalSignerErrors/null_signatures2478=== PAUSE TestExternalSignerErrors/null_signatures2479=== RUN TestExternalSignerErrors/wrong_signatures_shape2480=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2481=== RUN TestExternalSignerErrors/wrong_signature_name2482=== PAUSE TestExternalSignerErrors/wrong_signature_name2483=== RUN TestExternalSignerErrors/too_few_signatures2484=== PAUSE TestExternalSignerErrors/too_few_signatures2485=== RUN TestExternalSignerErrors/missing_signature_name2486=== PAUSE TestExternalSignerErrors/missing_signature_name2487=== RUN TestExternalSignerErrors/program_error2488=== PAUSE TestExternalSignerErrors/program_error2489=== RUN TestExternalSignerErrors/null2490=== PAUSE TestExternalSignerErrors/null2491=== RUN TestExternalSignerErrors/invalid_signature_base642492=== PAUSE TestExternalSignerErrors/invalid_signature_base642493=== RUN TestExternalSignerErrors/exit_at_startup2494=== PAUSE TestExternalSignerErrors/exit_at_startup2495=== RUN TestExternalSignerErrors/unrequested_key2496=== PAUSE TestExternalSignerErrors/unrequested_key2497=== RUN TestExternalSignerErrors/wrong_signature_length2498=== PAUSE TestExternalSignerErrors/wrong_signature_length2499=== CONT TestParseSigningKey2500=== RUN TestParseSigningKey/valid_32-byte_key2501=== PAUSE TestParseSigningKey/valid_32-byte_key2502=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2503=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2504=== RUN TestParseSigningKey/no_colon2505=== PAUSE TestParseSigningKey/no_colon2506=== RUN TestParseSigningKey/empty_name2507=== PAUSE TestParseSigningKey/empty_name2508=== RUN TestParseSigningKey/invalid_base642509=== PAUSE TestParseSigningKey/invalid_base642510=== RUN TestParseSigningKey/wrong_length2511=== PAUSE TestParseSigningKey/wrong_length2512=== CONT TestExternalSignerClose2513=== CONT TestSignErrors2514=== CONT TestSign2515=== CONT TestExternalSignerRejectsInvalidPublicKey2516=== RUN TestExternalSignerRejectsInvalidPublicKey/#002517=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002518=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2519=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2520=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2521=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2522=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2523=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2524=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2525=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2526=== CONT TestGenerateFingerprint2527=== RUN TestGenerateFingerprint/basic_with_references2528=== PAUSE TestGenerateFingerprint/basic_with_references2529=== RUN TestGenerateFingerprint/no_references2530=== PAUSE TestGenerateFingerprint/no_references2531=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2532=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2533=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2534=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2535=== RUN TestGenerateFingerprint/invalid_nar_hash_length2536=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2537=== RUN TestGenerateFingerprint/invalid_store_path_prefix2538=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2539=== RUN TestGenerateFingerprint/invalid_reference_prefix2540=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2541=== CONT TestNilKeyPublicKey2542--- PASS: TestNilKeyPublicKey (0.00s)2543=== CONT TestExternalSignerErrors/exit_on_request2544=== RUN TestSignErrors/nil_key2545--- PASS: TestSign (0.00s)2546=== CONT TestParseSigningKey/valid_32-byte_key2547=== PAUSE TestSignErrors/nil_key2548=== RUN TestSignErrors/nil_narinfo2549=== PAUSE TestSignErrors/nil_narinfo2550=== CONT TestExternalSignerErrors/null_signatures2551=== RUN TestSignErrors/invalid_narinfo2552=== PAUSE TestSignErrors/invalid_narinfo2553--- PASS: TestSignBatch (0.01s)2554=== CONT TestExternalSignerErrors/wrong_signature_length2555=== RUN TestSignErrors/canceled2556=== PAUSE TestSignErrors/canceled2557=== CONT TestExternalSignerErrors/unrequested_key2558--- PASS: TestExternalSignerCancellation (0.23s)2559=== CONT TestExternalSignerErrors/exit_at_startup2560--- PASS: TestExternalSignerWrongPublicKey (0.40s)2561=== CONT TestExternalSignerErrors/invalid_signature_base642562--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.59s)2563=== CONT TestExternalSignerErrors/null2564--- PASS: TestExternalSignerRestartsAfterCrash (0.79s)2565=== CONT TestExternalSignerErrors/program_error2566/nix/var/nix/builds/nix-54176-1079888160/TestExternalSignerRestartsAfterCrash2589510170/001/sign program: line 7: /nix/var/nix/builds/nix-54176-1079888160/TestExternalSignerRestartsAfterCrash2589510170/001/sign program.starts: No such file or directory2567--- PASS: TestExternalSigner (0.97s)2568=== CONT TestExternalSignerErrors/missing_signature_name2569--- PASS: TestExternalSignerClose (1.15s)2570=== CONT TestExternalSignerErrors/too_few_signatures2571=== CONT TestExternalSignerErrors/wrong_signature_name2572=== CONT TestExternalSignerErrors/wrong_signatures_shape2573=== CONT TestExternalSignerErrors/missing_signatures2574=== CONT TestExternalSignerErrors/wrong_id2575=== CONT TestExternalSignerErrors/wrong_shape2576=== CONT TestExternalSignerErrors/invalid_JSON2577=== CONT TestParseSigningKey/empty_name2578=== CONT TestParseSigningKey/wrong_length2579=== CONT TestParseSigningKey/invalid_base642580=== CONT TestParseSigningKey/no_colon2581=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2582--- PASS: TestParseSigningKey (0.00s)2583 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2584 --- PASS: TestParseSigningKey/empty_name (0.00s)2585 --- PASS: TestParseSigningKey/wrong_length (0.00s)2586 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2587 --- PASS: TestParseSigningKey/no_colon (0.00s)2588 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2589=== CONT TestExternalSignerRejectsInvalidPublicKey/#002590=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2591=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2592=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2593=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2594--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2595 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2596 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2597 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2598 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2599 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2600=== CONT TestGenerateFingerprint/basic_with_references2601=== CONT TestGenerateFingerprint/invalid_nar_hash_length2602=== CONT TestGenerateFingerprint/invalid_reference_prefix2603=== CONT TestGenerateFingerprint/invalid_store_path_prefix2604=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2605=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2606=== CONT TestGenerateFingerprint/no_references2607--- PASS: TestGenerateFingerprint (0.00s)2608 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2609 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2610 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2611 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2612 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2613 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2614 --- PASS: TestGenerateFingerprint/no_references (0.00s)2615=== CONT TestSignErrors/nil_key2616=== CONT TestSignErrors/invalid_narinfo2617=== CONT TestSignErrors/canceled2618=== CONT TestSignErrors/nil_narinfo2619--- PASS: TestSignErrors (0.00s)2620 --- PASS: TestSignErrors/nil_key (0.00s)2621 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2622 --- PASS: TestSignErrors/canceled (0.00s)2623 --- PASS: TestSignErrors/nil_narinfo (0.00s)2624--- PASS: TestExternalSignerErrors (0.00s)2625 --- PASS: TestExternalSignerErrors/exit_on_request (1.34s)2626 --- PASS: TestExternalSignerErrors/wrong_signature_length (1.52s)2627 --- PASS: TestExternalSignerErrors/null_signatures (1.95s)2628 --- PASS: TestExternalSignerErrors/unrequested_key (2.14s)2629 --- PASS: TestExternalSignerErrors/exit_at_startup (2.10s)2630 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (2.12s)2631 --- PASS: TestExternalSignerErrors/null (2.12s)2632 --- PASS: TestExternalSignerErrors/program_error (2.10s)2633 --- PASS: TestExternalSignerErrors/missing_signature_name (2.20s)2634 --- PASS: TestExternalSignerErrors/too_few_signatures (2.16s)2635 --- PASS: TestExternalSignerErrors/wrong_signature_name (2.16s)2636 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (2.17s)2637 --- PASS: TestExternalSignerErrors/missing_signatures (1.93s)2638 --- PASS: TestExternalSignerErrors/wrong_id (1.93s)2639 --- PASS: TestExternalSignerErrors/wrong_shape (1.93s)2640 --- PASS: TestExternalSignerErrors/invalid_JSON (1.92s)2641PASS2642Running OpenBao signer tests...2643=== RUN TestSign2644=== PAUSE TestSign2645=== RUN TestSignErrors2646=== PAUSE TestSignErrors2647=== RUN TestServe2648=== PAUSE TestServe2649=== RUN TestServeRejectsGarbage2650=== PAUSE TestServeRejectsGarbage2651=== CONT TestSign2652=== CONT TestServe2653=== CONT TestServeRejectsGarbage2654--- PASS: TestServeRejectsGarbage (0.00s)2655=== CONT TestSignErrors2656=== RUN TestSignErrors/http_error2657=== PAUSE TestSignErrors/http_error2658=== RUN TestSignErrors/invalid_json2659=== PAUSE TestSignErrors/invalid_json2660=== RUN TestSignErrors/no_prefix2661=== PAUSE TestSignErrors/no_prefix2662=== RUN TestSignErrors/invalid_base642663=== PAUSE TestSignErrors/invalid_base642664=== CONT TestSignErrors/http_error2665=== CONT TestSignErrors/no_prefix2666=== CONT TestSignErrors/invalid_json2667=== CONT TestSignErrors/invalid_base642668--- PASS: TestServe (0.00s)2669--- PASS: TestSign (0.00s)2670--- PASS: TestSignErrors (0.00s)2671 --- PASS: TestSignErrors/invalid_base64 (0.00s)2672 --- PASS: TestSignErrors/http_error (0.00s)2673 --- PASS: TestSignErrors/no_prefix (0.00s)2674 --- PASS: TestSignErrors/invalid_json (0.00s)2675PASS