niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #364
· 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.11s)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 TestShellSplit100=== CONT TestSetClientTLSErrors101=== CONT TestStreamPushRequestLine102=== CONT TestSetClientTLSDoesNotMutateDefaultTransport103=== CONT TestSetClientTLS104=== CONT TestClientSignaturesByStorePath105=== CONT TestScriptTokenBadJSON106=== CONT TestStreamPushReportsSignatures107=== CONT TestScriptTokenCachesUntilRefresh108=== CONT TestScriptTokenEmptyCommand109=== CONT TestScriptTokenEmptyToken110--- PASS: TestShellSplit (0.00s)1112026/10/06 08:16:58 ERROR Upload failed error=boom count=1112=== CONT TestScriptTokenScriptFails113--- PASS: TestClientSignaturesByStorePath (0.00s)114--- PASS: TestScriptTokenEmptyCommand (0.00s)115=== RUN TestSetClientTLSErrors/missing_cert_file116--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)117=== CONT TestUploadMultipart_PartsInParallel1182026/10/06 08:16:58 ERROR Upload failed error=boom count=1119=== RUN TestSetClientTLS/rejects_connection_without_client_cert120--- PASS: TestScriptTokenScriptFails (0.01s)121=== PAUSE TestSetClientTLSErrors/missing_cert_file122=== RUN TestSetClientTLSErrors/missing_key_file123=== PAUSE TestSetClientTLSErrors/missing_key_file124=== RUN TestSetClientTLSErrors/missing_ca_file125=== PAUSE TestSetClientTLSErrors/missing_ca_file126=== RUN TestSetClientTLSErrors/invalid_ca_file127=== PAUSE TestSetClientTLSErrors/invalid_ca_file128--- PASS: TestStreamPushReportsSignatures (0.01s)129=== CONT TestDumpPathSingleFile130=== CONT TestDumpPathMatchesNix131=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert132=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA133=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA134=== RUN TestSetClientTLS/preserves_debug_logging_transport135=== PAUSE TestSetClientTLS/preserves_debug_logging_transport136=== CONT TestDumpPathWriterError137=== CONT TestUploadMultipart_SupersededByPeer138=== RUN TestUploadMultipart_SupersededByPeer/exists139=== PAUSE TestUploadMultipart_SupersededByPeer/exists140=== RUN TestUploadMultipart_SupersededByPeer/missing141=== PAUSE TestUploadMultipart_SupersededByPeer/missing142=== CONT TestPartSizeForNAR143=== RUN TestPartSizeForNAR/zero_stays_at_minimum144=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum145=== RUN TestPartSizeForNAR/small_stays_at_minimum146=== PAUSE TestPartSizeForNAR/small_stays_at_minimum147=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum148=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum149=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts150=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts151=== RUN TestPartSizeForNAR/1_TiB152=== PAUSE TestPartSizeForNAR/1_TiB153=== RUN TestPartSizeForNAR/5_TiB_S3_max_object154=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object155=== RUN TestPartSizeForNAR/capped_at_5_GiB156=== PAUSE TestPartSizeForNAR/capped_at_5_GiB157=== CONT TestParsePathInfoJSONMultiplePaths158=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths159=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths160=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths161=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths162=== CONT TestDoWithRetry_BodyReplayedViaGetBody163--- PASS: TestDoServerRequestAttachesToken (0.01s)164=== CONT TestResolveStorePath165--- PASS: TestResolveStorePath (0.00s)166--- PASS: TestScriptTokenBadJSON (0.01s)167=== CONT TestRateLimiterFeedback168=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess169=== RUN TestRateLimiterFeedback/429_enables_limiter170=== PAUSE TestRateLimiterFeedback/429_enables_limiter171=== RUN TestRateLimiterFeedback/503_enables_limiter172=== PAUSE TestRateLimiterFeedback/503_enables_limiter173=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter174=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter175=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter176=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter177=== CONT TestPathInfoCACompatibility178=== RUN TestPathInfoCACompatibility/null_ca_field179=== PAUSE TestPathInfoCACompatibility/null_ca_field180=== RUN TestPathInfoCACompatibility/old_string_format_-_text181=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text182=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive183=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive184=== RUN TestPathInfoCACompatibility/new_structured_format_-_text185=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text186=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method187=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method188=== CONT TestFileTokenMissing1892026/10/06 08:16:58 WARN Rate limiter enabled after throttle name=server-test rate=5190--- PASS: TestFileTokenMissing (0.00s)191=== CONT TestScriptTokenNoExpiryRerunsEveryCall1922026/10/06 08:16:58 WARN Rate limiter enabled after throttle name=server-test rate=51932026/10/06 08:16:58 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:650031942026/10/06 08:16:58 WARN Rate limiter backed off name=server-test rate=51952026/10/06 08:16:58 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:65003196--- PASS: TestScriptTokenEmptyToken (0.02s)197=== CONT TestFileTokenEmpty198--- PASS: TestFileTokenEmpty (0.00s)199--- PASS: TestStreamPushRequestLine (0.02s)200=== CONT TestParsePathInfoJSON201=== RUN TestParsePathInfoJSON/Nix_format202=== PAUSE TestParsePathInfoJSON/Nix_format203=== RUN TestParsePathInfoJSON/Lix_format204=== PAUSE TestParsePathInfoJSON/Lix_format205=== RUN TestParsePathInfoJSON/empty_input206=== PAUSE TestParsePathInfoJSON/empty_input207=== RUN TestParsePathInfoJSON/whitespace_only208=== PAUSE TestParsePathInfoJSON/whitespace_only209=== RUN TestParsePathInfoJSON/invalid_JSON210=== PAUSE TestParsePathInfoJSON/invalid_JSON211=== CONT TestPathInfoHashCompatibility212=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)213=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)214=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon215=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon216=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI217=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI218=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512219=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512220--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)221=== CONT TestStreamPushGivesUpOnDeadServer222=== CONT TestStreamPushBatchesUnderLoad223=== CONT TestGetStorePathHash224=== RUN TestGetStorePathHash/valid_store_path225=== PAUSE TestGetStorePathHash/valid_store_path226=== RUN TestGetStorePathHash/basename_without_hyphen_should_error227=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error228=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error229=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error230=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error231=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error232=== CONT TestStreamPushReportsEveryPath2332026/10/06 08:16:58 ERROR Upload failed error="connection refused" count=202342026/10/06 08:16:58 ERROR Server seems unavailable, giving up on batch untried=17235--- PASS: TestStreamPushReportsEveryPath (0.00s)236--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)237=== CONT TestStreamPushIsolatesFailures238=== CONT TestFileTokenReadsAndCaches2392026/10/06 08:16:58 ERROR Upload failed error="bad path" count=3240--- PASS: TestStreamPushIsolatesFailures (0.00s)241=== CONT TestStaticToken242--- PASS: TestStaticToken (0.00s)243=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun244--- PASS: TestFileTokenReadsAndCaches (0.00s)245=== CONT TestConvertHashToNix32246=== RUN TestConvertHashToNix32/SRI_format_to_Nix32247=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32248=== RUN TestConvertHashToNix32/already_Nix32_format249=== PAUSE TestConvertHashToNix32/already_Nix32_format250=== RUN TestConvertHashToNix32/invalid_format251=== PAUSE TestConvertHashToNix32/invalid_format252=== CONT TestFilterOversizedClosures253=== RUN TestFilterOversizedClosures/no_limit_keeps_everything254=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything255=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped256=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped257=== RUN TestFilterOversizedClosures/all_closures_skipped258=== PAUSE TestFilterOversizedClosures/all_closures_skipped259=== CONT TestCaseHackSuffix2602026/10/06 08:16:58 INFO Garbage collection started261--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)262=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica2632026/10/06 08:16:58 INFO Garbage collection started2642026/10/06 08:16:58 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=02652026/10/06 08:16:58 WARN Garbage collection finished on another replica. Its statistics are not available here266--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)267=== CONT TestShellSplitErrors268--- PASS: TestShellSplitErrors (0.00s)269=== CONT TestRegisterUploadedObjectReusesConnections270--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)271=== CONT TestEncodeNixBase32WithRealHash272--- PASS: TestEncodeNixBase32WithRealHash (0.00s)273=== CONT TestEncodeNixBase32274=== RUN TestEncodeNixBase32/test_string_hash275=== PAUSE TestEncodeNixBase32/test_string_hash276=== RUN TestEncodeNixBase32/empty_input277=== PAUSE TestEncodeNixBase32/empty_input278=== CONT TestSetClientTLSErrors/missing_cert_file279=== CONT TestSetClientTLSErrors/invalid_ca_file280=== CONT TestSetClientTLSErrors/missing_ca_file281=== CONT TestSetClientTLSErrors/missing_key_file282--- PASS: TestSetClientTLSErrors (0.01s)283 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)284 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)285 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)286 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)287=== CONT TestSetClientTLS/rejects_connection_without_client_cert288--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)289=== CONT TestSetClientTLS/preserves_debug_logging_transport290--- PASS: TestDumpPathWriterError (0.05s)291=== CONT TestUploadMultipart_SupersededByPeer/exists292=== CONT TestPartSizeForNAR/zero_stays_at_minimum293=== CONT TestUploadMultipart_SupersededByPeer/missing294=== CONT TestPartSizeForNAR/1_TiB295=== CONT TestPartSizeForNAR/capped_at_5_GiB296=== CONT TestPartSizeForNAR/5_TiB_S3_max_object297=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum298=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts299=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA300--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)301 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)302 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)303=== CONT TestPartSizeForNAR/small_stays_at_minimum304--- PASS: TestPartSizeForNAR (0.00s)305 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)306 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)307 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)308 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)309 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)310 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)311 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)312=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths313=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths314--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)315 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)316 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)317=== CONT TestRateLimiterFeedback/429_enables_limiter3182026/10/06 08:16:58 WARN Rate limiter enabled after throttle name=server-test rate=53192026/10/06 08:16:58 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:650873202026/10/06 08:16:58 WARN Rate limiter backed off name=server-test rate=5321=== CONT TestPathInfoCACompatibility/null_ca_field322=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter3232026/10/06 08:16:58 http: TLS handshake error from 127.0.0.1:65080: remote error: tls: bad certificate324=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter325=== CONT TestRateLimiterFeedback/503_enables_limiter326=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method327=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive328=== CONT TestPathInfoCACompatibility/old_string_format_-_text329=== CONT TestPathInfoCACompatibility/new_structured_format_-_text330--- PASS: TestPathInfoCACompatibility (0.00s)331 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)332 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)333 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)334 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)335 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)336=== CONT TestParsePathInfoJSON/Nix_format337=== CONT TestParsePathInfoJSON/whitespace_only338=== CONT TestParsePathInfoJSON/invalid_JSON339=== CONT TestParsePathInfoJSON/empty_input340=== CONT TestParsePathInfoJSON/Lix_format341=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)342=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512343=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI344=== CONT TestGetStorePathHash/valid_store_path345--- PASS: TestParsePathInfoJSON (0.00s)346 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)347 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)348 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)349 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)350 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)351=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error352=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error353=== CONT TestGetStorePathHash/basename_without_hyphen_should_error354=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon355=== CONT TestConvertHashToNix32/invalid_format356=== CONT TestConvertHashToNix32/already_Nix32_format357=== CONT TestFilterOversizedClosures/no_limit_keeps_everything358=== CONT TestFilterOversizedClosures/all_closures_skipped3592026/10/06 08:16:58 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=50360=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3612026/10/06 08:16:58 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=2000362=== CONT TestEncodeNixBase32/test_string_hash363=== CONT TestEncodeNixBase32/empty_input364--- PASS: TestGetStorePathHash (0.00s)365 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)366 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)367 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)368 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)369--- PASS: TestPathInfoHashCompatibility (0.00s)370 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)371 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)372 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)373 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)374=== CONT TestConvertHashToNix32/SRI_format_to_Nix32375--- PASS: TestConvertHashToNix32 (0.00s)376 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)377 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)378 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)379--- PASS: TestFilterOversizedClosures (0.00s)380 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)381 --- PASS: TestFilterOv2026/10/06 08:16:58 WARN Rate limiter enabled after throttle name=server-test rate=5382ersizedClosures/all_closures_skipped (0.00s)383 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)3842026/10/06 08:16:58 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:65093385--- PASS: TestEncodeNixBase32 (0.00s)386 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)387 --- PASS: TestEncodeNixBase32/empty_input (0.00s)388--- PASS: TestSetClientTLS (0.01s)389 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)390 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)391 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)3922026/10/06 08:16:58 WARN Rate limiter backed off name=server-test rate=5393--- PASS: TestRateLimiterFeedback (0.00s)394 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)395 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)396 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)397 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)398--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)399--- PASS: TestCaseHackSuffix (0.05s)400--- PASS: TestDumpPathSingleFile (0.07s)401--- PASS: TestDumpPathMatchesNix (0.09s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestUploadMultipart_PartsInParallel (0.62s)404--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)405PASS406Running server tests...407The files belonging to this database system will be owned by user "_nixbld13".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-49438-1596666667/postgres1123097233/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-49438-1596666667/postgres1123097233/data -l logfile start4334342026-10-06 08:17:02.079 UTC [49627] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4352026-10-06 08:17:02.079 UTC [49627] LOG: listening on Unix socket "/nix/var/nix/builds/nix-49438-1596666667/postgres1123097233/.s.PGSQL.5432"4362026-10-06 08:17:02.081 UTC [49637] LOG: database system was shut down at 2026-10-06 08:17:02 UTC4372026-10-06 08:17:02.081 UTC [49638] FATAL: the database system is starting up438/nix/var/nix/builds/nix-49438-1596666667/postgres1123097233:5432 - rejecting connections4392026-10-06 08:17:02.082 UTC [49627] LOG: database system is ready to accept connections440/nix/var/nix/builds/nix-49438-1596666667/postgres1123097233:5432 - accepting connections441{"timestamp":"2026-10-06T08:17:02.456513Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"38c4f1c1-5084-499b-9381-94abeb1c2bbb","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":26,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(4)"}442{"timestamp":"2026-10-06T08:17:02.563618Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"5bb1e92e-87a7-4b8c-b216-dd0b89d1cd97","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(4)"}443{"timestamp":"2026-10-06T08:17:02.666308Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"fd0114ea-e808-4ca7-ae6f-d9bfb657a77b","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(7)"}444{"timestamp":"2026-10-06T08:17:02.769518Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"85bc11e7-4d67-43cb-9f89-4157d2b57c66","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":1,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(6)"}445=== RUN TestService_AuthMiddleware446=== PAUSE TestService_AuthMiddleware447=== RUN TestService_AuthMiddleware_MTLSProxyHeader448=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader449=== RUN TestService_AuthMiddleware_MTLSBoundSubjects450=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects451=== RUN TestService_ReadAuthMiddleware452=== PAUSE TestService_ReadAuthMiddleware453=== RUN TestService_AuthMiddleware_OIDC454=== PAUSE TestService_AuthMiddleware_OIDC455=== RUN TestService_RequireScope_OIDC456=== PAUSE TestService_RequireScope_OIDC457=== RUN TestService_ReadScope_PublicByDefault458=== PAUSE TestService_ReadScope_PublicByDefault459=== RUN TestCacheConfigHandler460=== PAUSE TestCacheConfigHandler461=== RUN TestCacheStatsHandler462=== PAUSE TestCacheStatsHandler463=== RUN TestClientCADerivations464=== PAUSE TestClientCADerivations465=== RUN TestClientErrorHandling466=== PAUSE TestClientErrorHandling467=== RUN TestClientIntegration468=== PAUSE TestClientIntegration469=== RUN TestClientMultipleUploads470=== PAUSE TestClientMultipleUploads471=== RUN TestClientWithDependencies472=== PAUSE TestClientWithDependencies473=== RUN TestClientSharedPathCommittedMidPush474=== PAUSE TestClientSharedPathCommittedMidPush475=== RUN TestPinProtectsFromGC476=== PAUSE TestPinProtectsFromGC477=== RUN TestClientPushesUseOnePush478=== PAUSE TestClientPushesUseOnePush479=== RUN TestClientFallsBackToClosures480=== PAUSE TestClientFallsBackToClosures481=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock482=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock483=== RUN TestResolveDBConnectionString484=== PAUSE TestResolveDBConnectionString485=== RUN TestConnectWaitsForAPeerMigration486=== PAUSE TestConnectWaitsForAPeerMigration487=== RUN TestLeadElectsOneAndHandsOver488=== PAUSE TestLeadElectsOneAndHandsOver489=== RUN TestLeadIncumbentWinsAfterRestart4902026/10/06 08:17:03 INFO lead: acquired remote=192.0.2.1:12344912026/10/06 08:17:03 INFO lead: released remote=192.0.2.1:12344922026/10/06 08:17:03 INFO lead: acquired remote=192.0.2.1:12344932026/10/06 08:17:05 INFO lead: released remote=192.0.2.1:1234494--- PASS: TestLeadIncumbentWinsAfterRestart (2.17s)495=== RUN TestLeadIncumbentAnnouncesAtOnce496=== PAUSE TestLeadIncumbentAnnouncesAtOnce497=== RUN TestLeadEndsOnShutdown498=== PAUSE TestLeadEndsOnShutdown499=== RUN TestLeadEndsWhenItsConnectionHangs5002026/10/06 08:17:05 INFO lead: acquired remote=192.0.2.1:12345012026-10-06 08:17:06.755 UTC [50457] FATAL: terminating connection due to administrator command5022026/10/06 08:17:06 INFO lead: acquired remote=192.0.2.1:12345032026/10/06 08:17:07 WARN lead: lock connection lost error="timeout: context deadline exceeded"5042026/10/06 08:17:07 INFO lead: released remote=192.0.2.1:12345052026/10/06 08:17:08 INFO lead: released remote=192.0.2.1:1234506--- PASS: TestLeadEndsWhenItsConnectionHangs (3.11s)507=== RUN TestGCAdvisoryLockBlocksConcurrentRun508=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun509=== RUN TestGCBugBareHashReferences510=== PAUSE TestGCBugBareHashReferences511=== RUN TestGCMetrics512=== PAUSE TestGCMetrics513=== RUN TestPushDedupSurvivesConcurrentGC514=== PAUSE TestPushDedupSurvivesConcurrentGC515=== RUN TestDeduplicatedObjectsRecordedAsPending516=== PAUSE TestDeduplicatedObjectsRecordedAsPending517=== RUN TestGCSweepSkipsPendingObjects518=== PAUSE TestGCSweepSkipsPendingObjects519=== RUN TestTombstonedObjectOfferedWithoutWaiting520=== PAUSE TestTombstonedObjectOfferedWithoutWaiting521=== RUN TestGCSweepDeliversEachKeyOnce522=== PAUSE TestGCSweepDeliversEachKeyOnce523=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection524=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection525=== RUN TestForceGCDuringPushOffersSweptObject526=== PAUSE TestForceGCDuringPushOffersSweptObject527=== RUN TestFailedS3DeleteKeepsTombstone528=== PAUSE TestFailedS3DeleteKeepsTombstone529=== RUN TestSweepSkipsRowsLockedByPush530=== PAUSE TestSweepSkipsRowsLockedByPush531=== RUN TestRegisterCompletedObjectNeedsPendingRow532=== PAUSE TestRegisterCompletedObjectNeedsPendingRow533=== RUN TestGetExistingObjectsLocksRows534=== PAUSE TestGetExistingObjectsLocksRows535=== RUN TestSweepRechecksPendingAfterLocking536=== PAUSE TestSweepRechecksPendingAfterLocking537=== RUN TestPushWaitsForSweepHoldingRow538=== PAUSE TestPushWaitsForSweepHoldingRow539=== RUN TestCommitRacingPendingCleanupKeepsObjects540=== PAUSE TestCommitRacingPendingCleanupKeepsObjects541=== RUN TestGCEndsOnShutdown542=== PAUSE TestGCEndsOnShutdown543=== RUN TestGCTaskStore_StartNew544=== PAUSE TestGCTaskStore_StartNew545=== RUN TestGCTaskStore_DeduplicateSameParams546=== PAUSE TestGCTaskStore_DeduplicateSameParams547=== RUN TestGCTaskStore_ConflictDifferentParams548=== PAUSE TestGCTaskStore_ConflictDifferentParams549=== RUN TestGCTaskStore_GetEmpty550=== PAUSE TestGCTaskStore_GetEmpty551=== RUN TestGCTaskStore_GetReturnsLatest552=== PAUSE TestGCTaskStore_GetReturnsLatest553=== RUN TestGCTaskStore_CompletedAllowsNewTask554=== PAUSE TestGCTaskStore_CompletedAllowsNewTask555=== RUN TestGCTaskStore_PhaseUpdates556=== PAUSE TestGCTaskStore_PhaseUpdates557=== RUN TestGCTaskStore_Fail558=== PAUSE TestGCTaskStore_Fail559=== RUN TestGracefulShutdownDrainsInflight560=== PAUSE TestGracefulShutdownDrainsInflight561=== RUN TestService_healthCheckHandler562=== PAUSE TestService_healthCheckHandler563=== RUN TestService_readinessHandler564=== PAUSE TestService_readinessHandler565=== RUN TestGenerateLandingPage566=== PAUSE TestGenerateLandingPage567=== RUN TestCacheConfigHandlerMaxNarSize568=== PAUSE TestCacheConfigHandlerMaxNarSize569=== RUN TestCreatePendingClosureRejectsOversizedNAR570=== PAUSE TestCreatePendingClosureRejectsOversizedNAR571=== RUN TestNARDeduplicationMetadataUploadBug572=== PAUSE TestNARDeduplicationMetadataUploadBug573=== RUN TestMetricsInventory574=== PAUSE TestMetricsInventory575=== RUN TestService_NativeMTLS576=== PAUSE TestService_NativeMTLS577=== RUN TestServerTLSConfig578=== PAUSE TestServerTLSConfig579=== RUN TestMultipartCleanup580=== PAUSE TestMultipartCleanup581=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded582=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded583=== RUN TestPendingCleanupUsesOneCutoff584=== PAUSE TestPendingCleanupUsesOneCutoff585=== RUN TestObjectStatsTrigger586=== PAUSE TestObjectStatsTrigger587=== RUN TestOrphanedObjectsGC588=== PAUSE TestOrphanedObjectsGC589=== RUN TestOrphanedObjectsGCStressTest590=== PAUSE TestOrphanedObjectsGCStressTest591=== RUN TestCreatePin_ReservedPins592=== PAUSE TestCreatePin_ReservedPins593=== RUN TestPresentReportsOnlyClosureRoots594=== PAUSE TestPresentReportsOnlyClosureRoots595=== RUN TestPresentNotReportedWhileGCDeletesClosure596=== PAUSE TestPresentNotReportedWhileGCDeletesClosure597=== RUN TestParseSingleRange598=== PAUSE TestParseSingleRange599=== RUN TestProxyHeadersOnlyTrustedOnSocket600=== PAUSE TestProxyHeadersOnlyTrustedOnSocket601=== RUN TestIsValidCachePath602=== PAUSE TestIsValidCachePath603=== RUN TestReadProxyNarinfo604=== PAUSE TestReadProxyNarinfo605=== RUN TestReadProxyNarinfoAlreadyDecompressed606=== PAUSE TestReadProxyNarinfoAlreadyDecompressed607=== RUN TestReadProxyNarStreaming608=== PAUSE TestReadProxyNarStreaming609=== RUN TestReadProxy404610=== PAUSE TestReadProxy404611=== RUN TestReadProxyInvalidPath612=== PAUSE TestReadProxyInvalidPath613=== RUN TestReadProxyHead614=== PAUSE TestReadProxyHead615=== RUN TestReadProxyOutlastsServerWriteTimeout616=== PAUSE TestReadProxyOutlastsServerWriteTimeout617=== RUN TestReadProxyConditionalGet618=== PAUSE TestReadProxyConditionalGet619=== RUN TestReadProxyRootRedirectsToIndexHTML620=== PAUSE TestReadProxyRootRedirectsToIndexHTML621=== RUN TestReadProxyDisabled622=== PAUSE TestReadProxyDisabled623=== RUN TestReadRedirectNar624=== PAUSE TestReadRedirectNar625=== RUN TestReadRedirectKeepsNarinfoProxied626=== PAUSE TestReadRedirectKeepsNarinfoProxied627=== RUN TestReadProxyRangeRequest628=== PAUSE TestReadProxyRangeRequest629=== RUN TestReadRedirectUsesPublicS3URL630=== PAUSE TestReadRedirectUsesPublicS3URL631=== RUN TestPush_OverlappingRootsStoreOneRowPerKey632=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey633=== RUN TestPush_CompleteCommitsEveryRoot634=== PAUSE TestPush_CompleteCommitsEveryRoot635=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit636=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit637=== RUN TestPush_RejectsBadRequests638=== PAUSE TestPush_RejectsBadRequests639=== RUN TestPush_SignsNarinfosOfItsPendingObjects640=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects641=== RUN TestRedundantMultipartUpload642=== PAUSE TestRedundantMultipartUpload643=== RUN TestCompleteMultipartUpload_ErrorButObjectExists644=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists645=== RUN TestCompletedNarNotReofferedAcrossClosures646=== PAUSE TestCompletedNarNotReofferedAcrossClosures647=== RUN TestPresignedUploadRegisteredBeforeCommit648=== PAUSE TestPresignedUploadRegisteredBeforeCommit649=== RUN TestService_Rustfstest650=== PAUSE TestService_Rustfstest651=== RUN TestParseSize652=== PAUSE TestParseSize653=== RUN TestSkippedUploadsHandler654=== PAUSE TestSkippedUploadsHandler655=== RUN TestSystemdListenerNotActivated656--- PASS: TestSystemdListenerNotActivated (0.00s)657=== RUN TestWatchdogBeatsWhenHealthy658--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)659=== RUN TestWatchdogSkipsWhenUnhealthy6602026/10/06 08:17:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/06 08:17:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/06 08:17:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/06 08:17:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/06 08:17:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/06 08:17:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/06 08:17:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/06 08:17:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6682026/10/06 08:17:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"669--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)670=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle671=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle672=== RUN TestProxyWriteTimeout673=== PAUSE TestProxyWriteTimeout674=== RUN TestPendingClosureWriteTimeout675=== PAUSE TestPendingClosureWriteTimeout676=== RUN TestIsValidUploadKey677=== PAUSE TestIsValidUploadKey678=== RUN TestUploadHandlersRejectInvalidKeys679=== PAUSE TestUploadHandlersRejectInvalidKeys680=== RUN TestUploadHandlersRejectOversizedBody681=== PAUSE TestUploadHandlersRejectOversizedBody682=== RUN TestService_cleanupPendingClosuresHandler683=== PAUSE TestService_cleanupPendingClosuresHandler684=== RUN TestService_createPendingClosureHandler685=== PAUSE TestService_createPendingClosureHandler686=== RUN TestService_verifyS3Integrity687=== PAUSE TestService_verifyS3Integrity688=== RUN TestCompleteMultipartUnregistered689=== PAUSE TestCompleteMultipartUnregistered690=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT691=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT692=== CONT TestUploadHandlersRejectOversizedBody693=== CONT TestService_AuthMiddleware694=== CONT TestUploadHandlersRejectInvalidKeys695=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info696=== CONT TestIsValidUploadKey697=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info698=== RUN TestIsValidUploadKey/narinfo699=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal700=== PAUSE TestIsValidUploadKey/narinfo701=== RUN TestIsValidUploadKey/nar_zst702=== CONT TestPendingClosureWriteTimeout703=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle704=== CONT TestSkippedUploadsHandler705=== RUN TestPendingClosureWriteTimeout/empty706=== CONT TestParseSize707=== CONT TestService_Rustfstest708=== PAUSE TestIsValidUploadKey/nar_zst709=== CONT TestProxyWriteTimeout710=== CONT TestPresignedUploadRegisteredBeforeCommit711=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal712--- PASS: TestParseSize (0.00s)713=== PAUSE TestPendingClosureWriteTimeout/empty7142026/10/06 08:17:08 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000715=== RUN TestProxyWriteTimeout/narinfo716=== PAUSE TestProxyWriteTimeout/narinfo717=== RUN TestProxyWriteTimeout/1_GiB_nar718=== PAUSE TestProxyWriteTimeout/1_GiB_nar719=== RUN TestProxyWriteTimeout/10_GiB_nar720=== PAUSE TestProxyWriteTimeout/10_GiB_nar721=== RUN TestProxyWriteTimeout/unknown_size722=== RUN TestIsValidUploadKey/nar_xz723=== RUN TestPendingClosureWriteTimeout/400_objects724=== PAUSE TestPendingClosureWriteTimeout/400_objects725=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key726=== RUN TestPendingClosureWriteTimeout/670k_objects727=== PAUSE TestPendingClosureWriteTimeout/670k_objects728=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key729=== PAUSE TestIsValidUploadKey/nar_xz730=== PAUSE TestProxyWriteTimeout/unknown_size731=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline732=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline733=== CONT TestCompleteMultipartUpload_ErrorButObjectExists734=== CONT TestCompletedNarNotReofferedAcrossClosures735=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key736=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key737=== RUN TestIsValidUploadKey/nar_plain738=== PAUSE TestIsValidUploadKey/nar_plain739=== RUN TestIsValidUploadKey/listing740=== PAUSE TestIsValidUploadKey/listing741=== RUN TestIsValidUploadKey/build_log742=== PAUSE TestIsValidUploadKey/build_log743=== RUN TestIsValidUploadKey/build_log_home-manager_file744=== PAUSE TestIsValidUploadKey/build_log_home-manager_file745=== RUN TestIsValidUploadKey/build_log_plus_in_name746=== PAUSE TestIsValidUploadKey/build_log_plus_in_name747=== RUN TestIsValidUploadKey/build_log_question_mark748=== CONT TestRedundantMultipartUpload749=== PAUSE TestIsValidUploadKey/build_log_question_mark750=== RUN TestIsValidUploadKey/build_log_equals751=== PAUSE TestIsValidUploadKey/build_log_equals752=== RUN TestIsValidUploadKey/realisation753=== PAUSE TestIsValidUploadKey/realisation754=== RUN TestIsValidUploadKey/realisation_plus_in_output755=== PAUSE TestIsValidUploadKey/realisation_plus_in_output756=== RUN TestIsValidUploadKey/nix-cache-info757=== PAUSE TestIsValidUploadKey/nix-cache-info758=== RUN TestIsValidUploadKey/index.html759=== PAUSE TestIsValidUploadKey/index.html760=== RUN TestIsValidUploadKey/narinfo_key,_nar_type761=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type762=== RUN TestIsValidUploadKey/nar_key,_narinfo_type763=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type764=== RUN TestIsValidUploadKey/listing_key,_narinfo_type765=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type766=== RUN TestIsValidUploadKey/traversal767=== PAUSE TestIsValidUploadKey/traversal768=== RUN TestIsValidUploadKey/traversal_nar769=== PAUSE TestIsValidUploadKey/traversal_nar770=== RUN TestIsValidUploadKey/absolute771=== PAUSE TestIsValidUploadKey/absolute772=== RUN TestIsValidUploadKey/empty_key773=== PAUSE TestIsValidUploadKey/empty_key774=== RUN TestIsValidUploadKey/unknown_type775=== PAUSE TestIsValidUploadKey/unknown_type776=== CONT TestPush_SignsNarinfosOfItsPendingObjects777--- PASS: TestSkippedUploadsHandler (0.01s)778=== CONT TestPush_RejectsBadRequests779=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure780=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure781=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart782=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart783=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts784=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts785=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit7862026/10/06 08:17:08 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"787--- PASS: TestService_AuthMiddleware (0.44s)788=== CONT TestPush_CompleteCommitsEveryRoot7892026/10/06 08:17:08 INFO Received uploads request method=POST path=/api/pending_closures7902026/10/06 08:17:09 INFO Received uploads request method=POST path=/api/pending_closures7912026/10/06 08:17:09 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst7922026/10/06 08:17:09 INFO Received uploads request method=POST path=/api/pending_closures793--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.83s)794=== CONT TestPush_OverlappingRootsStoreOneRowPerKey7952026/10/06 08:17:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7962026/10/06 08:17:09 INFO Received uploads request method=POST path=/api/pending_closures797=== RUN TestPush_RejectsBadRequests/no_roots798=== PAUSE TestPush_RejectsBadRequests/no_roots799=== RUN TestPush_RejectsBadRequests/no_objects800=== PAUSE TestPush_RejectsBadRequests/no_objects801=== RUN TestPush_RejectsBadRequests/bad_root802=== PAUSE TestPush_RejectsBadRequests/bad_root803=== RUN TestPush_RejectsBadRequests/root_not_in_objects804=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects805=== CONT TestReadRedirectUsesPublicS3URL8062026/10/06 08:17:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8072026/10/06 08:17:09 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OGU0NzNlNGItYTJmZS00NGZhLThmYWUtY2M4MzRjYTUxMTM2LjI1ODcyNTUxLTI5YTUtNDE4YS05OGJiLTMyODA1N2JhYzU2NHgxNzkxMjc0NjI5Mzc0NTk0MDAw8082026/10/06 08:17:09 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OGU0NzNlNGItYTJmZS00NGZhLThmYWUtY2M4MzRjYTUxMTM2LjI1ODcyNTUxLTI5YTUtNDE4YS05OGJiLTMyODA1N2JhYzU2NHgxNzkxMjc0NjI5Mzc0NTk0MDAw parts=1809--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.12s)810=== CONT TestReadProxyRangeRequest8112026/10/06 08:17:09 INFO Received uploads request method=POST path=/api/pending_closures812--- PASS: TestService_Rustfstest (1.46s)813=== CONT TestReadRedirectKeepsNarinfoProxied8142026/10/06 08:17:10 INFO Received push request method=POST path=/api/pushes8152026/10/06 08:17:10 INFO Received complete push request method=POST path=/api/pushes/1/complete8162026/10/06 08:17:10 INFO Received push request method=POST path=/api/pushes8172026/10/06 08:17:10 INFO Aborted multipart uploads count=0 kept=08182026/10/06 08:17:10 WARN Force mode enabled - objects will be deleted immediately without grace period8192026/10/06 08:17:10 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=2 objects-failed-to-delete=08202026/10/06 08:17:10 INFO Vacuumed table table=pending_closures8212026/10/06 08:17:10 INFO Vacuumed table table=pending_objects8222026/10/06 08:17:10 INFO Vacuumed table table=multipart_uploads8232026/10/06 08:17:10 INFO Received uploads request method=POST path=/api/pending_closures8242026/10/06 08:17:10 INFO Vacuumed table table=closures8252026/10/06 08:17:10 INFO Vacuumed table table=objects8262026/10/06 08:17:10 INFO Received complete push request method=POST path=/api/pushes/2/complete827--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (1.90s)828=== CONT TestService_verifyS3Integrity8292026/10/06 08:17:10 INFO Received uploads request method=POST path=/api/pending_closures8302026/10/06 08:17:10 INFO Received push request method=POST path=/api/pushes8312026/10/06 08:17:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8322026/10/06 08:17:10 INFO Signed narinfos id=1 count=18332026/10/06 08:17:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8342026/10/06 08:17:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8352026/10/06 08:17:10 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"8362026/10/06 08:17:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8372026/10/06 08:17:10 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"8382026/10/06 08:17:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8392026/10/06 08:17:10 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=18402026/10/06 08:17:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8412026/10/06 08:17:10 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo842--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (2.25s)843=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT8442026/10/06 08:17:10 INFO Received push request method=POST path=/api/pushes8452026/10/06 08:17:10 INFO Received complete push request method=POST path=/api/pushes/1/complete846--- PASS: TestPush_CompleteCommitsEveryRoot (2.18s)847=== CONT TestCompleteMultipartUnregistered8482026/10/06 08:17:11 INFO Received push request method=POST path=/api/pushes849--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (2.05s)850=== CONT TestGCEndsOnShutdown851=== RUN TestGCEndsOnShutdown/before_the_run852=== PAUSE TestGCEndsOnShutdown/before_the_run853=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete854=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete855=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark856=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark857=== CONT TestReadProxyDisabled8582026/10/06 08:17:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8592026/10/06 08:17:11 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=OGU0NzNlNGItYTJmZS00NGZhLThmYWUtY2M4MzRjYTUxMTM2LjExMmM5YzMzLWE2YjYtNDdkYy04MGJmLTJhNDhkNTAxYTZhYXgxNzkxMjc0NjI5NzExNTA5MDAw parts=128602026/10/06 08:17:11 INFO Received uploads request method=POST path=/api/pending_closures861--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.01s)862=== CONT TestReadProxyRootRedirectsToIndexHTML863--- PASS: TestReadRedirectUsesPublicS3URL (2.09s)864=== CONT TestReadProxyConditionalGet865--- PASS: TestReadProxyRangeRequest (2.40s)866=== CONT TestReadProxyOutlastsServerWriteTimeout8672026/10/06 08:17:12 INFO Received uploads request method=POST path=/api/pending_closures8682026/10/06 08:17:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8692026/10/06 08:17:12 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=OGU0NzNlNGItYTJmZS00NGZhLThmYWUtY2M4MzRjYTUxMTM2LjA1NTAyZmM4LWI2NjQtNDVhZi04NzRkLTlmNGQ4NmVjNWVmOHgxNzkxMjc0NjMwMzA3OTI2MDAw parts=128702026/10/06 08:17:12 INFO Received uploads request method=POST path=/api/pending_closures8712026/10/06 08:17:12 INFO Received uploads request method=POST path=/api/pending_closures872--- PASS: TestReadRedirectKeepsNarinfoProxied (3.00s)873=== CONT TestReadProxyHead8742026/10/06 08:17:13 INFO Received uploads request method=POST path=/api/pending_closures875--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (2.56s)876=== CONT TestReadProxyInvalidPath8772026/10/06 08:17:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8782026/10/06 08:17:13 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst879--- PASS: TestCompleteMultipartUnregistered (2.41s)880=== CONT TestReadProxy404881--- PASS: TestReadProxyDisabled (2.69s)882=== CONT TestReadProxyNarStreaming8832026/10/06 08:17:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8842026/10/06 08:17:14 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=OGU0NzNlNGItYTJmZS00NGZhLThmYWUtY2M4MzRjYTUxMTM2Ljk3NDFiMzgxLTVhMzMtNGZhMy05MWJmLTc4MGY1NGU0OTdlMXgxNzkxMjc0NjMyNTAyNzgzMDAw parts=108852026/10/06 08:17:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8862026/10/06 08:17:14 INFO Completed upload id=18872026/10/06 08:17:14 INFO Received uploads request method=POST path=/api/pending_closures8882026/10/06 08:17:14 INFO Received uploads request method=POST path=/api/pending_closures8892026/10/06 08:17:14 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo8902026/10/06 08:17:14 WARN Found objects in DB but missing from S3, will re-upload count=1891--- PASS: TestService_verifyS3Integrity (4.06s)892=== CONT TestReadProxyNarinfoAlreadyDecompressed893--- PASS: TestReadProxyConditionalGet (2.83s)894=== CONT TestReadProxyNarinfo8952026/10/06 08:17:14 WARN Rate limiter enabled after throttle name=s3-test rate=58962026/10/06 08:17:14 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."897=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle898 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=10899 throttle_test.go:215: Rate limiter: enabled=true, rate=5.00900--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.17s)901=== CONT TestIsValidCachePath902=== RUN TestIsValidCachePath/narinfo903=== PAUSE TestIsValidCachePath/narinfo904=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars905=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars906=== RUN TestIsValidCachePath/nar_zst907=== PAUSE TestIsValidCachePath/nar_zst908=== RUN TestIsValidCachePath/nar_xz909=== PAUSE TestIsValidCachePath/nar_xz910=== RUN TestIsValidCachePath/nar_bz2911=== PAUSE TestIsValidCachePath/nar_bz2912=== RUN TestIsValidCachePath/nar_uncompressed913=== PAUSE TestIsValidCachePath/nar_uncompressed914=== RUN TestIsValidCachePath/ls915=== PAUSE TestIsValidCachePath/ls916=== RUN TestIsValidCachePath/log917=== PAUSE TestIsValidCachePath/log918=== RUN TestIsValidCachePath/realisation919=== PAUSE TestIsValidCachePath/realisation920=== RUN TestIsValidCachePath/nix-cache-info921=== PAUSE TestIsValidCachePath/nix-cache-info922=== RUN TestIsValidCachePath/index.html923=== PAUSE TestIsValidCachePath/index.html924=== RUN TestIsValidCachePath/traversal_parent925=== PAUSE TestIsValidCachePath/traversal_parent926=== RUN TestIsValidCachePath/traversal_in_middle927=== PAUSE TestIsValidCachePath/traversal_in_middle928=== RUN TestIsValidCachePath/invalid_char_e929=== PAUSE TestIsValidCachePath/invalid_char_e930=== RUN TestIsValidCachePath/invalid_char_u931=== PAUSE TestIsValidCachePath/invalid_char_u932=== RUN TestIsValidCachePath/random_path933=== PAUSE TestIsValidCachePath/random_path934=== RUN TestIsValidCachePath/empty935=== PAUSE TestIsValidCachePath/empty936=== RUN TestIsValidCachePath/leading_slash937=== PAUSE TestIsValidCachePath/leading_slash938=== RUN TestIsValidCachePath/wrong_extension939=== PAUSE TestIsValidCachePath/wrong_extension940=== RUN TestIsValidCachePath/short_hash941=== PAUSE TestIsValidCachePath/short_hash942=== CONT TestProxyHeadersOnlyTrustedOnSocket9432026/10/06 08:17:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9442026/10/06 08:17:14 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OGU0NzNlNGItYTJmZS00NGZhLThmYWUtY2M4MzRjYTUxMTM2LmQ3MGNjYzRiLTgwNWMtNDk1ZS04MTNiLWEzNjQ2NTU0YzIzMHgxNzkxMjc0NjMyNzA2NzU0MDAw error="Get \"http://127.0.0.1:1/bucket11/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"9452026/10/06 08:17:14 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OGU0NzNlNGItYTJmZS00NGZhLThmYWUtY2M4MzRjYTUxMTM2LjM0YTJjZTlkLWI3ZTgtNGM3NS04Njg1LWZjYWVhYzA0ZDBhY3gxNzkxMjc0NjMyNjUyNzc4MDAw parts=129462026/10/06 08:17:14 INFO Received cleanup request method=DELETE path=/api/pending_closures9472026/10/06 08:17:14 INFO Aborted multipart uploads count=1 kept=0948--- PASS: TestRedundantMultipartUpload (6.54s)949=== CONT TestParseSingleRange950=== RUN TestParseSingleRange/none951=== PAUSE TestParseSingleRange/none952=== RUN TestParseSingleRange/unknown_unit953=== PAUSE TestParseSingleRange/unknown_unit954=== RUN TestParseSingleRange/multi-range_ignored955=== PAUSE TestParseSingleRange/multi-range_ignored956=== RUN TestParseSingleRange/malformed_no_dash957=== PAUSE TestParseSingleRange/malformed_no_dash958=== RUN TestParseSingleRange/malformed_both_empty959=== PAUSE TestParseSingleRange/malformed_both_empty960=== RUN TestParseSingleRange/malformed_end_before_start961=== PAUSE TestParseSingleRange/malformed_end_before_start962=== RUN TestParseSingleRange/closed963=== PAUSE TestParseSingleRange/closed964=== RUN TestParseSingleRange/open-ended965=== PAUSE TestParseSingleRange/open-ended966=== RUN TestParseSingleRange/end_clamped_to_size967=== PAUSE TestParseSingleRange/end_clamped_to_size968=== RUN TestParseSingleRange/suffix969=== PAUSE TestParseSingleRange/suffix970=== RUN TestParseSingleRange/suffix_exceeds_size971=== PAUSE TestParseSingleRange/suffix_exceeds_size972=== RUN TestParseSingleRange/single_byte973=== PAUSE TestParseSingleRange/single_byte974=== RUN TestParseSingleRange/start_past_EOF975=== PAUSE TestParseSingleRange/start_past_EOF976=== RUN TestParseSingleRange/start_far_past_EOF977=== PAUSE TestParseSingleRange/start_far_past_EOF978=== CONT TestPresentNotReportedWhileGCDeletesClosure979--- PASS: TestReadProxyRootRedirectsToIndexHTML (3.67s)980=== CONT TestPresentReportsOnlyClosureRoots981--- PASS: TestReadProxyHead (2.68s)982=== CONT TestService_createPendingClosureHandler983--- PASS: TestReadProxyInvalidPath (2.82s)984=== CONT TestCreatePin_ReservedPins9852026/10/06 08:17:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65246/oidc986--- PASS: TestReadProxy404 (3.09s)987=== CONT TestService_cleanupPendingClosuresHandler988--- PASS: TestReadProxyNarStreaming (2.81s)989=== CONT TestOrphanedObjectsGCStressTest990--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.73s)991=== CONT TestOrphanedObjectsGC9922026/10/06 08:17:17 INFO Starting HTTP server address=127.0.0.1:652629932026/10/06 08:17:17 INFO Starting HTTP server address=/nix/var/nix/builds/nix-49438-1596666667/TestProxyHeadersOnlyTrustedOnSocket2867933198/001/proxy.sock9942026/10/06 08:17:17 WARN mTLS auth: subject not in bound subjects subject="CN=someone"9952026/10/06 08:17:17 INFO Shutdown signal received, draining in-flight requests timeout=10s996--- PASS: TestProxyHeadersOnlyTrustedOnSocket (2.90s)997=== CONT TestLeadElectsOneAndHandsOver9982026/10/06 08:17:18 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"999--- PASS: TestPresentNotReportedWhileGCDeletesClosure (3.41s)1000=== CONT TestObjectStatsTrigger1001--- PASS: TestPresentReportsOnlyClosureRoots (3.38s)1002=== CONT TestCommitRacingPendingCleanupKeepsObjects10032026/10/06 08:17:18 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772161004--- PASS: TestReadProxyNarinfo (4.21s)1005=== CONT TestPendingCleanupUsesOneCutoff10062026/10/06 08:17:18 INFO Received uploads request method=POST path=/api/pending_closures10072026/10/06 08:17:18 INFO Received uploads request method=POST path=/api/pending_closures10082026/10/06 08:17:18 INFO Received uploads request method=POST path=/api/pending_closures1009--- PASS: TestReadProxyOutlastsServerWriteTimeout (7.05s)1010=== CONT TestPushWaitsForSweepHoldingRow10112026/10/06 08:17:19 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10122026/10/06 08:17:19 WARN Refused reserved pin name=worker-x86_64-linux10132026/10/06 08:17:19 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10142026/10/06 08:17:19 INFO Received create pin request method=POST path=/api/pins/my-app10152026/10/06 08:17:19 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1016--- PASS: TestCreatePin_ReservedPins (3.29s)1017=== CONT TestSweepRechecksPendingAfterLocking10182026/10/06 08:17:19 INFO Received cleanup request method=DELETE path=/api/pending_closures10192026/10/06 08:17:19 INFO Aborted multipart uploads count=0 kept=010202026/10/06 08:17:19 INFO Received uploads request method=POST path=/api/pending_closures10212026/10/06 08:17:19 INFO Received cleanup request method=DELETE path=/api/pending_closures10222026/10/06 08:17:19 INFO Aborted multipart uploads count=1 kept=010232026/10/06 08:17:19 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10242026-10-06 08:17:19.735 UTC [51703] ERROR: Closure does not exist: id=110252026-10-06 08:17:19.735 UTC [51703] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE10262026-10-06 08:17:19.735 UTC [51703] STATEMENT: -- name: CommitPendingClosure :exec1027 SELECT commit_pending_closure($1::bigint)1028 1029--- PASS: TestService_cleanupPendingClosuresHandler (3.23s)1030=== CONT TestGetExistingObjectsLocksRows10312026/10/06 08:17:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10322026/10/06 08:17:20 INFO lead: acquired remote=192.0.2.1:123410332026/10/06 08:17:20 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=OGU0NzNlNGItYTJmZS00NGZhLThmYWUtY2M4MzRjYTUxMTM2LmJhNzI0M2RkLWZhNjQtNGRmMS05YjhmLTUyNTM3OTFmN2ZmY3gxNzkxMjc0NjM4OTAxNjgzMDAw parts=1010342026/10/06 08:17:20 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10352026/10/06 08:17:20 INFO Completed upload id=110362026/10/06 08:17:20 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010372026/10/06 08:17:20 INFO Received uploads request method=POST path=/api/pending_closures10382026/10/06 08:17:20 INFO Starting cleanup of old closures method=DELETE path=/api/closures10392026/10/06 08:17:20 INFO Aborted multipart uploads count=0 kept=010402026/10/06 08:17:20 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=010412026/10/06 08:17:20 INFO Vacuumed table table=pending_closures10422026/10/06 08:17:20 INFO Vacuumed table table=pending_objects10432026/10/06 08:17:20 INFO Vacuumed table table=multipart_uploads10442026/10/06 08:17:20 INFO Vacuumed table table=closures10452026/10/06 08:17:20 INFO Vacuumed table table=objects10462026/10/06 08:17:20 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001047--- PASS: TestService_createPendingClosureHandler (5.26s)1048=== CONT TestRegisterCompletedObjectNeedsPendingRow10492026/10/06 08:17:20 INFO Received uploads request method=POST path=/api/pending_closures10502026/10/06 08:17:21 INFO Received uploads request method=POST path=/api/pending_closures10512026/10/06 08:17:21 INFO Received cleanup request method=DELETE path=/api/pending_closures1052=== NAME TestOrphanedObjectsGC1053 orphaned_objects_gc_test.go:290: GC Test Summary:1054 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1055 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1056 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1057 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1058 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1059--- PASS: TestOrphanedObjectsGC (3.96s)1060=== CONT TestSweepSkipsRowsLockedByPush1061--- PASS: TestObjectStatsTrigger (3.00s)1062=== CONT TestFailedS3DeleteKeepsTombstone10632026/10/06 08:17:21 INFO Aborted multipart uploads count=0 kept=010642026/10/06 08:17:21 WARN Force mode enabled - objects will be deleted immediately without grace period10652026/10/06 08:17:21 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010662026/10/06 08:17:21 INFO Vacuumed table table=pending_closures10672026/10/06 08:17:21 INFO Vacuumed table table=pending_objects10682026/10/06 08:17:21 INFO Vacuumed table table=multipart_uploads10692026/10/06 08:17:21 INFO Vacuumed table table=closures10702026/10/06 08:17:21 INFO Vacuumed table table=objects1071--- PASS: TestCommitRacingPendingCleanupKeepsObjects (3.28s)1072=== CONT TestForceGCDuringPushOffersSweptObject1073=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1074=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1075=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1076=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1077=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10782026/10/06 08:17:21 INFO lead: released remote=192.0.2.1:123410792026/10/06 08:17:21 INFO Received uploads request method=POST path=/api/pending_closures10802026/10/06 08:17:21 INFO lead: acquired remote=192.0.2.1:123410812026/10/06 08:17:22 INFO Aborted multipart uploads count=0 kept=010822026/10/06 08:17:22 WARN Force mode enabled - objects will be deleted immediately without grace period10832026/10/06 08:17:22 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=010842026/10/06 08:17:22 INFO Vacuumed table table=pending_closures10852026/10/06 08:17:22 INFO Vacuumed table table=pending_objects10862026/10/06 08:17:22 INFO Vacuumed table table=multipart_uploads10872026/10/06 08:17:22 INFO Vacuumed table table=closures10882026/10/06 08:17:22 INFO Vacuumed table table=objects1089--- PASS: TestSweepRechecksPendingAfterLocking (2.99s)1090=== CONT TestGCSweepDeliversEachKeyOnce1091--- PASS: TestPushWaitsForSweepHoldingRow (3.38s)1092=== CONT TestTombstonedObjectOfferedWithoutWaiting1093--- PASS: TestGetExistingObjectsLocksRows (2.73s)1094=== CONT TestGCSweepSkipsPendingObjects1095--- PASS: TestRegisterCompletedObjectNeedsPendingRow (1.89s)1096=== CONT TestDeduplicatedObjectsRecordedAsPending10972026/10/06 08:17:22 INFO lead: released remote=192.0.2.1:12341098--- PASS: TestLeadElectsOneAndHandsOver (5.52s)1099=== CONT TestPushDedupSurvivesConcurrentGC11002026/10/06 08:17:23 INFO Aborted multipart uploads count=0 kept=011012026/10/06 08:17:23 WARN Force mode enabled - objects will be deleted immediately without grace period11022026/10/06 08:17:23 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=011032026/10/06 08:17:23 INFO Vacuumed table table=pending_closures11042026/10/06 08:17:23 INFO Vacuumed table table=pending_objects11052026/10/06 08:17:23 INFO Vacuumed table table=multipart_uploads11062026/10/06 08:17:23 INFO Vacuumed table table=closures11072026/10/06 08:17:23 INFO Vacuumed table table=objects11082026/10/06 08:17:23 INFO Aborted multipart uploads count=0 kept=011092026/10/06 08:17:23 WARN Force mode enabled - objects will be deleted immediately without grace period11102026/10/06 08:17:23 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=011112026/10/06 08:17:23 INFO Vacuumed table table=pending_closures11122026/10/06 08:17:23 INFO Vacuumed table table=pending_objects11132026/10/06 08:17:23 INFO Vacuumed table table=multipart_uploads11142026/10/06 08:17:23 INFO Vacuumed table table=closures11152026/10/06 08:17:23 INFO Vacuumed table table=objects1116--- PASS: TestSweepSkipsRowsLockedByPush (2.22s)1117=== CONT TestGCMetrics11182026/10/06 08:17:23 INFO Received uploads request method=POST path=/api/pending_closures11192026/10/06 08:17:23 INFO Aborted multipart uploads count=0 kept=011202026/10/06 08:17:23 WARN Force mode enabled - objects will be deleted immediately without grace period11212026/10/06 08:17:23 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."11222026/10/06 08:17:23 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1123--- PASS: TestFailedS3DeleteKeepsTombstone (2.47s)1124=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded11252026/10/06 08:17:24 INFO Received uploads request method=POST path=/api/pending_closures1126--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (2.59s)1127=== CONT TestGCBugBareHashReferences11282026/10/06 08:17:24 INFO Aborted multipart uploads count=0 kept=011292026/10/06 08:17:24 WARN Force mode enabled - objects will be deleted immediately without grace period11302026/10/06 08:17:24 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=011312026/10/06 08:17:24 INFO Vacuumed table table=pending_closures11322026/10/06 08:17:24 INFO Vacuumed table table=pending_objects11332026/10/06 08:17:24 INFO Vacuumed table table=multipart_uploads11342026/10/06 08:17:24 INFO Vacuumed table table=closures11352026/10/06 08:17:24 INFO Vacuumed table table=objects1136--- PASS: TestGCSweepDeliversEachKeyOnce (2.47s)1137=== CONT TestGCAdvisoryLockBlocksConcurrentRun11382026/10/06 08:17:24 INFO Received uploads request method=POST path=/api/pending_closures11392026/10/06 08:17:24 INFO Aborted multipart uploads count=0 kept=011402026/10/06 08:17:24 WARN Force mode enabled - objects will be deleted immediately without grace period11412026/10/06 08:17:24 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=011422026/10/06 08:17:24 INFO Vacuumed table table=pending_closures11432026/10/06 08:17:24 INFO Vacuumed table table=pending_objects11442026/10/06 08:17:24 INFO Vacuumed table table=multipart_uploads11452026/10/06 08:17:24 INFO Vacuumed table table=closures11462026/10/06 08:17:24 INFO Vacuumed table table=objects1147--- PASS: TestGCSweepSkipsPendingObjects (2.57s)1148=== CONT TestMultipartCleanup11492026/10/06 08:17:25 INFO Received uploads request method=POST path=/api/pending_closures1150--- PASS: TestTombstonedObjectOfferedWithoutWaiting (2.85s)1151=== CONT TestServerTLSConfig1152=== RUN TestServerTLSConfig/no_client_CA1153=== PAUSE TestServerTLSConfig/no_client_CA1154=== RUN TestServerTLSConfig/missing_CA_file1155=== PAUSE TestServerTLSConfig/missing_CA_file1156=== RUN TestServerTLSConfig/not_a_PEM_file1157=== PAUSE TestServerTLSConfig/not_a_PEM_file1158=== CONT TestService_NativeMTLS11592026/10/06 08:17:25 INFO Received uploads request method=POST path=/api/pending_closures1160--- PASS: TestDeduplicatedObjectsRecordedAsPending (2.82s)1161=== CONT TestMetricsInventory11622026/10/06 08:17:25 INFO Received uploads request method=POST path=/api/pending_closures11632026/10/06 08:17:26 INFO Aborted multipart uploads count=0 kept=011642026/10/06 08:17:26 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=011652026/10/06 08:17:26 INFO Vacuumed table table=pending_closures11662026/10/06 08:17:26 INFO Vacuumed table table=pending_objects11672026/10/06 08:17:26 INFO Vacuumed table table=multipart_uploads11682026/10/06 08:17:26 INFO Vacuumed table table=closures11692026/10/06 08:17:26 INFO Vacuumed table table=objects11702026/10/06 08:17:26 INFO Aborted multipart uploads count=0 kept=011712026/10/06 08:17:26 WARN Force mode enabled - objects will be deleted immediately without grace period11722026/10/06 08:17:26 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=011732026/10/06 08:17:26 INFO Vacuumed table table=pending_closures11742026/10/06 08:17:26 INFO Vacuumed table table=pending_objects11752026/10/06 08:17:26 INFO Vacuumed table table=multipart_uploads11762026/10/06 08:17:26 INFO Vacuumed table table=closures11772026/10/06 08:17:26 INFO Vacuumed table table=objects1178--- PASS: TestPushDedupSurvivesConcurrentGC (3.32s)1179=== CONT TestNARDeduplicationMetadataUploadBug11802026/10/06 08:17:26 INFO Aborted multipart uploads count=0 kept=011812026/10/06 08:17:26 WARN Force mode enabled - objects will be deleted immediately without grace period11822026/10/06 08:17:26 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=011832026/10/06 08:17:26 INFO Vacuumed table table=pending_closures11842026/10/06 08:17:26 INFO Vacuumed table table=pending_objects11852026/10/06 08:17:26 INFO Vacuumed table table=multipart_uploads11862026/10/06 08:17:26 INFO Vacuumed table table=closures11872026/10/06 08:17:26 INFO Vacuumed table table=objects1188--- PASS: TestGCMetrics (3.08s)1189=== CONT TestReadRedirectNar1190=== NAME TestOrphanedObjectsGCStressTest1191 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1192 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion11932026/10/06 08:17:27 INFO Received uploads request method=POST path=/api/pending_closures11942026/10/06 08:17:27 INFO Aborted multipart uploads count=1 kept=011952026/10/06 08:17:27 INFO Received cleanup request method=DELETE path=/api/pending_closures11962026/10/06 08:17:27 INFO Aborted multipart uploads count=1 kept=01197--- PASS: TestPendingCleanupUsesOneCutoff (8.52s)1198=== CONT TestLeadIncumbentAnnouncesAtOnce1199--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (3.32s)1200=== CONT TestConnectWaitsForAPeerMigration1201--- PASS: TestGCBugBareHashReferences (3.45s)1202=== CONT TestGCTaskStore_PhaseUpdates1203--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1204=== CONT TestCreatePendingClosureRejectsOversizedNAR12052026/10/06 08:17:27 INFO Received uploads request method=POST path=/api/pending_closures1206--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1207=== CONT TestResolveDBConnectionString1208=== RUN TestResolveDBConnectionString/flag_wins1209=== PAUSE TestResolveDBConnectionString/flag_wins1210=== RUN TestResolveDBConnectionString/file_when_flag_empty1211=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1212=== RUN TestResolveDBConnectionString/missing_file_is_an_error1213=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1214=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1215=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1216=== RUN TestResolveDBConnectionString/nothing_configured1217=== PAUSE TestResolveDBConnectionString/nothing_configured1218=== CONT TestCacheConfigHandlerMaxNarSize1219--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1220=== CONT TestGCTaskStore_CompletedAllowsNewTask1221--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1222=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock12232026/10/06 08:17:27 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_nixbld13 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1224--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (3.06s)1225=== CONT TestGenerateLandingPage1226--- PASS: TestGenerateLandingPage (0.00s)1227=== CONT TestClientFallsBackToClosures12282026/10/06 08:17:28 INFO Received uploads request method=POST path=/api/pending_closures12292026/10/06 08:17:28 INFO Received cleanup request method=DELETE path=/api/pending_closures12302026/10/06 08:17:28 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket59/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""12312026/10/06 08:17:28 INFO Aborted multipart uploads count=0 kept=112322026/10/06 08:17:28 INFO Received cleanup request method=DELETE path=/api/pending_closures12332026/10/06 08:17:28 INFO Aborted multipart uploads count=1 kept=01234--- PASS: TestMultipartCleanup (3.23s)1235=== CONT TestGCTaskStore_GetReturnsLatest1236--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1237=== CONT TestService_readinessHandler1238--- PASS: TestMetricsInventory (2.91s)1239=== CONT TestLeadEndsOnShutdown12402026/10/06 08:17:28 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12412026/10/06 08:17:28 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1242--- PASS: TestService_NativeMTLS (3.36s)1243=== CONT TestService_healthCheckHandler1244=== NAME TestNARDeduplicationMetadataUploadBug1245 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-49438-1596666667/TestNARDeduplicationMetadataUploadBug4280468637/001/store/m9dhssdq8yc7mx7xcn5rz1s2h0ijfz20-file1.txt1246--- PASS: TestReadRedirectNar (2.63s)1247=== CONT TestGCTaskStore_GetEmpty1248--- PASS: TestGCTaskStore_GetEmpty (0.00s)1249=== CONT TestGracefulShutdownDrainsInflight12502026/10/06 08:17:29 INFO Starting HTTP server address=127.0.0.1:6535812512026/10/06 08:17:29 INFO Shutdown signal received, draining in-flight requests timeout=10s1252--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1253=== CONT TestGCTaskStore_StartNew1254--- PASS: TestGCTaskStore_StartNew (0.00s)1255=== CONT TestGCTaskStore_Fail1256--- PASS: TestGCTaskStore_Fail (0.00s)1257=== CONT TestGCTaskStore_ConflictDifferentParams1258--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1259=== CONT TestClientPushesUseOnePush12602026/10/06 08:17:29 INFO Received push request method=POST path=/api/pushes12612026/10/06 08:17:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12622026/10/06 08:17:29 INFO Uploading m9dhssdq8yc7mx7xcn5rz1s2h0ijfz20-file1.txt (160B)12632026/10/06 08:17:29 WARN Failed to register uploaded object key=m9dhssdq8yc7mx7xcn5rz1s2h0ijfz20.ls error="server returned 404: 404 page not found\n"12642026/10/06 08:17:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12652026/10/06 08:17:29 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12662026/10/06 08:17:29 INFO Signed narinfos id=1 count=112672026/10/06 08:17:29 INFO Uploading 1 narinfos12682026/10/06 08:17:29 INFO Received complete push request method=POST path=/api/pushes/1/complete12692026/10/06 08:17:29 WARN Failed to register uploaded object key=m9dhssdq8yc7mx7xcn5rz1s2h0ijfz20.narinfo error="server returned 404: 404 page not found\n"12702026/10/06 08:17:29 INFO Upload complete. (187ms)1271=== NAME TestNARDeduplicationMetadataUploadBug1272 metadata_upload_test.go:54: Retrieved narinfo from S3:1273 StorePath: /nix/var/nix/builds/nix-49438-1596666667/TestNARDeduplicationMetadataUploadBug4280468637/001/store/m9dhssdq8yc7mx7xcn5rz1s2h0ijfz20-file1.txt1274 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1275 Compression: zstd1276 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1277 NarSize: 1601278 References: 1279 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1280 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1281 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1282 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1283 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-49438-1596666667/TestNARDeduplicationMetadataUploadBug4280468637/001/store/g7w2qqwf1v5zpdy1manxvcl134zjdiz8-file2.txt12842026/10/06 08:17:29 INFO lead: acquired remote=192.0.2.1:123412852026/10/06 08:17:29 INFO lead: released remote=192.0.2.1:12341286--- PASS: TestLeadIncumbentAnnouncesAtOnce (2.18s)1287=== CONT TestService_ReadAuthMiddleware12882026/10/06 08:17:29 INFO Received push request method=POST path=/api/pushes12892026/10/06 08:17:29 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12902026/10/06 08:17:29 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12912026/10/06 08:17:29 INFO Signed narinfos id=2 count=112922026/10/06 08:17:29 INFO Uploading 1 narinfos12932026/10/06 08:17:29 WARN Failed to register uploaded object key=g7w2qqwf1v5zpdy1manxvcl134zjdiz8.ls error="server returned 404: 404 page not found\n"12942026/10/06 08:17:29 INFO Received complete push request method=POST path=/api/pushes/2/complete12952026/10/06 08:17:29 WARN Failed to register uploaded object key=g7w2qqwf1v5zpdy1manxvcl134zjdiz8.narinfo error="server returned 404: 404 page not found\n"12962026/10/06 08:17:29 INFO Upload complete. (161ms)1297=== NAME TestNARDeduplicationMetadataUploadBug1298 metadata_upload_test.go:76: Retrieved narinfo from S3:1299 StorePath: /nix/var/nix/builds/nix-49438-1596666667/TestNARDeduplicationMetadataUploadBug4280468637/001/store/g7w2qqwf1v5zpdy1manxvcl134zjdiz8-file2.txt1300 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1301 Compression: zstd1302 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1303 NarSize: 1601304 References: 1305 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1306 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1307 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1308 {"version":1,"root":{"type":"regular","size":44}}1309--- PASS: TestNARDeduplicationMetadataUploadBug (3.29s)1310=== CONT TestCacheStatsHandler1311=== NAME TestOrphanedObjectsGCStressTest1312 orphaned_objects_gc_test.go:509: Stress test completed successfully:1313 orphaned_objects_gc_test.go:510: - Active objects preserved: 201314 orphaned_objects_gc_test.go:511: - Objects deleted: 2101315 orphaned_objects_gc_test.go:512: - Total GC'd: 2101316--- PASS: TestOrphanedObjectsGCStressTest (12.88s)1317=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13182026/10/06 08:17:30 WARN readiness check failed error="closed pool"1319--- PASS: TestService_readinessHandler (2.43s)1320=== CONT TestPinProtectsFromGC13212026/10/06 08:17:30 INFO Received uploads request method=POST path=/api/pending_closures13222026/10/06 08:17:30 INFO Received uploads request method=POST path=/api/pending_closures13232026/10/06 08:17:30 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13242026/10/06 08:17:30 INFO Uploading xs6l5yhsb4387ja5bs5md6ypdmwkgc4j-b (248B)13252026/10/06 08:17:30 INFO Uploading bvph8y7zp8vjhmr117z8049v8210wzgn-shared-dep (136B)13262026/10/06 08:17:30 WARN Failed to register uploaded object key=xs6l5yhsb4387ja5bs5md6ypdmwkgc4j.ls error="server returned 404: 404 page not found\n"13272026/10/06 08:17:30 WARN Failed to register uploaded object key=bvph8y7zp8vjhmr117z8049v8210wzgn.ls error="server returned 404: 404 page not found\n"13282026/10/06 08:17:30 WARN Failed to register uploaded object key=nar/0am97zm2jcvr5qdgiw4z8ynzfassmvncfpsid1waf2q5l394yqa1.nar.zst error="server returned 404: 404 page not found\n"13292026/10/06 08:17:30 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13302026/10/06 08:17:30 WARN Failed to register uploaded object key=d47qngz9l801j1rkirspbk0w0xnxjddr.ls error="server returned 404: 404 page not found\n"13312026/10/06 08:17:30 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13322026/10/06 08:17:30 INFO Signed narinfos id=1 count=213332026/10/06 08:17:30 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13342026/10/06 08:17:30 INFO Signed narinfos id=2 count=213352026/10/06 08:17:30 INFO Uploading 4 narinfos13362026/10/06 08:17:30 WARN Failed to register uploaded object key=d47qngz9l801j1rkirspbk0w0xnxjddr.narinfo error="server returned 404: 404 page not found\n"13372026/10/06 08:17:30 WARN Failed to register uploaded object key=bvph8y7zp8vjhmr117z8049v8210wzgn.narinfo error="server returned 404: 404 page not found\n"13382026/10/06 08:17:30 WARN Failed to register uploaded object key=xs6l5yhsb4387ja5bs5md6ypdmwkgc4j.narinfo error="server returned 404: 404 page not found\n"13392026/10/06 08:17:30 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13402026/10/06 08:17:30 WARN Failed to register uploaded object key=bvph8y7zp8vjhmr117z8049v8210wzgn.narinfo error="server returned 404: 404 page not found\n"13412026/10/06 08:17:30 INFO Completed upload id=113422026/10/06 08:17:30 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13432026/10/06 08:17:30 INFO Completed upload id=213442026/10/06 08:17:30 INFO Upload complete. (216ms)1345=== NAME TestClientFallsBackToClosures1346 client_pushes_test.go:112: Retrieved narinfo from S3:1347 StorePath: /nix/var/nix/builds/nix-49438-1596666667/TestClientFallsBackToClosures3788100089/001/store/bvph8y7zp8vjhmr117z8049v8210wzgn-shared-dep1348 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1349 Compression: zstd1350 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821351 NarSize: 1361352 References: 1353 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1354 client_pushes_test.go:112: Retrieved narinfo from S3:1355 StorePath: /nix/var/nix/builds/nix-49438-1596666667/TestClientFallsBackToClosures3788100089/001/store/d47qngz9l801j1rkirspbk0w0xnxjddr-a1356 URL: nar/0am97zm2jcvr5qdgiw4z8ynzfassmvncfpsid1waf2q5l394yqa1.nar.zst1357 Compression: zstd1358 NarHash: sha256:0am97zm2jcvr5qdgiw4z8ynzfassmvncfpsid1waf2q5l394yqa11359 NarSize: 2481360 References: /nix/var/nix/builds/nix-49438-1596666667/TestClientFallsBackToClosures3788100089/001/store/bvph8y7zp8vjhmr117z8049v8210wzgn-shared-dep1361 CA: text:sha256:1c1nsiscjllzmcfxmzin0g0m4d9b2s9dsc6n0cwcdsdcfzkichp51362 client_pushes_test.go:112: Retrieved narinfo from S3:1363 StorePath: /nix/var/nix/builds/nix-49438-1596666667/TestClientFallsBackToClosures3788100089/001/store/xs6l5yhsb4387ja5bs5md6ypdmwkgc4j-b1364 URL: nar/0am97zm2jcvr5qdgiw4z8ynzfassmvncfpsid1waf2q5l394yqa1.nar.zst1365 Compression: zstd1366 NarHash: sha256:0am97zm2jcvr5qdgiw4z8ynzfassmvncfpsid1waf2q5l394yqa11367 NarSize: 2481368 References: /nix/var/nix/builds/nix-49438-1596666667/TestClientFallsBackToClosures3788100089/001/store/bvph8y7zp8vjhmr117z8049v8210wzgn-shared-dep1369 CA: text:sha256:1c1nsiscjllzmcfxmzin0g0m4d9b2s9dsc6n0cwcdsdcfzkichp51370--- PASS: TestClientFallsBackToClosures (3.16s)1371=== CONT TestService_AuthMiddleware_MTLSProxyHeader13722026/10/06 08:17:31 INFO lead: acquired remote=192.0.2.1:12341373--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (3.45s)1374=== CONT TestService_AuthMiddleware_OIDC13752026/10/06 08:17:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65396/oidc1376--- PASS: TestService_healthCheckHandler (2.90s)1377=== CONT TestService_RequireScope_OIDC13782026/10/06 08:17:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65398/oidc1379{"timestamp":"2026-10-06T08:17:31.904524Z","level":"ERROR","message":"Scanner cycle completed without a durable data usage snapshot","event":"scanner_persist_state","component":"scanner","subsystem":"runtime","cycle":4,"outcome":"NoUpdate","state":"usage_not_durable","target":"rustfs::scanner","filename":"crates/scanner/src/scanner.rs","line_number":2350,"threadName":"rustfs-worker","threadId":"ThreadId(11)"}1380--- PASS: TestService_ReadAuthMiddleware (2.90s)1381=== CONT TestCacheConfigHandler1382=== RUN TestCacheConfigHandler/full_config,_no_issuer1383=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1384=== RUN TestCacheConfigHandler/no_cache_url_configured1385=== PAUSE TestCacheConfigHandler/no_cache_url_configured1386=== RUN TestCacheConfigHandler/no_signing_keys1387=== PAUSE TestCacheConfigHandler/no_signing_keys1388=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1389=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1390=== CONT TestService_ReadScope_PublicByDefault13912026/10/06 08:17:32 INFO lead: released remote=192.0.2.1:12341392--- PASS: TestLeadEndsOnShutdown (3.81s)1393=== CONT TestGCTaskStore_DeduplicateSameParams1394--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1395=== CONT TestClientSharedPathCommittedMidPush13962026/10/06 08:17:32 INFO Received push request method=POST path=/api/pushes13972026/10/06 08:17:32 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"13982026/10/06 08:17:32 WARN mTLS auth: bound subjects configured but subject DN unavailable13992026/10/06 08:17:32 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1400--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.88s)1401=== CONT TestClientErrorHandling1402=== RUN TestClientErrorHandling/InvalidStorePath1403=== PAUSE TestClientErrorHandling/InvalidStorePath1404=== RUN TestClientErrorHandling/InvalidAuthToken1405=== PAUSE TestClientErrorHandling/InvalidAuthToken1406=== RUN TestClientErrorHandling/ServerNotAvailable1407=== PAUSE TestClientErrorHandling/ServerNotAvailable1408=== CONT TestClientCADerivations14092026/10/06 08:17:32 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14102026/10/06 08:17:32 INFO Uploading lzckj83qwjs0gml5kv6h5xg8347jcvfb-b (248B)14112026/10/06 08:17:32 INFO Uploading qfbwjf89h2ma2lk3b0qqg0rz8p90yicf-shared-dep (136B)14122026/10/06 08:17:32 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14132026/10/06 08:17:32 WARN Failed to register uploaded object key=8dbcnnvn5l6bwfhfsyjj6zlw0ihk8931.ls error="server returned 404: 404 page not found\n"14142026/10/06 08:17:32 WARN Failed to register uploaded object key=nar/074zansdnwz7pz4z363bkh9hg76x6nmkv5avnldkba7k1g6fdcvg.nar.zst error="server returned 404: 404 page not found\n"14152026/10/06 08:17:32 WARN Failed to register uploaded object key=lzckj83qwjs0gml5kv6h5xg8347jcvfb.ls error="server returned 404: 404 page not found\n"14162026/10/06 08:17:32 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14172026/10/06 08:17:32 WARN Failed to register uploaded object key=qfbwjf89h2ma2lk3b0qqg0rz8p90yicf.ls error="server returned 404: 404 page not found\n"14182026/10/06 08:17:32 INFO Signed narinfos id=1 count=314192026/10/06 08:17:32 INFO Uploading 3 narinfos14202026/10/06 08:17:32 WARN Failed to register uploaded object key=lzckj83qwjs0gml5kv6h5xg8347jcvfb.narinfo error="server returned 404: 404 page not found\n"14212026/10/06 08:17:32 WARN Failed to register uploaded object key=8dbcnnvn5l6bwfhfsyjj6zlw0ihk8931.narinfo error="server returned 404: 404 page not found\n"14222026/10/06 08:17:32 INFO Received complete push request method=POST path=/api/pushes/1/complete14232026/10/06 08:17:32 WARN Failed to register uploaded object key=qfbwjf89h2ma2lk3b0qqg0rz8p90yicf.narinfo error="server returned 404: 404 page not found\n"14242026/10/06 08:17:32 INFO Upload complete. (279ms)1425=== NAME TestClientPushesUseOnePush1426 client_pushes_test.go:97: Retrieved narinfo from S3:1427 StorePath: /nix/var/nix/builds/nix-49438-1596666667/TestClientPushesUseOnePush4080912277/001/store/qfbwjf89h2ma2lk3b0qqg0rz8p90yicf-shared-dep1428 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1429 Compression: zstd1430 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821431 NarSize: 1361432 References: 1433 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1434 client_pushes_test.go:97: Retrieved narinfo from S3:1435 StorePath: /nix/var/nix/builds/nix-49438-1596666667/TestClientPushesUseOnePush4080912277/001/store/8dbcnnvn5l6bwfhfsyjj6zlw0ihk8931-a1436 URL: nar/074zansdnwz7pz4z363bkh9hg76x6nmkv5avnldkba7k1g6fdcvg.nar.zst1437 Compression: zstd1438 NarHash: sha256:074zansdnwz7pz4z363bkh9hg76x6nmkv5avnldkba7k1g6fdcvg1439 NarSize: 2481440 References: /nix/var/nix/builds/nix-49438-1596666667/TestClientPushesUseOnePush4080912277/001/store/qfbwjf89h2ma2lk3b0qqg0rz8p90yicf-shared-dep1441 CA: text:sha256:1b66jdi768nc892ixd6rvjfvk5n3baf05nqqnyms61r88q0a0l0a1442 client_pushes_test.go:97: Retrieved narinfo from S3:1443 StorePath: /nix/var/nix/builds/nix-49438-1596666667/TestClientPushesUseOnePush4080912277/001/store/lzckj83qwjs0gml5kv6h5xg8347jcvfb-b1444 URL: nar/074zansdnwz7pz4z363bkh9hg76x6nmkv5avnldkba7k1g6fdcvg.nar.zst1445 Compression: zstd1446 NarHash: sha256:074zansdnwz7pz4z363bkh9hg76x6nmkv5avnldkba7k1g6fdcvg1447 NarSize: 2481448 References: /nix/var/nix/builds/nix-49438-1596666667/TestClientPushesUseOnePush4080912277/001/store/qfbwjf89h2ma2lk3b0qqg0rz8p90yicf-shared-dep1449 CA: text:sha256:1b66jdi768nc892ixd6rvjfvk5n3baf05nqqnyms61r88q0a0l0a1450--- PASS: TestClientPushesUseOnePush (3.76s)1451=== CONT TestClientIntegration1452--- PASS: TestCacheStatsHandler (3.42s)1453=== CONT TestClientWithDependencies1454--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (2.75s)1455=== CONT TestClientMultipleUploads1456=== NAME TestPinProtectsFromGC1457 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-49438-1596666667/TestPinProtectsFromGC3937537890/001/store/zk4clyrhfk2rspv8fn0rfcz0gzyhhm03-pinned-file.txt1458 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-49438-1596666667/TestPinProtectsFromGC3937537890/001/store/whyhqwj285kirzgaj375wqvp2m8ppjn7-unpinned-file.txt14592026/10/06 08:17:33 INFO Received push request method=POST path=/api/pushes14602026/10/06 08:17:33 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14612026/10/06 08:17:33 INFO Uploading zk4clyrhfk2rspv8fn0rfcz0gzyhhm03-pinned-file.txt (128B)14622026/10/06 08:17:34 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14632026/10/06 08:17:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14642026/10/06 08:17:34 INFO Signed narinfos id=1 count=114652026/10/06 08:17:34 WARN Failed to register uploaded object key=zk4clyrhfk2rspv8fn0rfcz0gzyhhm03.ls error="server returned 404: 404 page not found\n"14662026/10/06 08:17:34 INFO Uploading 1 narinfos14672026/10/06 08:17:34 INFO Received complete push request method=POST path=/api/pushes/1/complete14682026/10/06 08:17:34 WARN Failed to register uploaded object key=zk4clyrhfk2rspv8fn0rfcz0gzyhhm03.narinfo error="server returned 404: 404 page not found\n"14692026/10/06 08:17:34 INFO Upload complete. (174ms)1470=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1471=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1472=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1473=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1474=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1475=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1476=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1477=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1478=== CONT TestProxyWriteTimeout/narinfo1479=== CONT TestPendingClosureWriteTimeout/empty1480=== CONT TestProxyWriteTimeout/10_GiB_nar1481=== CONT TestProxyWriteTimeout/1_GiB_nar1482=== CONT TestProxyWriteTimeout/unknown_size1483--- PASS: TestProxyWriteTimeout (0.01s)1484 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1485 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1486 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1487 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1488=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info14892026/10/06 08:17:34 INFO Received uploads request method=POST path=/1490=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key14912026/10/06 08:17:34 INFO Received request for more parts method=POST path=/1492=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key14932026/10/06 08:17:34 INFO Received complete multipart upload request method=POST path=/1494=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal14952026/10/06 08:17:34 INFO Received uploads request method=POST path=/1496--- PASS: TestUploadHandlersRejectInvalidKeys (0.01s)1497 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1498 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1499 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1500 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1501=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline15022026/10/06 08:17:34 INFO Received push request method=POST path=/api/pushes15032026/10/06 08:17:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15042026/10/06 08:17:34 INFO Uploading whyhqwj285kirzgaj375wqvp2m8ppjn7-unpinned-file.txt (128B)15052026/10/06 08:17:34 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15062026/10/06 08:17:34 WARN Failed to register uploaded object key=whyhqwj285kirzgaj375wqvp2m8ppjn7.ls error="server returned 404: 404 page not found\n"15072026/10/06 08:17:34 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15082026/10/06 08:17:34 INFO Signed narinfos id=2 count=115092026/10/06 08:17:34 INFO Uploading 1 narinfos15102026/10/06 08:17:34 INFO Received complete push request method=POST path=/api/pushes/2/complete15112026/10/06 08:17:34 WARN Failed to register uploaded object key=whyhqwj285kirzgaj375wqvp2m8ppjn7.narinfo error="server returned 404: 404 page not found\n"15122026/10/06 08:17:34 INFO Upload complete. (129ms)15132026/10/06 08:17:34 INFO Starting cleanup of old closures method=DELETE path=/api/closures15142026/10/06 08:17:34 INFO Garbage collection started15152026/10/06 08:17:34 INFO Aborted multipart uploads count=0 kept=015162026/10/06 08:17:34 WARN Force mode enabled - objects will be deleted immediately without grace period1517--- PASS: TestConnectWaitsForAPeerMigration (7.24s)1518=== CONT TestPendingClosureWriteTimeout/400_objects1519=== CONT TestIsValidUploadKey/narinfo1520=== CONT TestIsValidUploadKey/unknown_type1521=== CONT TestIsValidUploadKey/empty_key1522=== CONT TestIsValidUploadKey/absolute1523=== CONT TestIsValidUploadKey/traversal_nar1524=== CONT TestIsValidUploadKey/traversal1525=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1526=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1527=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1528=== CONT TestIsValidUploadKey/index.html15292026/10/06 08:17:34 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=01530=== CONT TestIsValidUploadKey/nix-cache-info1531=== CONT TestIsValidUploadKey/realisation_plus_in_output1532=== CONT TestIsValidUploadKey/realisation1533=== CONT TestIsValidUploadKey/build_log_equals1534=== CONT TestIsValidUploadKey/build_log_question_mark1535=== CONT TestIsValidUploadKey/build_log_plus_in_name1536=== CONT TestIsValidUploadKey/build_log_home-manager_file1537=== CONT TestIsValidUploadKey/build_log1538=== CONT TestIsValidUploadKey/listing1539=== CONT TestIsValidUploadKey/nar_plain1540=== CONT TestIsValidUploadKey/nar_xz1541=== CONT TestIsValidUploadKey/nar_zst1542--- PASS: TestIsValidUploadKey (0.01s)1543 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1544 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1545 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1546 --- PASS: TestIsValidUploadKey/absolute (0.00s)1547 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1548 --- PASS: TestIsValidUploadKey/traversal (0.00s)1549 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1550 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1551 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1552 --- PASS: TestIsValidUploadKey/index.html (0.00s)1553 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1554 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1555 --- PASS: TestIsValidUploadKey/realisation (0.00s)1556 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1557 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1558 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1559 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1560 --- PASS: TestIsValidUploadKey/build_log (0.00s)1561 --- PASS: TestIsValidUploadKey/listing (0.00s)1562 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1563 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1564 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1565=== CONT TestPendingClosureWriteTimeout/670k_objects1566=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure15672026/10/06 08:17:34 INFO Received uploads request method=POST path=/15682026/10/06 08:17:34 INFO Vacuumed table table=pending_closures15692026/10/06 08:17:34 INFO Vacuumed table table=pending_objects15702026/10/06 08:17:34 INFO Vacuumed table table=multipart_uploads1571=== RUN TestService_RequireScope_OIDC/builder_may_write1572=== PAUSE TestService_RequireScope_OIDC/builder_may_write1573=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1574=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1575=== RUN TestService_RequireScope_OIDC/ops_may_admin1576=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1577=== RUN TestService_RequireScope_OIDC/ops_may_not_write1578=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1579=== RUN TestService_RequireScope_OIDC/reader_may_not_write1580=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1581=== RUN TestService_RequireScope_OIDC/static_token_may_admin1582=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1583=== RUN TestService_RequireScope_OIDC/static_token_may_write1584=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1585=== RUN TestService_RequireScope_OIDC/reader_may_read1586=== PAUSE TestService_RequireScope_OIDC/reader_may_read1587=== RUN TestService_RequireScope_OIDC/writer_implies_read1588=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1589=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1590=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1591=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1592=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1593=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1594=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1595=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1596=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1597=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1598=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1599=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16002026/10/06 08:17:34 INFO Received request for more parts method=POST path=/16012026/10/06 08:17:34 INFO Vacuumed table table=closures1602=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16032026/10/06 08:17:34 INFO Received complete multipart upload request method=POST path=/1604=== CONT TestPush_RejectsBadRequests/no_roots16052026/10/06 08:17:34 INFO Received push request method=POST path=/api/pushes1606=== CONT TestPush_RejectsBadRequests/bad_root16072026/10/06 08:17:34 INFO Received push request method=POST path=/api/pushes1608=== CONT TestPush_RejectsBadRequests/root_not_in_objects16092026/10/06 08:17:34 INFO Received push request method=POST path=/api/pushes1610=== CONT TestPush_RejectsBadRequests/no_objects16112026/10/06 08:17:34 INFO Received push request method=POST path=/api/pushes1612=== CONT TestGCEndsOnShutdown/before_the_run1613--- PASS: TestPush_RejectsBadRequests (1.08s)1614 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1615 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1616 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1617 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)16182026/10/06 08:17:34 INFO Vacuumed table table=objects1619--- PASS: TestUploadHandlersRejectOversizedBody (0.03s)1620 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1621 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1622 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.30s)1623=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1624--- PASS: TestService_ReadScope_PublicByDefault (3.11s)1625=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete16262026/10/06 08:17:35 INFO Received push request method=POST path=/api/pushes16272026/10/06 08:17:35 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)16282026/10/06 08:17:35 INFO Uploading 0l2hp8wvvll3n56xsj0l4k67fn1qldh0-top (256B)16292026/10/06 08:17:35 INFO Uploading b7xb2jd3nks5cfxd7fp081bi38d8hs8w-shared-dep (136B)16302026/10/06 08:17:35 WARN Failed to register uploaded object key=0l2hp8wvvll3n56xsj0l4k67fn1qldh0.ls error="server returned 404: 404 page not found\n"16312026/10/06 08:17:35 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16322026/10/06 08:17:35 WARN Failed to register uploaded object key=b7xb2jd3nks5cfxd7fp081bi38d8hs8w.ls error="server returned 404: 404 page not found\n"16332026/10/06 08:17:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16342026/10/06 08:17:35 WARN Failed to register uploaded object key=nar/0l0173ga51p8n2mi1bhbadd08xqq0qqric8893z0x5xkb4a9napn.nar.zst error="server returned 404: 404 page not found\n"16352026/10/06 08:17:35 INFO Signed narinfos id=1 count=216362026/10/06 08:17:35 INFO Uploading 2 narinfos16372026/10/06 08:17:35 WARN Failed to register uploaded object key=0l2hp8wvvll3n56xsj0l4k67fn1qldh0.narinfo error="server returned 404: 404 page not found\n"16382026/10/06 08:17:35 INFO Received complete push request method=POST path=/api/pushes/1/complete16392026/10/06 08:17:35 WARN Failed to register uploaded object key=b7xb2jd3nks5cfxd7fp081bi38d8hs8w.narinfo error="server returned 404: 404 page not found\n"16402026/10/06 08:17:35 INFO Upload complete. (188ms)1641=== NAME TestClientSharedPathCommittedMidPush1642 client_integration_test.go:680: Retrieved narinfo from S3:1643 StorePath: /nix/var/nix/builds/nix-49438-1596666667/TestClientSharedPathCommittedMidPush2735213616/001/store/b7xb2jd3nks5cfxd7fp081bi38d8hs8w-shared-dep1644 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1645 Compression: zstd1646 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821647 NarSize: 1361648 References: 1649 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1650 client_integration_test.go:680: Retrieved narinfo from S3:1651 StorePath: /nix/var/nix/builds/nix-49438-1596666667/TestClientSharedPathCommittedMidPush2735213616/001/store/0l2hp8wvvll3n56xsj0l4k67fn1qldh0-top1652 URL: nar/0l0173ga51p8n2mi1bhbadd08xqq0qqric8893z0x5xkb4a9napn.nar.zst1653 Compression: zstd1654 NarHash: sha256:0l0173ga51p8n2mi1bhbadd08xqq0qqric8893z0x5xkb4a9napn1655 NarSize: 2561656 References: /nix/var/nix/builds/nix-49438-1596666667/TestClientSharedPathCommittedMidPush2735213616/001/store/b7xb2jd3nks5cfxd7fp081bi38d8hs8w-shared-dep1657 CA: text:sha256:0v7s3hk1l7r5nk0f1g5gzqw29139l4k8c3l6xxv9m05mn1yywfnf1658--- PASS: TestClientSharedPathCommittedMidPush (3.53s)1659=== CONT TestIsValidCachePath/narinfo1660=== CONT TestIsValidCachePath/index.html1661=== CONT TestIsValidCachePath/short_hash1662=== CONT TestIsValidCachePath/wrong_extension1663=== CONT TestIsValidCachePath/leading_slash1664=== CONT TestIsValidCachePath/empty1665=== CONT TestIsValidCachePath/random_path1666=== CONT TestIsValidCachePath/invalid_char_u1667=== CONT TestIsValidCachePath/invalid_char_e1668=== CONT TestIsValidCachePath/traversal_in_middle1669=== CONT TestIsValidCachePath/traversal_parent1670=== CONT TestIsValidCachePath/nar_uncompressed1671=== CONT TestIsValidCachePath/nix-cache-info1672=== CONT TestIsValidCachePath/realisation1673=== CONT TestIsValidCachePath/log1674=== CONT TestIsValidCachePath/ls1675=== CONT TestIsValidCachePath/nar_xz1676=== CONT TestIsValidCachePath/nar_bz21677=== CONT TestIsValidCachePath/nar_zst1678=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1679--- PASS: TestIsValidCachePath (0.00s)1680 --- PASS: TestIsValidCachePath/narinfo (0.00s)1681 --- PASS: TestIsValidCachePath/index.html (0.00s)1682 --- PASS: TestIsValidCachePath/short_hash (0.00s)1683 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1684 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1685 --- PASS: TestIsValidCachePath/empty (0.00s)1686 --- PASS: TestIsValidCachePath/random_path (0.00s)1687 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1688 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1689 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1690 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1691 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1692 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1693 --- PASS: TestIsValidCachePath/realisation (0.00s)1694 --- PASS: TestIsValidCachePath/log (0.00s)1695 --- PASS: TestIsValidCachePath/ls (0.00s)1696 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1697 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1698 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1699 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1700=== CONT TestParseSingleRange/none1701=== CONT TestParseSingleRange/open-ended1702=== CONT TestParseSingleRange/closed1703=== CONT TestParseSingleRange/malformed_end_before_start1704=== CONT TestParseSingleRange/malformed_both_empty1705=== CONT TestParseSingleRange/malformed_no_dash1706=== CONT TestParseSingleRange/multi-range_ignored1707=== CONT TestParseSingleRange/unknown_unit1708=== CONT TestParseSingleRange/end_clamped_to_size1709=== CONT TestParseSingleRange/single_byte1710=== CONT TestParseSingleRange/suffix_exceeds_size1711=== CONT TestParseSingleRange/suffix1712=== CONT TestParseSingleRange/start_past_EOF1713=== CONT TestParseSingleRange/start_far_past_EOF1714--- PASS: TestParseSingleRange (0.00s)1715 --- PASS: TestParseSingleRange/none (0.00s)1716 --- PASS: TestParseSingleRange/open-ended (0.00s)1717 --- PASS: TestParseSingleRange/closed (0.00s)1718 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1719 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1720 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1721 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1722 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1723 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1724 --- PASS: TestParseSingleRange/single_byte (0.00s)1725 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1726 --- PASS: TestParseSingleRange/suffix (0.00s)1727 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1728 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1729=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows17302026/10/06 08:17:36 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=017312026/10/06 08:17:36 INFO Received create pin request method=POST path=/api/pins/myapp17322026/10/06 08:17:36 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-49438-1596666667/TestPinProtectsFromGC3937537890/001/store/zk4clyrhfk2rspv8fn0rfcz0gzyhhm03-pinned-file.txt narinfo_key=zk4clyrhfk2rspv8fn0rfcz0gzyhhm03.narinfo17332026/10/06 08:17:36 INFO Starting cleanup of old closures method=DELETE path=/api/closures17342026/10/06 08:17:36 INFO Garbage collection started17352026/10/06 08:17:36 INFO Aborted multipart uploads count=0 kept=017362026/10/06 08:17:36 WARN Force mode enabled - objects will be deleted immediately without grace period17372026/10/06 08:17: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=017382026/10/06 08:17:36 INFO Vacuumed table table=pending_closures17392026/10/06 08:17:36 INFO Vacuumed table table=pending_objects17402026/10/06 08:17:36 INFO Vacuumed table table=multipart_uploads17412026/10/06 08:17:36 INFO Vacuumed table table=closures17422026/10/06 08:17:36 INFO Vacuumed table table=objects1743=== NAME TestClientCADerivations1744 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-49438-1596666667/TestClientCADerivations286368368/001/store/1vi5ypg8yn8qcszn3jc1xibxjgxarzhx-ca-test1745=== NAME TestClientIntegration1746 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-49438-1596666667/TestClientIntegration3507377287/002/store/1x4jbh460bk1ag34l7spmrdhzxgpc51l-test-file.txt1747=== NAME TestClientCADerivations1748 client_ca_test.go:139: Found 1 dependencies (including self)17492026/10/06 08:17:36 INFO Received push request method=POST path=/api/pushes17502026/10/06 08:17:36 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17512026/10/06 08:17:36 INFO Uploading 1x4jbh460bk1ag34l7spmrdhzxgpc51l-test-file.txt (152B)17522026/10/06 08:17:36 WARN Failed to register uploaded object key=1x4jbh460bk1ag34l7spmrdhzxgpc51l.ls error="server returned 404: 404 page not found\n"17532026/10/06 08:17:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17542026/10/06 08:17:36 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17552026/10/06 08:17:36 INFO Signed narinfos id=1 count=117562026/10/06 08:17:36 INFO Uploading 1 narinfos17572026/10/06 08:17:36 INFO Received complete push request method=POST path=/api/pushes/1/complete17582026/10/06 08:17:36 WARN Failed to register uploaded object key=1x4jbh460bk1ag34l7spmrdhzxgpc51l.narinfo error="server returned 404: 404 page not found\n"17592026/10/06 08:17:36 INFO Upload complete. (151ms)17602026/10/06 08:17:36 INFO Received push request method=POST path=/api/pushes17612026/10/06 08:17:36 INFO All 1 paths already cached1762=== NAME TestClientIntegration1763 client_integration_test.go:312: Retrieved narinfo from S3:1764 StorePath: /nix/var/nix/builds/nix-49438-1596666667/TestClientIntegration3507377287/002/store/1x4jbh460bk1ag34l7spmrdhzxgpc51l-test-file.txt1765 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1766 Compression: zstd1767 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11768 NarSize: 1521769 References: 1770 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11771 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1772 client_integration_test.go:313: Decompressed .ls content (64 bytes):1773 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1774 client_integration_test.go:316: Testing garbage collection...17752026/10/06 08:17:36 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17762026/10/06 08:17:36 INFO Uploading 1vi5ypg8yn8qcszn3jc1xibxjgxarzhx-ca-test (144B)17772026/10/06 08:17:36 INFO Starting cleanup of old closures method=DELETE path=/api/closures17782026/10/06 08:17:36 INFO Garbage collection started17792026/10/06 08:17:36 INFO Aborted multipart uploads count=0 kept=017802026/10/06 08:17:36 WARN Force mode enabled - objects will be deleted immediately without grace period17812026/10/06 08:17:36 WARN Failed to register uploaded object key=1vi5ypg8yn8qcszn3jc1xibxjgxarzhx.ls error="server returned 404: 404 page not found\n"17822026/10/06 08:17:36 WARN Failed to register uploaded object key=log/nm1kmmqym92yb4i5yjjwfbc54rzyyikv-ca-test.drv error="server returned 404: 404 page not found\n"17832026/10/06 08:17:36 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"17842026/10/06 08:17:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17852026/10/06 08:17:36 INFO Signed narinfos id=1 count=117862026/10/06 08:17:36 INFO Uploading 1 narinfos17872026/10/06 08:17:36 INFO Received complete push request method=POST path=/api/pushes/1/complete17882026/10/06 08:17:36 WARN Failed to register uploaded object key=1vi5ypg8yn8qcszn3jc1xibxjgxarzhx.narinfo error="server returned 404: 404 page not found\n"17892026/10/06 08:17:36 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=017902026/10/06 08:17:36 INFO Upload complete. (269ms)1791=== NAME TestClientCADerivations1792 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-49438-1596666667/TestClientCADerivations286368368/001/store/1vi5ypg8yn8qcszn3jc1xibxjgxarzhx-ca-test1793 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1794 Compression: zstd1795 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1796 NarSize: 1441797 References: 1798 Deriver: /nix/var/nix/builds/nix-49438-1596666667/TestClientCADerivations286368368/001/store/nm1kmmqym92yb4i5yjjwfbc54rzyyikv-ca-test.drv1799 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1800 client_ca_test.go:185: Checking for realisation files in S3...1801 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1802 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache18032026/10/06 08:17:36 INFO Vacuumed table table=pending_closures18042026/10/06 08:17:36 INFO Vacuumed table table=pending_objects18052026/10/06 08:17:36 INFO Vacuumed table table=multipart_uploads18062026/10/06 08:17:36 INFO Vacuumed table table=closures18072026/10/06 08:17:36 INFO Vacuumed table table=objects1808 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket80?endpoint=http://localhost:65099®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-49438-1596666667/TestClientCADerivations286368368/001/store'1809 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11810=== NAME TestClientWithDependencies1811 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-49438-1596666667/TestClientWithDependencies2272201351/001/store/s54j595fdyvk3m81bnzcgdzs5kwki33m-test-script1812 client_integration_test.go:615: Found 1 dependencies (including self)1813--- PASS: TestClientCADerivations (4.45s)1814=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check18152026/10/06 08:17:37 INFO Received push request method=POST path=/api/pushes18162026/10/06 08:17:37 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18172026/10/06 08:17:37 INFO Uploading s54j595fdyvk3m81bnzcgdzs5kwki33m-test-script (136B)18182026/10/06 08:17:37 WARN Failed to register uploaded object key=s54j595fdyvk3m81bnzcgdzs5kwki33m.ls error="server returned 404: 404 page not found\n"18192026/10/06 08:17:37 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"18202026/10/06 08:17:37 WARN Failed to register uploaded object key=log/vg8gnbac4rs9rs51gr1n6858ma4ii2yf-test-script.drv error="server returned 404: 404 page not found\n"18212026/10/06 08:17:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18222026/10/06 08:17:37 INFO Signed narinfos id=1 count=118232026/10/06 08:17:37 INFO Uploading 1 narinfos18242026/10/06 08:17:37 INFO Received complete push request method=POST path=/api/pushes/1/complete18252026/10/06 08:17:37 WARN Failed to register uploaded object key=s54j595fdyvk3m81bnzcgdzs5kwki33m.narinfo error="server returned 404: 404 page not found\n"1826=== NAME TestClientMultipleUploads1827 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-49438-1596666667/TestClientMultipleUploads2889574116/001/store/z65ajfrzyqx0a2bnpdwxdsx307jqykrs-test-file-0.txt18282026/10/06 08:17:37 INFO Upload complete. (182ms)1829=== NAME TestClientWithDependencies1830 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-49438-1596666667/TestClientWithDependencies2272201351/001/store) requires matching store prefix1831=== NAME TestClientMultipleUploads1832 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-49438-1596666667/TestClientMultipleUploads2889574116/001/store/5yip4si3frmnch5sbvbn0cqvikvpv6n2-test-file-1.txt1833--- PASS: TestClientWithDependencies (4.32s)1834=== CONT TestServerTLSConfig/no_client_CA1835=== CONT TestServerTLSConfig/not_a_PEM_file1836=== CONT TestServerTLSConfig/missing_CA_file1837--- PASS: TestServerTLSConfig (0.00s)1838 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1839 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.02s)1840 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1841=== CONT TestResolveDBConnectionString/flag_wins1842=== CONT TestResolveDBConnectionString/missing_file_is_an_error1843=== CONT TestResolveDBConnectionString/file_when_flag_empty1844=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1845=== CONT TestResolveDBConnectionString/nothing_configured1846=== CONT TestCacheConfigHandler/full_config,_no_issuer1847=== CONT TestCacheConfigHandler/no_signing_keys1848=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1849=== CONT TestCacheConfigHandler/no_cache_url_configured1850--- PASS: TestCacheConfigHandler (0.00s)1851 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1852 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1853 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1854 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1855=== CONT TestClientErrorHandling/InvalidStorePath1856--- PASS: TestResolveDBConnectionString (0.02s)1857 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1858 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1859 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1860 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1861 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)18622026/10/06 08:17:37 INFO Received uploads request method=POST path=/api/pending_closures1863=== NAME TestClientMultipleUploads1864 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-49438-1596666667/TestClientMultipleUploads2889574116/001/store/c9wlqpn9bv8vcqks24sff1lc85zrkdfr-test-file-2.txt18652026/10/06 08:17:37 INFO Received push request method=POST path=/api/pushes18662026/10/06 08:17:37 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)18672026/10/06 08:17:37 INFO Uploading 5yip4si3frmnch5sbvbn0cqvikvpv6n2-test-file-1.txt (160B)18682026/10/06 08:17:37 INFO Uploading z65ajfrzyqx0a2bnpdwxdsx307jqykrs-test-file-0.txt (160B)18692026/10/06 08:17:37 INFO Uploading c9wlqpn9bv8vcqks24sff1lc85zrkdfr-test-file-2.txt (160B)18702026/10/06 08:17:37 WARN Failed to register uploaded object key=c9wlqpn9bv8vcqks24sff1lc85zrkdfr.ls error="server returned 404: 404 page not found\n"18712026/10/06 08:17:37 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"18722026/10/06 08:17:37 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"18732026/10/06 08:17:37 WARN Failed to register uploaded object key=5yip4si3frmnch5sbvbn0cqvikvpv6n2.ls error="server returned 404: 404 page not found\n"18742026/10/06 08:17:37 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"18752026/10/06 08:17:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18762026/10/06 08:17:37 WARN Failed to register uploaded object key=z65ajfrzyqx0a2bnpdwxdsx307jqykrs.ls error="server returned 404: 404 page not found\n"18772026/10/06 08:17:37 INFO Signed narinfos id=1 count=318782026/10/06 08:17:37 INFO Uploading 3 narinfos18792026/10/06 08:17:37 WARN Failed to register uploaded object key=c9wlqpn9bv8vcqks24sff1lc85zrkdfr.narinfo error="server returned 404: 404 page not found\n"18802026/10/06 08:17:37 WARN Failed to register uploaded object key=z65ajfrzyqx0a2bnpdwxdsx307jqykrs.narinfo error="server returned 404: 404 page not found\n"18812026/10/06 08:17:37 INFO Received complete push request method=POST path=/api/pushes/1/complete18822026/10/06 08:17:37 WARN Failed to register uploaded object key=5yip4si3frmnch5sbvbn0cqvikvpv6n2.narinfo error="server returned 404: 404 page not found\n"18832026/10/06 08:17:37 INFO Upload complete. (201ms)1884 client_integration_test.go:369: Uploaded 3 paths in 235.892ms1885=== CONT TestClientErrorHandling/ServerNotAvailable1886--- PASS: TestClientMultipleUploads (4.04s)1887=== CONT TestClientErrorHandling/InvalidAuthToken18882026/10/06 08:17:38 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/present18892026/10/06 08:17:38 INFO Aborted multipart uploads count=0 kept=018902026/10/06 08:17:38 WARN Force mode enabled - objects will be deleted immediately without grace period18912026-10-06 08:17:38.100 UTC [52331] ERROR: canceling statement due to user request18922026-10-06 08:17:38.100 UTC [52331] STATEMENT: -- name: MarkStaleObjects :execrows1893 WITH RECURSIVE ct AS (1894 SELECT timezone('UTC', now()) AS now1895 ),1896 closure_reach AS (1897 -- Start with all closure keys1898 SELECT o.key, o.refs1899 FROM objects o1900 INNER JOIN closures c ON o.key = c.key1901 UNION1902 -- Recursively add all referenced objects1903 SELECT o.key, o.refs1904 FROM objects o1905 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1906 ),1907 reachable_objects AS (1908 SELECT DISTINCT key FROM closure_reach1909 ),1910 stale_objects AS (1911 SELECT o.key1912 FROM objects AS o, ct1913 WHERE1914 NOT EXISTS (1915 SELECT 11916 FROM reachable_objects ro1917 WHERE ro.key = o.key1918 )1919 AND NOT EXISTS (1920 SELECT 11921 FROM pending_objects AS po1922 WHERE po.key = o.key1923 )1924 AND o.deleted_at IS NULL -- Only mark fresh objects1925 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure1926 FOR UPDATE1927 )1928 UPDATE objects1929 SET1930 deleted_at = ct.now,1931 first_deleted_at = COALESCE(first_deleted_at, ct.now)1932 FROM stale_objects, ct1933 WHERE objects.key = stale_objects.key1934 1935=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1936=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1937=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19382026/10/06 08:17:38 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]1939=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19402026/10/06 08:17:38 WARN Authentication failed token_preview=eyJhbGciOi...00H9R16WAA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1941=== CONT TestService_RequireScope_OIDC/builder_may_write1942=== CONT TestService_RequireScope_OIDC/static_token_may_write1943=== CONT TestService_RequireScope_OIDC/static_token_may_admin1944=== CONT TestService_RequireScope_OIDC/reader_may_not_write1945=== CONT TestService_RequireScope_OIDC/ops_may_not_write1946=== CONT TestService_RequireScope_OIDC/ops_may_admin1947=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1948=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1949=== CONT TestService_RequireScope_OIDC/reader_may_read1950=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1951=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1952=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1953=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19542026/10/06 08:17:38 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]1955=== CONT TestService_RequireScope_OIDC/writer_implies_read1956--- PASS: TestService_RequireScope_OIDC (3.00s)1957 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1958 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1959 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1960 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1961 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1962 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1963 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1964 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1965 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1966 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1967 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1968 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1969 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1970 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1971--- PASS: TestService_AuthMiddleware_OIDC (2.84s)1972 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1973 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1974 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1975 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)19762026/10/06 08:17:38 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=182.261652ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1977--- PASS: TestPendingClosureWriteTimeout (0.01s)1978 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1979 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1980 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1981 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (4.11s)1982=== NAME TestPinProtectsFromGC1983 client_integration_test.go:840: Pin successfully protected closure from garbage collection19842026/10/06 08:17:38 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=410.996803ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1985--- PASS: TestPinProtectsFromGC (7.72s)19862026/10/06 08:17:38 INFO Aborted multipart uploads count=0 kept=019872026/10/06 08:17:38 WARN Force mode enabled - objects will be deleted immediately without grace period19882026/10/06 08:17:38 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:65099/bucket87/?delete=\": context canceled"1989--- PASS: TestGCEndsOnShutdown (0.00s)1990 --- PASS: TestGCEndsOnShutdown/before_the_run (3.28s)1991 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (3.43s)1992 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (3.20s)19932026/10/06 08:17:38 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01994=== NAME TestClientIntegration1995 client_integration_test.go:323: Objects in database after GC:1996 client_integration_test.go:323: Successfully deleted all objects with GC --force1997--- PASS: TestClientIntegration (5.87s)19982026/10/06 08:17:38 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=829.615375ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19992026/10/06 08:17:38 INFO Received uploads request method=POST path=/api/pending_closures20002026/10/06 08:17:38 INFO Aborted multipart uploads count=0 kept=020012026/10/06 08:17:38 WARN Force mode enabled - objects will be deleted immediately without grace period20022026/10/06 08:17:38 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=020032026/10/06 08:17:38 INFO Vacuumed table table=pending_closures20042026/10/06 08:17:38 INFO Vacuumed table table=pending_objects20052026/10/06 08:17:38 INFO Vacuumed table table=multipart_uploads20062026/10/06 08:17:38 INFO Vacuumed table table=closures20072026/10/06 08:17:39 INFO Vacuumed table table=objects20082026/10/06 08:17:39 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.669737685s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20092026/10/06 08:17:39 INFO Received uploads request method=POST path=/api/pending_closures20102026/10/06 08:17:39 INFO Aborted multipart uploads count=0 kept=020112026/10/06 08:17:39 WARN Force mode enabled - objects will be deleted immediately without grace period20122026/10/06 08:17:39 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=020132026/10/06 08:17:39 INFO Vacuumed table table=pending_closures20142026/10/06 08:17:39 INFO Vacuumed table table=pending_objects20152026/10/06 08:17:39 INFO Vacuumed table table=multipart_uploads20162026/10/06 08:17:39 INFO Vacuumed table table=closures20172026/10/06 08:17:39 INFO Vacuumed table table=objects2018--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2019 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (3.35s)2020 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (2.92s)20212026/10/06 08:17:40 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20222026/10/06 08:17:40 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2023{"timestamp":"2026-10-06T08:17:41.162Z","level":"ERROR","message":"Scanner cycle completed without a durable data usage snapshot","event":"scanner_persist_state","component":"scanner","subsystem":"runtime","cycle":4,"outcome":"NoUpdate","state":"usage_not_durable","target":"rustfs::scanner","filename":"crates/scanner/src/scanner.rs","line_number":2350,"threadName":"rustfs-worker","threadId":"ThreadId(11)"}20242026/10/06 08:17:41 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-config20252026/10/06 08:17:41 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=217.052592ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20262026/10/06 08:17:41 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=433.312307ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20272026/10/06 08:17:42 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=839.944687ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20282026/10/06 08:17:42 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.74524034s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20292026/10/06 08:17:44 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"20302026/10/06 08:17:44 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-config20312026/10/06 08:17:44 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=187.106188ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20322026/10/06 08:17:44 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=438.617269ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20332026/10/06 08:17:45 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=840.196867ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20342026/10/06 08:17:46 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.751719448s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2035{"timestamp":"2026-10-06T08:17:46.689101Z","level":"ERROR","message":"Scanner cycle completed without a durable data usage snapshot","event":"scanner_persist_state","component":"scanner","subsystem":"runtime","cycle":4,"outcome":"NoUpdate","state":"usage_not_durable","target":"rustfs::scanner","filename":"crates/scanner/src/scanner.rs","line_number":2350,"threadName":"rustfs-worker","threadId":"ThreadId(8)"}20362026/10/06 08:17:47 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_closures20372026/10/06 08:17:48 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=212.836247ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20382026/10/06 08:17:48 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=399.607402ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20392026/10/06 08:17:48 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=813.140485ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20402026/10/06 08:17:49 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.536480695s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2041--- PASS: TestClientErrorHandling (0.00s)2042 --- PASS: TestClientErrorHandling/InvalidStorePath (2.75s)2043 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.77s)2044 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.29s)2045PASS20462026-10-06 08:17:51.319 UTC [49627] LOG: received smart shutdown request20472026-10-06 08:17:51.321 UTC [49627] LOG: background worker "logical replication launcher" (PID 49641) exited with exit code 120482026-10-06 08:17:51.329 UTC [49635] LOG: shutting down20492026-10-06 08:17:51.329 UTC [49635] LOG: checkpoint starting: shutdown immediate20502026-10-06 08:17:53.495 UTC [49635] LOG: checkpoint complete: wrote 12736 buffers (77.7%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 27 recycled; write=0.949 s, sync=1.189 s, total=2.167 s; sync files=30999, longest=0.033 s, average=0.001 s; distance=435748 kB, estimate=435748 kB; lsn=0/1C116238, redo lsn=0/1C11623820512026-10-06 08:17:53.505 UTC [49627] LOG: database system is shut down2052Running OIDC tests...2053=== RUN TestAudienceForIssuer2054=== PAUSE TestAudienceForIssuer2055=== RUN TestGlobMatch2056=== PAUSE TestGlobMatch2057=== RUN TestValidateToken_ValidToken2058=== PAUSE TestValidateToken_ValidToken2059=== RUN TestValidateToken_WrongAudience2060=== PAUSE TestValidateToken_WrongAudience2061=== RUN TestValidateToken_Expired2062=== PAUSE TestValidateToken_Expired2063=== RUN TestValidateToken_BoundClaimsMismatch2064=== PAUSE TestValidateToken_BoundClaimsMismatch2065=== RUN TestValidateToken_BoundSubjectMismatch2066=== PAUSE TestValidateToken_BoundSubjectMismatch2067=== RUN TestValidateToken_MultipleProviders2068=== PAUSE TestValidateToken_MultipleProviders2069=== RUN TestValidateToken_NoMatchingProvider2070=== PAUSE TestValidateToken_NoMatchingProvider2071=== RUN TestValidateToken_KubernetesServiceAccount2072=== PAUSE TestValidateToken_KubernetesServiceAccount2073=== RUN TestNewValidator_KubernetesRequiresCA2074=== PAUSE TestNewValidator_KubernetesRequiresCA2075=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2076=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2077=== RUN TestPins_ReservedForMatchingRule2078=== PAUSE TestPins_ReservedForMatchingRule2079=== RUN TestPins_TopLevelShorthand2080=== PAUSE TestPins_TopLevelShorthand2081=== RUN TestPins_ConfigValidation2082=== PAUSE TestPins_ConfigValidation2083=== RUN TestScopes_LegacyProviderDefaultsToWrite2084=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2085=== RUN TestScopes_Rules2086=== PAUSE TestScopes_Rules2087=== RUN TestScopes_ConfigValidation2088=== PAUSE TestScopes_ConfigValidation2089=== CONT TestAudienceForIssuer2090--- PASS: TestAudienceForIssuer (0.00s)2091=== CONT TestScopes_ConfigValidation2092=== CONT TestValidateToken_KubernetesServiceAccount2093=== CONT TestPins_TopLevelShorthand2094=== CONT TestValidateToken_BoundClaimsMismatch2095=== CONT TestValidateToken_MultipleProviders2096--- PASS: TestScopes_ConfigValidation (0.00s)2097=== CONT TestValidateToken_Expired2098=== CONT TestValidateToken_NoMatchingProvider2099=== CONT TestValidateToken_BoundSubjectMismatch2100=== CONT TestValidateToken_ValidToken2101=== CONT TestNewValidator_KubernetesRequiresCA2102=== CONT TestValidateToken_KubernetesIssuerFromOwnToken21032026/10/06 08:17:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49210/oidc2104--- PASS: TestValidateToken_BoundClaimsMismatch (0.02s)2105=== CONT TestScopes_Rules21062026/10/06 08:17:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49213/oidc2107--- PASS: TestValidateToken_ValidToken (0.19s)2108=== CONT TestScopes_LegacyProviderDefaultsToWrite21092026/10/06 08:17:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49215/oidc2110--- PASS: TestPins_TopLevelShorthand (0.21s)2111=== CONT TestPins_ConfigValidation2112--- PASS: TestPins_ConfigValidation (0.00s)2113=== CONT TestGlobMatch2114=== RUN TestGlobMatch/foo_foo2115=== PAUSE TestGlobMatch/foo_foo2116=== RUN TestGlobMatch/foo_bar2117=== PAUSE TestGlobMatch/foo_bar2118=== RUN TestGlobMatch/*_2119=== PAUSE TestGlobMatch/*_2120=== RUN TestGlobMatch/*_anything2121=== PAUSE TestGlobMatch/*_anything2122=== RUN TestGlobMatch/foo*_foo2123=== PAUSE TestGlobMatch/foo*_foo2124=== RUN TestGlobMatch/foo*_foobar2125=== PAUSE TestGlobMatch/foo*_foobar2126=== RUN TestGlobMatch/foo*_bar2127=== PAUSE TestGlobMatch/foo*_bar2128=== RUN TestGlobMatch/*bar_bar2129=== PAUSE TestGlobMatch/*bar_bar2130=== RUN TestGlobMatch/*bar_foobar2131=== PAUSE TestGlobMatch/*bar_foobar2132=== RUN TestGlobMatch/*bar_foo2133=== PAUSE TestGlobMatch/*bar_foo2134=== RUN TestGlobMatch/foo*bar_foobar2135=== PAUSE TestGlobMatch/foo*bar_foobar2136=== RUN TestGlobMatch/foo*bar_foo123bar2137=== PAUSE TestGlobMatch/foo*bar_foo123bar2138=== RUN TestGlobMatch/foo*bar_foobarbaz2139=== PAUSE TestGlobMatch/foo*bar_foobarbaz2140=== RUN TestGlobMatch/*/*_foo/bar2141=== PAUSE TestGlobMatch/*/*_foo/bar2142=== RUN TestGlobMatch/*/*_foo2143=== PAUSE TestGlobMatch/*/*_foo2144=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2145=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2146=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02147=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02148=== RUN TestGlobMatch/refs/*/main_refs/heads/main2149=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2150=== RUN TestGlobMatch/fo?_foo2151=== PAUSE TestGlobMatch/fo?_foo2152=== RUN TestGlobMatch/fo?_fo2153=== PAUSE TestGlobMatch/fo?_fo2154=== RUN TestGlobMatch/fo?_fooo2155=== PAUSE TestGlobMatch/fo?_fooo2156=== RUN TestGlobMatch/?oo_foo2157=== PAUSE TestGlobMatch/?oo_foo2158=== RUN TestGlobMatch/?oo_boo2159=== PAUSE TestGlobMatch/?oo_boo2160=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2161=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2162=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2163=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2164=== CONT TestValidateToken_WrongAudience21652026/10/06 08:17:56 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:492172166--- PASS: TestValidateToken_KubernetesServiceAccount (0.25s)2167=== CONT TestPins_ReservedForMatchingRule21682026/10/06 08:17:56 http: TLS handshake error from 127.0.0.1:49220: read tcp 127.0.0.1:49219->127.0.0.1:49220: use of closed network connection2169--- PASS: TestNewValidator_KubernetesRequiresCA (0.27s)2170=== CONT TestGlobMatch/foo_foo2171=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2172=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2173=== CONT TestGlobMatch/?oo_boo2174=== CONT TestGlobMatch/?oo_foo2175=== CONT TestGlobMatch/fo?_fooo2176=== CONT TestGlobMatch/fo?_fo2177=== CONT TestGlobMatch/fo?_foo2178=== CONT TestGlobMatch/refs/*/main_refs/heads/main2179=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02180=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2181=== CONT TestGlobMatch/*/*_foo2182=== CONT TestGlobMatch/*/*_foo/bar2183=== CONT TestGlobMatch/foo*bar_foobarbaz2184=== CONT TestGlobMatch/foo*bar_foo123bar2185=== CONT TestGlobMatch/foo*bar_foobar2186=== CONT TestGlobMatch/*bar_foo2187=== CONT TestGlobMatch/*bar_foobar2188=== CONT TestGlobMatch/*bar_bar2189=== CONT TestGlobMatch/foo*_bar2190=== CONT TestGlobMatch/foo*_foobar2191=== CONT TestGlobMatch/foo*_foo2192=== CONT TestGlobMatch/*_anything2193=== CONT TestGlobMatch/*_2194=== CONT TestGlobMatch/foo_bar2195--- PASS: TestGlobMatch (0.00s)2196 --- PASS: TestGlobMatch/foo_foo (0.00s)2197 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2198 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2199 --- PASS: TestGlobMatch/?oo_boo (0.00s)2200 --- PASS: TestGlobMatch/?oo_foo (0.00s)2201 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2202 --- PASS: TestGlobMatch/fo?_fo (0.00s)2203 --- PASS: TestGlobMatch/fo?_foo (0.00s)2204 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2205 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2206 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2207 --- PASS: TestGlobMatch/*/*_foo (0.00s)2208 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2209 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2210 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2211 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2212 --- PASS: TestGlobMatch/*bar_foo (0.00s)2213 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2214 --- PASS: TestGlobMatch/*bar_bar (0.00s)2215 --- PASS: TestGlobMatch/foo*_bar (0.00s)2216 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2217 --- PASS: TestGlobMatch/foo*_foo (0.00s)2218 --- PASS: TestGlobMatch/*_anything (0.00s)2219 --- PASS: TestGlobMatch/*_ (0.00s)2220 --- PASS: TestGlobMatch/foo_bar (0.00s)22212026/10/06 08:17:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49221/oidc2222--- PASS: TestPins_ReservedForMatchingRule (0.09s)22232026/10/06 08:17:56 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232224--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.34s)22252026/10/06 08:17:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49225/oidc22262026/10/06 08:17:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49227/oidc2227--- PASS: TestScopes_Rules (0.38s)2228--- PASS: TestValidateToken_BoundSubjectMismatch (0.39s)22292026/10/06 08:17:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49229/oidc2230--- PASS: TestValidateToken_Expired (0.41s)22312026/10/06 08:17:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49231/oidc2232--- PASS: TestValidateToken_WrongAudience (0.20s)22332026/10/06 08:17:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49234/oidc2234--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.40s)22352026/10/06 08:17:56 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:49212/oidc2236--- PASS: TestValidateToken_NoMatchingProvider (0.66s)22372026/10/06 08:17:56 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:49238/oidc22382026/10/06 08:17:56 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:49233/oidc2239--- PASS: TestValidateToken_MultipleProviders (0.72s)2240PASS2241Running hook tests...2242=== RUN TestSendPathsEmpty2243=== PAUSE TestSendPathsEmpty2244=== RUN TestQueueEnqueueAndFetch2245=== PAUSE TestQueueEnqueueAndFetch2246=== RUN TestQueueDeduplication2247=== PAUSE TestQueueDeduplication2248=== RUN TestQueueRemove2249=== PAUSE TestQueueRemove2250=== RUN TestQueueFetchBatchLimit2251=== PAUSE TestQueueFetchBatchLimit2252=== RUN TestQueueRetryMovesToBack2253=== PAUSE TestQueueRetryMovesToBack2254=== RUN TestQueueFetchRemoveLifecycle2255=== PAUSE TestQueueFetchRemoveLifecycle2256=== RUN TestQueueConcurrentWriters2257=== PAUSE TestQueueConcurrentWriters2258=== RUN TestQueueRemoveLargeClosure2259=== PAUSE TestQueueRemoveLargeClosure2260=== RUN TestServerClientIntegration2261=== PAUSE TestServerClientIntegration2262=== RUN TestServerQueueError2263=== PAUSE TestServerQueueError2264=== RUN TestGetListenerSocketActivation2265 server_test.go:210: === RUN TestGetListenerSocketActivation2266 --- PASS: TestGetListenerSocketActivation (0.00s)2267 PASS2268 2269--- PASS: TestGetListenerSocketActivation (0.01s)2270=== RUN TestDrainIsolatesPoisonPath2271=== PAUSE TestDrainIsolatesPoisonPath2272=== RUN TestRunNotBlockedByPoisonHead2273=== PAUSE TestRunNotBlockedByPoisonHead2274=== RUN TestDrainGivesUpWhenServerDown2275=== PAUSE TestDrainGivesUpWhenServerDown2276=== RUN TestFailedPathPrunedByLaterClosure2277=== PAUSE TestFailedPathPrunedByLaterClosure2278=== RUN TestWorkerUploadsAndRemoves2279=== PAUSE TestWorkerUploadsAndRemoves2280=== RUN TestWorkerSkipsGCdPaths2281=== PAUSE TestWorkerSkipsGCdPaths2282=== RUN TestWorkerPrunesClosureDeps2283=== PAUSE TestWorkerPrunesClosureDeps2284=== RUN TestDrainTimeout2285=== PAUSE TestDrainTimeout2286=== CONT TestSendPathsEmpty2287--- PASS: TestSendPathsEmpty (0.00s)2288=== CONT TestDrainTimeout2289=== CONT TestServerClientIntegration2290=== CONT TestFailedPathPrunedByLaterClosure2291=== CONT TestWorkerSkipsGCdPaths2292=== CONT TestDrainGivesUpWhenServerDown2293=== CONT TestQueueRemoveLargeClosure2294=== CONT TestQueueFetchBatchLimit2295=== CONT TestQueueRemove2296=== CONT TestWorkerUploadsAndRemoves2297=== CONT TestQueueFetchRemoveLifecycle2298--- PASS: TestServerClientIntegration (0.00s)2299=== CONT TestWorkerPrunesClosureDeps23002026/10/06 08:17:56 INFO Upload queue status pending=223012026/10/06 08:17:56 INFO Uploading batch count=223022026/10/06 08:17:56 INFO Uploading batch count=223032026/10/06 08:17:56 INFO Uploading batch count=223042026/10/06 08:17:56 ERROR Upload failed error="upload failed" count=223052026/10/06 08:17:56 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-49438-1596666667/TestDrainGivesUpWhenServerDown1897148819/002/a2306--- PASS: TestQueueFetchBatchLimit (0.01s)2307=== CONT TestQueueDeduplication23082026/10/06 08:17:56 INFO Upload queue status pending=223092026/10/06 08:17:56 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-49438-1596666667/TestWorkerSkipsGCdPaths1609938234/002/nonexistent2310--- PASS: TestQueueRemove (0.01s)2311=== CONT TestQueueEnqueueAndFetch23122026/10/06 08:17:56 INFO Uploading batch count=123132026/10/06 08:17:56 ERROR Upload failed error="upload failed" count=123142026/10/06 08:17:56 INFO Upload queue status pending=223152026/10/06 08:17:56 INFO Uploading batch count=123162026/10/06 08:17:56 INFO Uploading batch count=123172026/10/06 08:17:56 INFO Uploading batch count=12318--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2319=== CONT TestDrainIsolatesPoisonPath23202026/10/06 08:17:56 INFO Uploading batch count=123212026/10/06 08:17:56 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-49438-1596666667/TestDrainGivesUpWhenServerDown1897148819/002/b23222026/10/06 08:17:57 INFO Uploading batch count=223232026/10/06 08:17:57 ERROR Upload failed error="upload failed" count=223242026/10/06 08:17:57 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-49438-1596666667/TestDrainGivesUpWhenServerDown1897148819/002/c23252026/10/06 08:17:57 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-49438-1596666667/TestDrainGivesUpWhenServerDown1897148819/002/d2326--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)2327=== CONT TestRunNotBlockedByPoisonHead2328--- PASS: TestQueueEnqueueAndFetch (0.00s)2329=== CONT TestQueueConcurrentWriters23302026/10/06 08:17:57 INFO Uploading batch count=423312026/10/06 08:17:57 ERROR Upload failed error="upload failed" count=423322026/10/06 08:17:57 INFO Uploading batch count=223332026/10/06 08:17:57 ERROR Upload failed error="upload failed" count=223342026/10/06 08:17:57 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-49438-1596666667/TestDrainGivesUpWhenServerDown1897148819/002/e23352026/10/06 08:17:57 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-49438-1596666667/TestDrainIsolatesPoisonPath196895078/002/bbb2336--- PASS: TestQueueDeduplication (0.00s)2337=== CONT TestServerQueueError23382026/10/06 08:17:57 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-49438-1596666667/TestDrainGivesUpWhenServerDown1897148819/002/f23392026/10/06 08:17:57 ERROR Failed to queue paths error="permission denied" count=12340--- PASS: TestServerQueueError (0.00s)2341=== CONT TestQueueRetryMovesToBack23422026/10/06 08:17:57 INFO Uploading batch count=123432026/10/06 08:17:57 ERROR Upload failed error="upload failed" count=123442026/10/06 08:17:57 ERROR Drain finished with paths left in queue remaining=1023452026/10/06 08:17:57 INFO Uploading batch count=123462026/10/06 08:17:57 ERROR Upload failed error="upload failed" count=123472026/10/06 08:17:57 INFO Uploading batch count=123482026/10/06 08:17:57 ERROR Upload failed error="upload failed" count=12349--- PASS: TestDrainGivesUpWhenServerDown (0.01s)23502026/10/06 08:17:57 ERROR Drain finished with paths left in queue remaining=12351--- PASS: TestDrainIsolatesPoisonPath (0.01s)23522026/10/06 08:17:57 INFO Upload queue status pending=323532026/10/06 08:17:57 INFO Uploading batch count=123542026/10/06 08:17:57 ERROR Upload failed error="upload failed" count=12355--- PASS: TestQueueRetryMovesToBack (0.01s)2356--- PASS: TestWorkerUploadsAndRemoves (0.03s)2357--- PASS: TestWorkerSkipsGCdPaths (0.03s)2358--- PASS: TestWorkerPrunesClosureDeps (0.03s)2359--- PASS: TestQueueRemoveLargeClosure (0.05s)2360--- PASS: TestQueueConcurrentWriters (0.15s)23612026/10/06 08:17:57 ERROR Upload failed error="context deadline exceeded" count=223622026/10/06 08:17:57 ERROR Drain finished with paths left in queue remaining=42363--- PASS: TestDrainTimeout (0.21s)23642026/10/06 08:17:58 INFO Uploading batch count=123652026/10/06 08:17:58 INFO Uploading batch count=123662026/10/06 08:17:58 INFO Uploading batch count=123672026/10/06 08:17:58 ERROR Upload failed error="upload failed" count=123682026/10/06 08:17:58 INFO Uploading batch count=123692026/10/06 08:17:58 ERROR Upload failed error="upload failed" count=123702026/10/06 08:17:58 INFO Uploading batch count=123712026/10/06 08:17:58 ERROR Upload failed error="upload failed" count=123722026/10/06 08:17:58 INFO Uploading batch count=123732026/10/06 08:17:58 ERROR Upload failed error="upload failed" count=123742026/10/06 08:17:58 ERROR Drain finished with paths left in queue remaining=12375--- PASS: TestRunNotBlockedByPoisonHead (1.01s)2376PASS2377Running signing tests...2378=== RUN TestExternalSigner2379=== PAUSE TestExternalSigner2380=== RUN TestExternalSignerWrongPublicKey2381=== PAUSE TestExternalSignerWrongPublicKey2382=== RUN TestExternalSignerErrors2383=== PAUSE TestExternalSignerErrors2384=== RUN TestExternalSignerRestartsAfterCrash2385=== PAUSE TestExternalSignerRestartsAfterCrash2386=== RUN TestExternalSignerProgramErrorKeepsProcess2387=== PAUSE TestExternalSignerProgramErrorKeepsProcess2388=== RUN TestExternalSignerClose2389=== PAUSE TestExternalSignerClose2390=== RUN TestExternalSignerRejectsInvalidPublicKey2391=== PAUSE TestExternalSignerRejectsInvalidPublicKey2392=== RUN TestExternalSignerCancellation2393=== PAUSE TestExternalSignerCancellation2394=== RUN TestGenerateFingerprint2395=== PAUSE TestGenerateFingerprint2396=== RUN TestParseSigningKey2397=== PAUSE TestParseSigningKey2398=== RUN TestSign2399=== PAUSE TestSign2400=== RUN TestSignBatch2401=== PAUSE TestSignBatch2402=== RUN TestNilKeyPublicKey2403=== PAUSE TestNilKeyPublicKey2404=== RUN TestSignErrors2405=== PAUSE TestSignErrors2406=== CONT TestExternalSigner2407=== CONT TestExternalSignerCancellation2408=== CONT TestSignBatch2409=== CONT TestSignErrors2410=== CONT TestParseSigningKey2411=== RUN TestParseSigningKey/valid_32-byte_key2412=== PAUSE TestParseSigningKey/valid_32-byte_key2413=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2414=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2415=== RUN TestParseSigningKey/no_colon2416=== PAUSE TestParseSigningKey/no_colon2417=== CONT TestExternalSignerProgramErrorKeepsProcess2418=== RUN TestParseSigningKey/empty_name2419=== PAUSE TestParseSigningKey/empty_name2420=== RUN TestParseSigningKey/invalid_base642421=== PAUSE TestParseSigningKey/invalid_base642422=== RUN TestParseSigningKey/wrong_length2423=== PAUSE TestParseSigningKey/wrong_length2424=== CONT TestSign2425=== CONT TestExternalSignerErrors2426=== RUN TestExternalSignerErrors/wrong_id2427=== PAUSE TestExternalSignerErrors/wrong_id2428=== RUN TestExternalSignerErrors/unrequested_key2429=== PAUSE TestExternalSignerErrors/unrequested_key2430=== RUN TestExternalSignerErrors/missing_signature_name2431=== PAUSE TestExternalSignerErrors/missing_signature_name2432=== RUN TestExternalSignerErrors/null_signatures2433=== CONT TestExternalSignerRestartsAfterCrash2434=== CONT TestExternalSignerClose2435=== PAUSE TestExternalSignerErrors/null_signatures2436=== RUN TestExternalSignerErrors/wrong_signatures_shape2437=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2438=== RUN TestExternalSignerErrors/too_few_signatures2439=== PAUSE TestExternalSignerErrors/too_few_signatures2440=== RUN TestExternalSignerErrors/wrong_signature_name2441=== PAUSE TestExternalSignerErrors/wrong_signature_name2442=== RUN TestExternalSignerErrors/wrong_signature_length2443=== PAUSE TestExternalSignerErrors/wrong_signature_length2444=== RUN TestExternalSignerErrors/exit_at_startup2445=== PAUSE TestExternalSignerErrors/exit_at_startup2446=== RUN TestExternalSignerErrors/exit_on_request2447=== PAUSE TestExternalSignerErrors/exit_on_request2448=== RUN TestExternalSignerErrors/invalid_JSON2449=== PAUSE TestExternalSignerErrors/invalid_JSON2450=== RUN TestExternalSignerErrors/null2451=== PAUSE TestExternalSignerErrors/null2452=== RUN TestExternalSignerErrors/missing_signatures2453=== PAUSE TestExternalSignerErrors/missing_signatures2454=== RUN TestExternalSignerErrors/program_error2455=== PAUSE TestExternalSignerErrors/program_error2456=== RUN TestExternalSignerErrors/wrong_shape2457=== PAUSE TestExternalSignerErrors/wrong_shape2458=== RUN TestExternalSignerErrors/invalid_signature_base642459=== PAUSE TestExternalSignerErrors/invalid_signature_base642460=== CONT TestExternalSignerRejectsInvalidPublicKey2461=== CONT TestNilKeyPublicKey2462--- PASS: TestNilKeyPublicKey (0.00s)2463=== CONT TestGenerateFingerprint2464=== RUN TestExternalSignerRejectsInvalidPublicKey/#002465=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002466=== RUN TestGenerateFingerprint/basic_with_references2467=== PAUSE TestGenerateFingerprint/basic_with_references2468=== RUN TestGenerateFingerprint/no_references2469=== PAUSE TestGenerateFingerprint/no_references2470=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2471=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2472=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2473=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2474=== RUN TestGenerateFingerprint/invalid_nar_hash_length2475=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2476=== RUN TestGenerateFingerprint/invalid_store_path_prefix2477=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2478=== RUN TestGenerateFingerprint/invalid_reference_prefix2479=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2480=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2481=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2482=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2483=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2484=== CONT TestExternalSignerWrongPublicKey2485=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2486=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2487=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2488=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2489=== RUN TestSignErrors/nil_key2490=== PAUSE TestSignErrors/nil_key2491=== RUN TestSignErrors/nil_narinfo2492=== PAUSE TestSignErrors/nil_narinfo2493=== RUN TestSignErrors/invalid_narinfo2494=== PAUSE TestSignErrors/invalid_narinfo2495=== RUN TestSignErrors/canceled2496=== CONT TestParseSigningKey/valid_32-byte_key2497=== PAUSE TestSignErrors/canceled2498=== CONT TestParseSigningKey/invalid_base642499=== CONT TestParseSigningKey/wrong_length2500=== CONT TestParseSigningKey/empty_name2501=== CONT TestParseSigningKey/no_colon2502=== CONT TestExternalSignerErrors/wrong_id2503=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2504--- PASS: TestSign (0.00s)2505=== CONT TestExternalSignerErrors/invalid_signature_base642506--- PASS: TestParseSigningKey (0.00s)2507 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2508 --- PASS: TestParseSigningKey/wrong_length (0.00s)2509 --- PASS: TestParseSigningKey/empty_name (0.00s)2510 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2511 --- PASS: TestParseSigningKey/no_colon (0.00s)2512 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2513=== CONT TestExternalSignerErrors/exit_at_startup2514--- PASS: TestSignBatch (0.00s)2515=== CONT TestExternalSignerErrors/wrong_shape2516--- PASS: TestExternalSigner (0.35s)2517=== CONT TestExternalSignerErrors/invalid_JSON2518--- PASS: TestExternalSignerRestartsAfterCrash (0.47s)2519=== CONT TestExternalSignerErrors/exit_on_request2520/nix/var/nix/builds/nix-49438-1596666667/TestExternalSignerRestartsAfterCrash3336369908/001/sign program: line 7: /nix/var/nix/builds/nix-49438-1596666667/TestExternalSignerRestartsAfterCrash3336369908/001/sign program.starts: No such file or directory2521--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.65s)2522=== CONT TestExternalSignerErrors/wrong_signatures_shape2523--- PASS: TestExternalSignerClose (0.83s)2524=== CONT TestExternalSignerErrors/wrong_signature_length2525--- PASS: TestExternalSignerWrongPublicKey (1.02s)2526=== CONT TestExternalSignerErrors/wrong_signature_name2527--- PASS: TestExternalSignerCancellation (1.22s)2528=== CONT TestExternalSignerErrors/too_few_signatures2529=== CONT TestExternalSignerErrors/program_error2530=== CONT TestExternalSignerErrors/missing_signatures2531=== CONT TestExternalSignerErrors/missing_signature_name2532=== CONT TestExternalSignerErrors/null_signatures2533=== CONT TestExternalSignerErrors/unrequested_key2534=== CONT TestExternalSignerErrors/null2535=== CONT TestGenerateFingerprint/basic_with_references2536=== CONT TestGenerateFingerprint/invalid_nar_hash_length2537=== CONT TestGenerateFingerprint/invalid_reference_prefix2538=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2539=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2540=== CONT TestGenerateFingerprint/invalid_store_path_prefix2541=== CONT TestGenerateFingerprint/no_references2542--- PASS: TestGenerateFingerprint (0.00s)2543 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2544 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2545 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2546 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2547 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2548 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2549 --- PASS: TestGenerateFingerprint/no_references (0.00s)2550=== CONT TestExternalSignerRejectsInvalidPublicKey/#002551=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2552=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2553=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2554=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2555--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2556 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2557 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2558 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2559 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2560 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2561=== CONT TestSignErrors/nil_key2562=== CONT TestSignErrors/nil_narinfo2563=== CONT TestSignErrors/canceled2564=== CONT TestSignErrors/invalid_narinfo2565--- PASS: TestSignErrors (0.00s)2566 --- PASS: TestSignErrors/nil_key (0.00s)2567 --- PASS: TestSignErrors/nil_narinfo (0.00s)2568 --- PASS: TestSignErrors/canceled (0.00s)2569 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2570--- PASS: TestExternalSignerErrors (0.00s)2571 --- PASS: TestExternalSignerErrors/wrong_id (1.38s)2572 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (1.57s)2573 --- PASS: TestExternalSignerErrors/wrong_shape (1.75s)2574 --- PASS: TestExternalSignerErrors/exit_at_startup (1.94s)2575 --- PASS: TestExternalSignerErrors/invalid_JSON (1.98s)2576 --- PASS: TestExternalSignerErrors/exit_on_request (2.04s)2577 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (2.06s)2578 --- PASS: TestExternalSignerErrors/wrong_signature_length (2.06s)2579 --- PASS: TestExternalSignerErrors/wrong_signature_name (2.06s)2580 --- PASS: TestExternalSignerErrors/too_few_signatures (2.04s)2581 --- PASS: TestExternalSignerErrors/program_error (2.07s)2582 --- PASS: TestExternalSignerErrors/missing_signatures (2.06s)2583 --- PASS: TestExternalSignerErrors/missing_signature_name (2.07s)2584 --- PASS: TestExternalSignerErrors/null_signatures (2.06s)2585 --- PASS: TestExternalSignerErrors/unrequested_key (1.87s)2586 --- PASS: TestExternalSignerErrors/null (1.86s)2587PASS2588Running OpenBao signer tests...2589=== RUN TestSign2590=== PAUSE TestSign2591=== RUN TestSignErrors2592=== PAUSE TestSignErrors2593=== RUN TestServe2594=== PAUSE TestServe2595=== RUN TestServeRejectsGarbage2596=== PAUSE TestServeRejectsGarbage2597=== CONT TestSign2598=== CONT TestServe2599=== CONT TestServeRejectsGarbage2600--- PASS: TestServeRejectsGarbage (0.00s)2601=== CONT TestSignErrors2602=== RUN TestSignErrors/http_error2603=== PAUSE TestSignErrors/http_error2604=== RUN TestSignErrors/invalid_json2605=== PAUSE TestSignErrors/invalid_json2606=== RUN TestSignErrors/no_prefix2607=== PAUSE TestSignErrors/no_prefix2608=== RUN TestSignErrors/invalid_base642609=== PAUSE TestSignErrors/invalid_base642610=== CONT TestSignErrors/http_error2611=== CONT TestSignErrors/invalid_base642612=== CONT TestSignErrors/no_prefix2613--- PASS: TestServe (0.00s)2614=== CONT TestSignErrors/invalid_json2615--- PASS: TestSign (0.00s)2616--- PASS: TestSignErrors (0.00s)2617 --- PASS: TestSignErrors/invalid_base64 (0.00s)2618 --- PASS: TestSignErrors/invalid_json (0.00s)2619 --- PASS: TestSignErrors/no_prefix (0.00s)2620 --- PASS: TestSignErrors/http_error (0.00s)2621PASS