niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #369
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestRegisterUploadedObjectReusesConnections5=== PAUSE TestRegisterUploadedObjectReusesConnections6=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica7=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica8=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun9=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun10=== RUN TestCaseHackSuffix11=== PAUSE TestCaseHackSuffix12=== RUN TestFilterOversizedClosures13=== PAUSE TestFilterOversizedClosures14=== RUN TestUploadMultipart_PartsInParallel15=== PAUSE TestUploadMultipart_PartsInParallel16=== RUN TestPartSizeForNAR17=== PAUSE TestPartSizeForNAR18=== RUN TestUploadMultipart_SupersededByPeer19=== PAUSE TestUploadMultipart_SupersededByPeer20=== RUN TestDumpPathCaseHackMatchesNix21--- PASS: TestDumpPathCaseHackMatchesNix (0.05s)22=== RUN TestDumpPathCaseHackCollision23--- PASS: TestDumpPathCaseHackCollision (0.00s)24=== RUN TestDumpPathMatchesNix25=== PAUSE TestDumpPathMatchesNix26=== RUN TestDumpPathSingleFile27=== PAUSE TestDumpPathSingleFile28=== RUN TestDumpPathWriterError29=== PAUSE TestDumpPathWriterError30=== RUN TestEncodeNixBase3231=== PAUSE TestEncodeNixBase3232=== RUN TestEncodeNixBase32WithRealHash33=== PAUSE TestEncodeNixBase32WithRealHash34=== RUN TestConvertHashToNix3235=== PAUSE TestConvertHashToNix3236=== RUN TestGetStorePathHash37=== PAUSE TestGetStorePathHash38=== RUN TestPathInfoHashCompatibility39=== PAUSE TestPathInfoHashCompatibility40=== RUN TestParsePathInfoJSON41=== PAUSE TestParsePathInfoJSON42=== RUN TestParsePathInfoJSONMultiplePaths43=== PAUSE TestParsePathInfoJSONMultiplePaths44=== RUN TestPathInfoCACompatibility45=== PAUSE TestPathInfoCACompatibility46=== RUN TestRateLimiterFeedback47=== PAUSE TestRateLimiterFeedback48=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess49=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== RUN TestResolveStorePath51=== PAUSE TestResolveStorePath52=== RUN TestDoWithRetry_BodyReplayedViaGetBody53=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody54=== RUN TestShellSplit55=== PAUSE TestShellSplit56=== RUN TestShellSplitErrors57=== PAUSE TestShellSplitErrors58=== RUN TestStreamPushReportsEveryPath59=== PAUSE TestStreamPushReportsEveryPath60=== RUN TestStreamPushBatchesUnderLoad61=== PAUSE TestStreamPushBatchesUnderLoad62=== RUN TestStreamPushIsolatesFailures63=== PAUSE TestStreamPushIsolatesFailures64=== RUN TestStreamPushGivesUpOnDeadServer65=== PAUSE TestStreamPushGivesUpOnDeadServer66=== RUN TestStreamPushRequestLine67=== PAUSE TestStreamPushRequestLine68=== RUN TestStreamPushReportsSignatures69=== PAUSE TestStreamPushReportsSignatures70=== RUN TestClientSignaturesByStorePath71=== PAUSE TestClientSignaturesByStorePath72=== RUN TestSetClientTLS73=== PAUSE TestSetClientTLS74=== RUN TestSetClientTLSDoesNotMutateDefaultTransport75=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport76=== RUN TestSetClientTLSErrors77=== PAUSE TestSetClientTLSErrors78=== RUN TestStaticToken79=== PAUSE TestStaticToken80=== RUN TestFileTokenReadsAndCaches81=== PAUSE TestFileTokenReadsAndCaches82=== RUN TestFileTokenMissing83=== PAUSE TestFileTokenMissing84=== RUN TestFileTokenEmpty85=== PAUSE TestFileTokenEmpty86=== RUN TestScriptTokenNoExpiryRerunsEveryCall87=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall88=== RUN TestScriptTokenCachesUntilRefresh89=== PAUSE TestScriptTokenCachesUntilRefresh90=== RUN TestScriptTokenEmptyToken91=== PAUSE TestScriptTokenEmptyToken92=== RUN TestScriptTokenBadJSON93=== PAUSE TestScriptTokenBadJSON94=== RUN TestScriptTokenScriptFails95=== PAUSE TestScriptTokenScriptFails96=== RUN TestScriptTokenEmptyCommand97=== PAUSE TestScriptTokenEmptyCommand98=== CONT TestDoServerRequestAttachesToken99=== CONT TestDoWithRetry_BodyReplayedViaGetBody100=== CONT TestEncodeNixBase32101=== RUN TestEncodeNixBase32/test_string_hash102=== CONT TestResolveStorePath103=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess104=== CONT TestRateLimiterFeedback105=== RUN TestRateLimiterFeedback/429_enables_limiter1062026/10/06 10:44:30 WARN Rate limiter enabled after throttle name=server-test rate=5107=== PAUSE TestRateLimiterFeedback/429_enables_limiter108=== RUN TestRateLimiterFeedback/503_enables_limiter109=== PAUSE TestRateLimiterFeedback/503_enables_limiter110=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter111=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter112=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter113=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter114=== CONT TestPathInfoCACompatibility115=== RUN TestPathInfoCACompatibility/null_ca_field116=== PAUSE TestPathInfoCACompatibility/null_ca_field117=== RUN TestPathInfoCACompatibility/old_string_format_-_text118=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text119=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive120=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive121=== RUN TestPathInfoCACompatibility/new_structured_format_-_text122=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text123=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method124=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method125=== CONT TestParsePathInfoJSONMultiplePaths126=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths127=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths128=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths129=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths130=== CONT TestConvertHashToNix32131=== RUN TestConvertHashToNix32/SRI_format_to_Nix32132=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32133=== RUN TestConvertHashToNix32/already_Nix32_format134=== PAUSE TestConvertHashToNix32/already_Nix32_format135=== CONT TestEncodeNixBase32WithRealHash136=== CONT TestParsePathInfoJSON137=== RUN TestParsePathInfoJSON/Nix_format138=== PAUSE TestParsePathInfoJSON/Nix_format139=== RUN TestConvertHashToNix32/invalid_format140=== RUN TestParsePathInfoJSON/Lix_format141=== CONT TestGetStorePathHash142=== RUN TestGetStorePathHash/valid_store_path143--- PASS: TestEncodeNixBase32WithRealHash (0.00s)144=== PAUSE TestConvertHashToNix32/invalid_format145=== CONT TestPathInfoHashCompatibility146=== CONT TestScriptTokenEmptyCommand147--- PASS: TestScriptTokenEmptyCommand (0.00s)148=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)149=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)150=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon151=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon152=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI153=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI154=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512155=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512156=== PAUSE TestEncodeNixBase32/test_string_hash157=== RUN TestEncodeNixBase32/empty_input158=== CONT TestScriptTokenScriptFails159--- PASS: TestResolveStorePath (0.00s)160=== CONT TestScriptTokenEmptyToken161=== CONT TestScriptTokenBadJSON162=== PAUSE TestParsePathInfoJSON/Lix_format163=== RUN TestParsePathInfoJSON/empty_input164=== PAUSE TestParsePathInfoJSON/empty_input165=== PAUSE TestGetStorePathHash/valid_store_path166=== PAUSE TestEncodeNixBase32/empty_input167=== RUN TestGetStorePathHash/basename_without_hyphen_should_error168=== CONT TestSetClientTLSErrors169=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error170=== RUN TestParsePathInfoJSON/whitespace_only171=== CONT TestScriptTokenCachesUntilRefresh172=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error173=== PAUSE TestParsePathInfoJSON/whitespace_only174=== RUN TestParsePathInfoJSON/invalid_JSON175=== PAUSE TestParsePathInfoJSON/invalid_JSON176=== CONT TestScriptTokenNoExpiryRerunsEveryCall177=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error1782026/10/06 10:44:30 WARN Rate limiter enabled after throttle name=server-test rate=51792026/10/06 10:44:30 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:52621180=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error181=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error182=== CONT TestFileTokenEmpty183=== RUN TestSetClientTLSErrors/missing_cert_file184=== PAUSE TestSetClientTLSErrors/missing_cert_file185=== RUN TestSetClientTLSErrors/missing_key_file186=== PAUSE TestSetClientTLSErrors/missing_key_file187=== RUN TestSetClientTLSErrors/missing_ca_file188=== PAUSE TestSetClientTLSErrors/missing_ca_file189=== RUN TestSetClientTLSErrors/invalid_ca_file190=== PAUSE TestSetClientTLSErrors/invalid_ca_file191=== CONT TestFileTokenMissing192--- PASS: TestDoServerRequestAttachesToken (0.01s)193=== CONT TestFileTokenReadsAndCaches1942026/10/06 10:44:30 WARN Rate limiter backed off name=server-test rate=51952026/10/06 10:44:30 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:52621196--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)197=== CONT TestStaticToken198--- PASS: TestStaticToken (0.00s)199=== CONT TestUploadMultipart_PartsInParallel200--- PASS: TestFileTokenMissing (0.00s)201=== CONT TestDumpPathWriterError202--- PASS: TestFileTokenEmpty (0.00s)203=== CONT TestDumpPathSingleFile204--- PASS: TestScriptTokenScriptFails (0.01s)205=== CONT TestDumpPathMatchesNix206--- PASS: TestFileTokenReadsAndCaches (0.00s)207=== CONT TestUploadMultipart_SupersededByPeer208=== RUN TestUploadMultipart_SupersededByPeer/exists209=== PAUSE TestUploadMultipart_SupersededByPeer/exists210=== RUN TestUploadMultipart_SupersededByPeer/missing211=== PAUSE TestUploadMultipart_SupersededByPeer/missing212=== CONT TestPartSizeForNAR213=== RUN TestPartSizeForNAR/zero_stays_at_minimum214=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum215=== RUN TestPartSizeForNAR/small_stays_at_minimum216=== PAUSE TestPartSizeForNAR/small_stays_at_minimum217=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum218=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum219=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts220=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts221=== RUN TestPartSizeForNAR/1_TiB222=== PAUSE TestPartSizeForNAR/1_TiB223=== RUN TestPartSizeForNAR/5_TiB_S3_max_object224=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object225=== RUN TestPartSizeForNAR/capped_at_5_GiB226=== PAUSE TestPartSizeForNAR/capped_at_5_GiB227=== CONT TestStreamPushGivesUpOnDeadServer2282026/10/06 10:44:30 ERROR Upload failed error="connection refused" count=202292026/10/06 10:44:30 ERROR Server seems unavailable, giving up on batch untried=17230--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)231=== CONT TestSetClientTLSDoesNotMutateDefaultTransport232--- PASS: TestScriptTokenBadJSON (0.01s)233=== CONT TestSetClientTLS234--- PASS: TestScriptTokenEmptyToken (0.01s)235=== CONT TestClientSignaturesByStorePath236--- PASS: TestClientSignaturesByStorePath (0.00s)237=== CONT TestStreamPushReportsSignatures2382026/10/06 10:44:30 ERROR Upload failed error=boom count=1239--- PASS: TestStreamPushReportsSignatures (0.00s)240=== CONT TestStreamPushRequestLine2412026/10/06 10:44:30 ERROR Upload failed error=boom count=1242--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)243=== CONT TestStreamPushReportsEveryPath244--- PASS: TestStreamPushReportsEveryPath (0.00s)245=== CONT TestStreamPushIsolatesFailures2462026/10/06 10:44:31 ERROR Upload failed error="bad path" count=3247--- PASS: TestStreamPushIsolatesFailures (0.00s)248=== CONT TestStreamPushBatchesUnderLoad249=== RUN TestSetClientTLS/rejects_connection_without_client_cert250=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert251=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA252=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA253=== RUN TestSetClientTLS/preserves_debug_logging_transport254=== PAUSE TestSetClientTLS/preserves_debug_logging_transport255=== CONT TestShellSplitErrors256--- PASS: TestShellSplitErrors (0.00s)257=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun2582026/10/06 10:44:31 INFO Garbage collection started259--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)260=== CONT TestFilterOversizedClosures261=== RUN TestFilterOversizedClosures/no_limit_keeps_everything262=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything263=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped264=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped265=== RUN TestFilterOversizedClosures/all_closures_skipped266=== PAUSE TestFilterOversizedClosures/all_closures_skipped267=== CONT TestCaseHackSuffix268--- PASS: TestStreamPushRequestLine (0.01s)269=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica2702026/10/06 10:44:31 INFO Garbage collection started2712026/10/06 10:44:31 INFO Garbage collection progress phase=running_on_another_replica failed_uploads_deleted=0 old_closures_deleted=0 objects_marked=0 objects_deleted=0 objects_failed=0272--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)273=== CONT TestShellSplit274--- PASS: TestShellSplit (0.00s)275=== CONT TestRegisterUploadedObjectReusesConnections2762026/10/06 10:44:31 WARN Garbage collection finished on another replica. Its statistics are not available here277--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)278=== CONT TestRateLimiterFeedback/429_enables_limiter279--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)280=== CONT TestPathInfoCACompatibility/null_ca_field281=== CONT TestRateLimiterFeedback/503_enables_limiter2822026/10/06 10:44:31 WARN Rate limiter enabled after throttle name=server-test rate=52832026/10/06 10:44:31 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:526372842026/10/06 10:44:31 WARN Rate limiter backed off name=server-test rate=5285=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths286=== CONT TestPathInfoCACompatibility/old_string_format_-_text287=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method288=== CONT TestPathInfoCACompatibility/new_structured_format_-_text289=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive290--- PASS: TestPathInfoCACompatibility (0.00s)291 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)292 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)293 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)294 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)295 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)296=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter2972026/10/06 10:44:31 WARN Rate limiter enabled after throttle name=server-test rate=52982026/10/06 10:44:31 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:526532992026/10/06 10:44:31 WARN Rate limiter backed off name=server-test rate=5300=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths301--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)302 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)303 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)304=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter305=== CONT TestConvertHashToNix32/SRI_format_to_Nix32306=== CONT TestConvertHashToNix32/invalid_format307=== CONT TestConvertHashToNix32/already_Nix32_format308--- PASS: TestConvertHashToNix32 (0.00s)309 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)310 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)311 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)312=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)313=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512314=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI315=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon316--- PASS: TestPathInfoHashCompatibility (0.00s)317 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)318 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)319 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)320 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)321=== CONT TestEncodeNixBase32/test_string_hash322=== CONT TestEncodeNixBase32/empty_input323--- PASS: TestEncodeNixBase32 (0.00s)324 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)325 --- PASS: TestEncodeNixBase32/empty_input (0.00s)326=== CONT TestParsePathInfoJSON/Nix_format327=== CONT TestParsePathInfoJSON/whitespace_only328=== CONT TestParsePathInfoJSON/empty_input329=== CONT TestParsePathInfoJSON/Lix_format330=== CONT TestParsePathInfoJSON/invalid_JSON331--- PASS: TestParsePathInfoJSON (0.00s)332 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)333 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)334 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)335 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)336 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)337=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error338=== CONT TestGetStorePathHash/valid_store_path339=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error340=== CONT TestGetStorePathHash/basename_without_hyphen_should_error341--- PASS: TestGetStorePathHash (0.00s)342 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)343 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)344 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)345 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)346=== CONT TestSetClientTLSErrors/missing_cert_file347=== CONT TestSetClientTLSErrors/missing_ca_file348=== CONT TestSetClientTLSErrors/invalid_ca_file349=== CONT TestSetClientTLSErrors/missing_key_file350--- PASS: TestRateLimiterFeedback (0.00s)351 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)352 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)353 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)354 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)355=== CONT TestUploadMultipart_SupersededByPeer/missing356=== CONT TestUploadMultipart_SupersededByPeer/exists357--- PASS: TestSetClientTLSErrors (0.01s)358 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)359 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)360 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)361 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)362=== CONT TestPartSizeForNAR/zero_stays_at_minimum363=== CONT TestPartSizeForNAR/capped_at_5_GiB364=== CONT TestPartSizeForNAR/5_TiB_S3_max_object365=== CONT TestPartSizeForNAR/1_TiB366=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts367=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum368=== CONT TestPartSizeForNAR/small_stays_at_minimum369--- PASS: TestPartSizeForNAR (0.00s)370 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)371 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)372 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)373 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)374 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)375 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)376 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)377=== CONT TestSetClientTLS/rejects_connection_without_client_cert378--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)379 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)380 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)381=== CONT TestSetClientTLS/preserves_debug_logging_transport382--- PASS: TestDumpPathWriterError (0.03s)383=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA384=== CONT TestFilterOversizedClosures/no_limit_keeps_everything385=== CONT TestFilterOversizedClosures/all_closures_skipped3862026/10/06 10:44:31 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=50387=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3882026/10/06 10:44:31 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=2000389--- PASS: TestFilterOversizedClosures (0.00s)390 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)391 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)392 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)3932026/10/06 10:44:31 http: TLS handshake error from 127.0.0.1:52713: remote error: tls: bad certificate394--- PASS: TestSetClientTLS (0.00s)395 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)396 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)397 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)398--- PASS: TestRegisterUploadedObjectReusesConnections (0.02s)399--- PASS: TestDumpPathSingleFile (0.05s)400--- PASS: TestCaseHackSuffix (0.04s)401--- PASS: TestDumpPathMatchesNix (0.07s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestUploadMultipart_PartsInParallel (0.61s)404--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)405PASS406Running server tests...407The files belonging to this database system will be owned by user "_nixbld1".408This user must also own the server process.409410The database cluster will be initialized with locale "C".411The default database encoding has accordingly been set to "SQL_ASCII".412The default text search configuration will be set to "english".413414Data page checksums are enabled.415416creating directory /nix/var/nix/builds/nix-21795-464819160/postgres351128969/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-21795-464819160/postgres351128969/data -l logfile start433434/nix/var/nix/builds/nix-21795-464819160/postgres351128969:5432 - no response4352026-10-06 10:44:32.625 UTC [21832] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4362026-10-06 10:44:32.626 UTC [21832] LOG: listening on Unix socket "/nix/var/nix/builds/nix-21795-464819160/postgres351128969/.s.PGSQL.5432"4372026-10-06 10:44:32.628 UTC [21839] LOG: database system was shut down at 2026-10-06 10:44:32 UTC4382026-10-06 10:44:32.628 UTC [21832] LOG: database system is ready to accept connections439/nix/var/nix/builds/nix-21795-464819160/postgres351128969:5432 - accepting connections440{"timestamp":"2026-10-06T10:44:32.842785Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"5d1785f2-bc37-4d06-8a39-fa6dbed335a2","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(5)"}441{"timestamp":"2026-10-06T10:44:32.946851Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"289faf18-6e41-49f7-ac72-ddf1cafe9e43","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(11)"}442=== RUN TestService_AuthMiddleware443=== PAUSE TestService_AuthMiddleware444=== RUN TestService_AuthMiddleware_MTLSProxyHeader445=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader446=== RUN TestService_AuthMiddleware_MTLSBoundSubjects447=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects448=== RUN TestService_ReadAuthMiddleware449=== PAUSE TestService_ReadAuthMiddleware450=== RUN TestService_AuthMiddleware_OIDC451=== PAUSE TestService_AuthMiddleware_OIDC452=== RUN TestService_RequireScope_OIDC453=== PAUSE TestService_RequireScope_OIDC454=== RUN TestService_ReadScope_PublicByDefault455=== PAUSE TestService_ReadScope_PublicByDefault456=== RUN TestCacheConfigHandler457=== PAUSE TestCacheConfigHandler458=== RUN TestCacheStatsHandler459=== PAUSE TestCacheStatsHandler460=== RUN TestClientCADerivations461=== PAUSE TestClientCADerivations462=== RUN TestClientErrorHandling463=== PAUSE TestClientErrorHandling464=== RUN TestClientIntegration465=== PAUSE TestClientIntegration466=== RUN TestClientMultipleUploads467=== PAUSE TestClientMultipleUploads468=== RUN TestClientWithDependencies469=== PAUSE TestClientWithDependencies470=== RUN TestClientSharedPathCommittedMidPush471=== PAUSE TestClientSharedPathCommittedMidPush472=== RUN TestPinProtectsFromGC473=== PAUSE TestPinProtectsFromGC474=== RUN TestClientPushesUseOnePush475=== PAUSE TestClientPushesUseOnePush476=== RUN TestClientFallsBackToClosures477=== PAUSE TestClientFallsBackToClosures478=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock479=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock480=== RUN TestResolveDBConnectionString481=== PAUSE TestResolveDBConnectionString482=== RUN TestConnectWaitsForAPeerMigration483=== PAUSE TestConnectWaitsForAPeerMigration484=== RUN TestLeadElectsOneAndHandsOver485=== PAUSE TestLeadElectsOneAndHandsOver486=== RUN TestLeadIncumbentWinsAfterRestart4872026/10/06 10:44:33 INFO lead: acquired remote=192.0.2.1:12344882026/10/06 10:44:33 INFO lead: released remote=192.0.2.1:12344892026/10/06 10:44:33 INFO lead: acquired remote=192.0.2.1:12344902026/10/06 10:44:34 INFO lead: released remote=192.0.2.1:1234491--- PASS: TestLeadIncumbentWinsAfterRestart (1.90s)492=== RUN TestLeadIncumbentAnnouncesAtOnce493=== PAUSE TestLeadIncumbentAnnouncesAtOnce494=== RUN TestLeadEndsOnShutdown495=== PAUSE TestLeadEndsOnShutdown496=== RUN TestLeadEndsWhenItsConnectionHangs4972026/10/06 10:44:35 INFO lead: acquired remote=192.0.2.1:12344982026-10-06 10:44:36.312 UTC [21875] FATAL: terminating connection due to administrator command4992026/10/06 10:44:36 INFO lead: acquired remote=192.0.2.1:12345002026/10/06 10:44:37 WARN lead: lock connection lost error="timeout: context deadline exceeded"5012026/10/06 10:44:37 INFO lead: released remote=192.0.2.1:12345022026/10/06 10:44:37 INFO lead: released remote=192.0.2.1:1234503--- PASS: TestLeadEndsWhenItsConnectionHangs (2.76s)504=== RUN TestGCAdvisoryLockBlocksConcurrentRun505=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun506=== RUN TestGCBugBareHashReferences507=== PAUSE TestGCBugBareHashReferences508=== RUN TestGCMetrics509=== PAUSE TestGCMetrics510=== RUN TestPushDedupSurvivesConcurrentGC511=== PAUSE TestPushDedupSurvivesConcurrentGC512=== RUN TestDeduplicatedObjectsRecordedAsPending513=== PAUSE TestDeduplicatedObjectsRecordedAsPending514=== RUN TestGCSweepSkipsPendingObjects515=== PAUSE TestGCSweepSkipsPendingObjects516=== RUN TestTombstonedObjectOfferedWithoutWaiting517=== PAUSE TestTombstonedObjectOfferedWithoutWaiting518=== RUN TestGCSweepDeliversEachKeyOnce519=== PAUSE TestGCSweepDeliversEachKeyOnce520=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection521=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection522=== RUN TestForceGCDuringPushOffersSweptObject523=== PAUSE TestForceGCDuringPushOffersSweptObject524=== RUN TestFailedS3DeleteKeepsTombstone525=== PAUSE TestFailedS3DeleteKeepsTombstone526=== RUN TestSweepSkipsRowsLockedByPush527=== PAUSE TestSweepSkipsRowsLockedByPush528=== RUN TestRegisterCompletedObjectNeedsPendingRow529=== PAUSE TestRegisterCompletedObjectNeedsPendingRow530=== RUN TestGetExistingObjectsLocksRows531=== PAUSE TestGetExistingObjectsLocksRows532=== RUN TestSweepRechecksPendingAfterLocking533=== PAUSE TestSweepRechecksPendingAfterLocking534=== RUN TestPushWaitsForSweepHoldingRow535=== PAUSE TestPushWaitsForSweepHoldingRow536=== RUN TestCommitRacingPendingCleanupKeepsObjects537=== PAUSE TestCommitRacingPendingCleanupKeepsObjects538=== RUN TestGCEndsOnShutdown539=== PAUSE TestGCEndsOnShutdown540=== RUN TestGCTaskStore_StartNew541=== PAUSE TestGCTaskStore_StartNew542=== RUN TestGCTaskStore_DeduplicateSameParams543=== PAUSE TestGCTaskStore_DeduplicateSameParams544=== RUN TestGCTaskStore_ConflictDifferentParams545=== PAUSE TestGCTaskStore_ConflictDifferentParams546=== RUN TestGCTaskStore_GetEmpty547=== PAUSE TestGCTaskStore_GetEmpty548=== RUN TestGCTaskStore_GetReturnsLatest549=== PAUSE TestGCTaskStore_GetReturnsLatest550=== RUN TestGCTaskStore_CompletedAllowsNewTask551=== PAUSE TestGCTaskStore_CompletedAllowsNewTask552=== RUN TestGCTaskStore_PhaseUpdates553=== PAUSE TestGCTaskStore_PhaseUpdates554=== RUN TestGCTaskStore_Fail555=== PAUSE TestGCTaskStore_Fail556=== RUN TestGracefulShutdownDrainsInflight557=== PAUSE TestGracefulShutdownDrainsInflight558=== RUN TestService_healthCheckHandler559=== PAUSE TestService_healthCheckHandler560=== RUN TestService_readinessHandler561=== PAUSE TestService_readinessHandler562=== RUN TestGenerateLandingPage563=== PAUSE TestGenerateLandingPage564=== RUN TestCacheConfigHandlerMaxNarSize565=== PAUSE TestCacheConfigHandlerMaxNarSize566=== RUN TestCreatePendingClosureRejectsOversizedNAR567=== PAUSE TestCreatePendingClosureRejectsOversizedNAR568=== RUN TestNARDeduplicationMetadataUploadBug569=== PAUSE TestNARDeduplicationMetadataUploadBug570=== RUN TestMetricsInventory571=== PAUSE TestMetricsInventory572=== RUN TestService_NativeMTLS573=== PAUSE TestService_NativeMTLS574=== RUN TestServerTLSConfig575=== PAUSE TestServerTLSConfig576=== RUN TestMultipartCleanup577=== PAUSE TestMultipartCleanup578=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded579=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded580=== RUN TestPendingCleanupUsesOneCutoff581=== PAUSE TestPendingCleanupUsesOneCutoff582=== RUN TestObjectStatsTrigger583=== PAUSE TestObjectStatsTrigger584=== RUN TestOrphanedObjectsGC585=== PAUSE TestOrphanedObjectsGC586=== RUN TestOrphanedObjectsGCStressTest587=== PAUSE TestOrphanedObjectsGCStressTest588=== RUN TestCreatePin_ReservedPins589=== PAUSE TestCreatePin_ReservedPins590=== RUN TestPresentReportsOnlyClosureRoots591=== PAUSE TestPresentReportsOnlyClosureRoots592=== RUN TestPresentNotReportedWhileGCDeletesClosure593=== PAUSE TestPresentNotReportedWhileGCDeletesClosure594=== RUN TestParseSingleRange595=== PAUSE TestParseSingleRange596=== RUN TestProxyHeadersOnlyTrustedOnSocket597=== PAUSE TestProxyHeadersOnlyTrustedOnSocket598=== RUN TestIsValidCachePath599=== PAUSE TestIsValidCachePath600=== RUN TestReadProxyNarinfo601=== PAUSE TestReadProxyNarinfo602=== RUN TestReadProxyNarinfoAlreadyDecompressed603=== PAUSE TestReadProxyNarinfoAlreadyDecompressed604=== RUN TestReadProxyContentNegotiation605=== PAUSE TestReadProxyContentNegotiation606=== RUN TestReadProxyNarStreaming607=== PAUSE TestReadProxyNarStreaming608=== RUN TestReadProxy404609=== PAUSE TestReadProxy404610=== RUN TestReadProxyInvalidPath611=== PAUSE TestReadProxyInvalidPath612=== RUN TestReadProxyHead613=== PAUSE TestReadProxyHead614=== RUN TestReadProxyOutlastsServerWriteTimeout615=== PAUSE TestReadProxyOutlastsServerWriteTimeout616=== RUN TestReadProxyConditionalGet617=== PAUSE TestReadProxyConditionalGet618=== RUN TestReadProxyRootRedirectsToIndexHTML619=== PAUSE TestReadProxyRootRedirectsToIndexHTML620=== RUN TestReadProxyDisabled621=== PAUSE TestReadProxyDisabled622=== RUN TestReadRedirectNar623=== PAUSE TestReadRedirectNar624=== RUN TestReadRedirectKeepsNarinfoProxied625=== PAUSE TestReadRedirectKeepsNarinfoProxied626=== RUN TestReadProxyRangeRequest627=== PAUSE TestReadProxyRangeRequest628=== RUN TestReadRedirectUsesPublicS3URL629=== PAUSE TestReadRedirectUsesPublicS3URL630=== RUN TestPush_OverlappingRootsStoreOneRowPerKey631=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey632=== RUN TestPush_CompleteCommitsEveryRoot633=== PAUSE TestPush_CompleteCommitsEveryRoot634=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit635=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit636=== RUN TestPush_RejectsBadRequests637=== PAUSE TestPush_RejectsBadRequests638=== RUN TestPush_SignsNarinfosOfItsPendingObjects639=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects640=== RUN TestRedundantMultipartUpload641=== PAUSE TestRedundantMultipartUpload642=== RUN TestCompleteMultipartUpload_ErrorButObjectExists643=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists644=== RUN TestCompletedNarNotReofferedAcrossClosures645=== PAUSE TestCompletedNarNotReofferedAcrossClosures646=== RUN TestPresignedUploadRegisteredBeforeCommit647=== PAUSE TestPresignedUploadRegisteredBeforeCommit648=== RUN TestService_Rustfstest649=== PAUSE TestService_Rustfstest650=== RUN TestParseSize651=== PAUSE TestParseSize652=== RUN TestSkippedUploadsHandler653=== PAUSE TestSkippedUploadsHandler654=== RUN TestSystemdListenerNotActivated655--- PASS: TestSystemdListenerNotActivated (0.00s)656=== RUN TestWatchdogBeatsWhenHealthy657--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)658=== RUN TestWatchdogSkipsWhenUnhealthy6592026/10/06 10:44:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/06 10:44:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/06 10:44:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/06 10:44:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/06 10:44:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/06 10:44:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/06 10:44:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/06 10:44:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/06 10:44:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6682026/10/06 10:44:37 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 TestService_AuthMiddleware693=== CONT TestService_verifyS3Integrity694=== CONT TestForceGCDuringPushOffersSweptObject695=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows696=== CONT TestPush_OverlappingRootsStoreOneRowPerKey697=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows698=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check699=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check700=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows701=== CONT TestGCTaskStore_Fail702--- PASS: TestGCTaskStore_Fail (0.00s)703=== CONT TestOrphanedObjectsGCStressTest704=== CONT TestReadRedirectUsesPublicS3URL705=== CONT TestParseSize706=== CONT TestCreatePin_ReservedPins707=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT708=== CONT TestCompleteMultipartUnregistered709--- PASS: TestParseSize (0.00s)710=== CONT TestService_Rustfstest7112026/10/06 10:44:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52738/oidc712--- PASS: TestReadRedirectUsesPublicS3URL (0.43s)713=== CONT TestPresignedUploadRegisteredBeforeCommit7142026/10/06 10:44:38 INFO Received uploads request method=POST path=/api/pending_closures7152026/10/06 10:44:38 INFO Aborted multipart uploads count=0 kept=07162026/10/06 10:44:38 WARN Force mode enabled - objects will be deleted immediately without grace period7172026/10/06 10:44: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=07182026/10/06 10:44:38 INFO Vacuumed table table=pending_closures7192026/10/06 10:44:38 INFO Vacuumed table table=pending_objects7202026/10/06 10:44:38 INFO Vacuumed table table=multipart_uploads7212026/10/06 10:44:38 INFO Vacuumed table table=closures7222026/10/06 10:44:38 INFO Vacuumed table table=objects723=== CONT TestCompletedNarNotReofferedAcrossClosures7242026/10/06 10:44:38 INFO Received push request method=POST path=/api/pushes725--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.80s)726=== CONT TestCompleteMultipartUpload_ErrorButObjectExists7272026/10/06 10:44:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7282026/10/06 10:44:39 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst729--- PASS: TestCompleteMultipartUnregistered (1.13s)730=== CONT TestRedundantMultipartUpload7312026/10/06 10:44:39 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"732--- PASS: TestService_AuthMiddleware (1.31s)733=== CONT TestPush_SignsNarinfosOfItsPendingObjects7342026/10/06 10:44:39 INFO Received uploads request method=POST path=/api/pending_closures7352026/10/06 10:44:39 INFO Received uploads request method=POST path=/api/pending_closures736--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.90s)737=== CONT TestPush_RejectsBadRequests738--- PASS: TestService_Rustfstest (2.09s)739=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit7402026/10/06 10:44:40 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux7412026/10/06 10:44:40 WARN Refused reserved pin name=worker-x86_64-linux7422026/10/06 10:44:40 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux7432026/10/06 10:44:40 INFO Received create pin request method=POST path=/api/pins/my-app7442026/10/06 10:44:40 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux745--- PASS: TestCreatePin_ReservedPins (2.40s)746=== CONT TestPush_CompleteCommitsEveryRoot7472026/10/06 10:44:40 INFO Received uploads request method=POST path=/api/pending_closures7482026/10/06 10:44:40 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst7492026/10/06 10:44:40 INFO Received uploads request method=POST path=/api/pending_closures750--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.29s)751=== CONT TestIsValidUploadKey752=== RUN TestIsValidUploadKey/narinfo753=== PAUSE TestIsValidUploadKey/narinfo754=== RUN TestIsValidUploadKey/nar_zst755=== PAUSE TestIsValidUploadKey/nar_zst756=== RUN TestIsValidUploadKey/nar_xz757=== PAUSE TestIsValidUploadKey/nar_xz758=== RUN TestIsValidUploadKey/nar_plain759=== PAUSE TestIsValidUploadKey/nar_plain760=== RUN TestIsValidUploadKey/listing761=== PAUSE TestIsValidUploadKey/listing762=== RUN TestIsValidUploadKey/build_log763=== PAUSE TestIsValidUploadKey/build_log764=== RUN TestIsValidUploadKey/build_log_home-manager_file765=== PAUSE TestIsValidUploadKey/build_log_home-manager_file766=== RUN TestIsValidUploadKey/build_log_plus_in_name767=== PAUSE TestIsValidUploadKey/build_log_plus_in_name768=== RUN TestIsValidUploadKey/build_log_question_mark769=== PAUSE TestIsValidUploadKey/build_log_question_mark770=== RUN TestIsValidUploadKey/build_log_equals771=== PAUSE TestIsValidUploadKey/build_log_equals772=== RUN TestIsValidUploadKey/realisation773=== PAUSE TestIsValidUploadKey/realisation774=== RUN TestIsValidUploadKey/realisation_plus_in_output775=== PAUSE TestIsValidUploadKey/realisation_plus_in_output776=== RUN TestIsValidUploadKey/nix-cache-info777=== PAUSE TestIsValidUploadKey/nix-cache-info778=== RUN TestIsValidUploadKey/index.html779=== PAUSE TestIsValidUploadKey/index.html780=== RUN TestIsValidUploadKey/narinfo_key,_nar_type781=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type782=== RUN TestIsValidUploadKey/nar_key,_narinfo_type783=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type784=== RUN TestIsValidUploadKey/listing_key,_narinfo_type785=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type786=== RUN TestIsValidUploadKey/traversal787=== PAUSE TestIsValidUploadKey/traversal788=== RUN TestIsValidUploadKey/traversal_nar789=== PAUSE TestIsValidUploadKey/traversal_nar790=== RUN TestIsValidUploadKey/absolute791=== PAUSE TestIsValidUploadKey/absolute792=== RUN TestIsValidUploadKey/empty_key793=== PAUSE TestIsValidUploadKey/empty_key794=== RUN TestIsValidUploadKey/unknown_type795=== PAUSE TestIsValidUploadKey/unknown_type796=== CONT TestService_createPendingClosureHandler7972026/10/06 10:44:40 INFO Received uploads request method=POST path=/api/pending_closures7982026/10/06 10:44:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7992026/10/06 10:44:40 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YzJlMjUwOTEtNDQ2Yy00MmI5LThhZGItOTE2OGQ2YTU0MGNiLmFmYjU1YzQwLTI3ZDctNDRhMy05YmIyLTJmNGJlZTJmZDhkZXgxNzkxMjgzNDc5NTEyNjYyMDAw parts=108002026/10/06 10:44:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8012026/10/06 10:44:40 INFO Completed upload id=18022026/10/06 10:44:40 INFO Received uploads request method=POST path=/api/pending_closures8032026/10/06 10:44:40 INFO Received uploads request method=POST path=/api/pending_closures8042026/10/06 10:44:41 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo8052026/10/06 10:44:41 WARN Found objects in DB but missing from S3, will re-upload count=1806--- PASS: TestService_verifyS3Integrity (3.06s)807=== CONT TestService_cleanupPendingClosuresHandler8082026/10/06 10:44:41 INFO Received uploads request method=POST path=/api/pending_closures8092026/10/06 10:44:41 INFO Received uploads request method=POST path=/api/pending_closures8102026/10/06 10:44:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8112026/10/06 10:44:41 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YzJlMjUwOTEtNDQ2Yy00MmI5LThhZGItOTE2OGQ2YTU0MGNiLjk4NzE2MDFlLTA1Y2QtNDNjYS1hZmEyLWFjYmFiMGU4NmE3ZHgxNzkxMjgzNDgxMjg3MTk0MDAw8122026/10/06 10:44:41 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YzJlMjUwOTEtNDQ2Yy00MmI5LThhZGItOTE2OGQ2YTU0MGNiLjk4NzE2MDFlLTA1Y2QtNDNjYS1hZmEyLWFjYmFiMGU4NmE3ZHgxNzkxMjgzNDgxMjg3MTk0MDAw parts=1813--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.90s)814=== CONT TestUploadHandlersRejectOversizedBody8152026/10/06 10:44:41 INFO Received uploads request method=POST path=/api/pending_closures816=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure817=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure818=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart819=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart820=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts821=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts822=== CONT TestUploadHandlersRejectInvalidKeys823=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info824=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info825=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal826=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal827=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key828=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key829=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key830=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key831=== CONT TestMetricsInventory8322026/10/06 10:44:41 INFO Received push request method=POST path=/api/pushes8332026/10/06 10:44:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8342026/10/06 10:44:42 INFO Signed narinfos id=1 count=18352026/10/06 10:44:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8362026/10/06 10:44:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8372026/10/06 10:44:42 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"8382026/10/06 10:44:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8392026/10/06 10:44:42 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"8402026/10/06 10:44:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8412026/10/06 10:44:42 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=18422026/10/06 10:44:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8432026/10/06 10:44:42 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo844--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (2.79s)845=== CONT TestOrphanedObjectsGC8462026/10/06 10:44:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8472026/10/06 10:44:42 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YzJlMjUwOTEtNDQ2Yy00MmI5LThhZGItOTE2OGQ2YTU0MGNiLmJlYTE3NDY2LTM5NjgtNDc2ZS05Y2Q4LTcwZDRjY2I2MDg5YngxNzkxMjgzNDgwOTI0MDk5MDAw parts=128482026/10/06 10:44:42 INFO Received uploads request method=POST path=/api/pending_closures849--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.29s)850=== CONT TestObjectStatsTrigger851=== RUN TestPush_RejectsBadRequests/no_roots852=== PAUSE TestPush_RejectsBadRequests/no_roots853=== RUN TestPush_RejectsBadRequests/no_objects854=== PAUSE TestPush_RejectsBadRequests/no_objects855=== RUN TestPush_RejectsBadRequests/bad_root856=== PAUSE TestPush_RejectsBadRequests/bad_root857=== RUN TestPush_RejectsBadRequests/root_not_in_objects858=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects859=== CONT TestPendingCleanupUsesOneCutoff8602026/10/06 10:44:43 INFO Received push request method=POST path=/api/pushes8612026/10/06 10:44:43 INFO Received complete push request method=POST path=/api/pushes/1/complete8622026/10/06 10:44:43 INFO Received push request method=POST path=/api/pushes8632026/10/06 10:44:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8642026/10/06 10:44:43 INFO Aborted multipart uploads count=0 kept=08652026/10/06 10:44:43 WARN Force mode enabled - objects will be deleted immediately without grace period8662026/10/06 10:44:43 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=08672026/10/06 10:44:43 INFO Vacuumed table table=pending_closures8682026/10/06 10:44:43 INFO Vacuumed table table=pending_objects8692026/10/06 10:44:43 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YzJlMjUwOTEtNDQ2Yy00MmI5LThhZGItOTE2OGQ2YTU0MGNiLjA5NTA0YzQwLWM2YmEtNDE4Ni1hMTc4LWMwNTc5NzJmMTU3OXgxNzkxMjgzNDgxNjE1NTc4MDAw parts=128702026/10/06 10:44:43 INFO Received uploads request method=POST path=/api/pending_closures8712026/10/06 10:44:43 INFO Vacuumed table table=multipart_uploads8722026/10/06 10:44:43 INFO Received push request method=POST path=/api/pushes8732026/10/06 10:44:43 INFO Vacuumed table table=closures8742026/10/06 10:44:43 INFO Received uploads request method=POST path=/api/pending_closures8752026/10/06 10:44:43 INFO Vacuumed table table=objects8762026/10/06 10:44:43 INFO Received complete push request method=POST path=/api/pushes/2/complete877--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (3.81s)878=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded8792026/10/06 10:44:43 INFO Received complete push request method=POST path=/api/pushes/1/complete880--- PASS: TestPush_CompleteCommitsEveryRoot (3.64s)881=== CONT TestMultipartCleanup8822026/10/06 10:44:44 INFO Received uploads request method=POST path=/api/pending_closures8832026/10/06 10:44:44 INFO Received uploads request method=POST path=/api/pending_closures8842026/10/06 10:44:44 INFO Received uploads request method=POST path=/api/pending_closures8852026/10/06 10:44:44 INFO Received cleanup request method=DELETE path=/api/pending_closures8862026/10/06 10:44:44 INFO Aborted multipart uploads count=0 kept=08872026/10/06 10:44:44 INFO Received uploads request method=POST path=/api/pending_closures8882026/10/06 10:44:44 INFO Received cleanup request method=DELETE path=/api/pending_closures8892026/10/06 10:44:44 INFO Aborted multipart uploads count=1 kept=08902026/10/06 10:44:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8912026-10-06 10:44:44.863 UTC [21950] ERROR: Closure does not exist: id=18922026-10-06 10:44:44.863 UTC [21950] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE8932026-10-06 10:44:44.863 UTC [21950] STATEMENT: -- name: CommitPendingClosure :exec894 SELECT commit_pending_closure($1::bigint)895 896--- PASS: TestService_cleanupPendingClosuresHandler (3.86s)897=== CONT TestNARDeduplicationMetadataUploadBug898--- PASS: TestMetricsInventory (3.64s)899=== CONT TestServerTLSConfig900=== RUN TestServerTLSConfig/no_client_CA901=== PAUSE TestServerTLSConfig/no_client_CA902=== RUN TestServerTLSConfig/missing_CA_file903=== PAUSE TestServerTLSConfig/missing_CA_file904=== RUN TestServerTLSConfig/not_a_PEM_file905=== PAUSE TestServerTLSConfig/not_a_PEM_file906=== CONT TestCreatePendingClosureRejectsOversizedNAR9072026/10/06 10:44:45 INFO Received uploads request method=POST path=/api/pending_closures908--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)909=== CONT TestService_NativeMTLS910=== NAME TestOrphanedObjectsGCStressTest911 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains912 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion9132026/10/06 10:44:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9142026/10/06 10:44:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9152026/10/06 10:44:45 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YzJlMjUwOTEtNDQ2Yy00MmI5LThhZGItOTE2OGQ2YTU0MGNiLjAwYzNiNDA3LWQyNGEtNDAxYS1iNjFlLTZmYzlhZDU2ZmVlYngxNzkxMjgzNDgzODIyNzQwMDAw error="Get \"http://127.0.0.1:1/bucket16/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"9162026/10/06 10:44:45 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YzJlMjUwOTEtNDQ2Yy00MmI5LThhZGItOTE2OGQ2YTU0MGNiLmE2MWVmYzcyLWEzOTEtNGYzYS04Nzc5LTlkYWEwNDY1MWIzNngxNzkxMjgzNDgzNzc3MjI5MDAw parts=129172026/10/06 10:44:45 INFO Received cleanup request method=DELETE path=/api/pending_closures9182026/10/06 10:44:45 INFO Aborted multipart uploads count=1 kept=0919--- PASS: TestRedundantMultipartUpload (6.82s)920=== CONT TestCacheConfigHandlerMaxNarSize921--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)922=== CONT TestCommitRacingPendingCleanupKeepsObjects9232026/10/06 10:44:45 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YzJlMjUwOTEtNDQ2Yy00MmI5LThhZGItOTE2OGQ2YTU0MGNiLjI3ZWM5NGY3LWY4ZmYtNDk0My04YzlmLWY1M2ViMGNiOWQ2NngxNzkxMjgzNDg0MjU5OTA0MDAw parts=109242026/10/06 10:44:45 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9252026/10/06 10:44:45 INFO Completed upload id=19262026/10/06 10:44:45 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009272026/10/06 10:44:45 INFO Received uploads request method=POST path=/api/pending_closures9282026/10/06 10:44:45 INFO Starting cleanup of old closures method=DELETE path=/api/closures9292026/10/06 10:44:45 INFO Aborted multipart uploads count=0 kept=09302026/10/06 10:44:45 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=09312026/10/06 10:44:45 INFO Vacuumed table table=pending_closures9322026/10/06 10:44:45 INFO Vacuumed table table=pending_objects9332026/10/06 10:44:46 INFO Vacuumed table table=multipart_uploads9342026/10/06 10:44:46 INFO Vacuumed table table=closures9352026/10/06 10:44:46 INFO Vacuumed table table=objects9362026/10/06 10:44:46 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000937--- PASS: TestService_createPendingClosureHandler (5.43s)938=== CONT TestGenerateLandingPage939--- PASS: TestGenerateLandingPage (0.00s)940=== CONT TestGCTaskStore_PhaseUpdates941--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)942=== CONT TestService_readinessHandler943--- PASS: TestObjectStatsTrigger (3.29s)944=== CONT TestGCTaskStore_CompletedAllowsNewTask945--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)946=== CONT TestService_healthCheckHandler947=== NAME TestOrphanedObjectsGC948 orphaned_objects_gc_test.go:290: GC Test Summary:949 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A950 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B951 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)952 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)953 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects954--- PASS: TestOrphanedObjectsGC (4.22s)955=== CONT TestGCTaskStore_GetReturnsLatest956--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)957=== CONT TestGracefulShutdownDrainsInflight9582026/10/06 10:44:46 INFO Starting HTTP server address=127.0.0.1:528089592026/10/06 10:44:46 INFO Shutdown signal received, draining in-flight requests timeout=10s960--- PASS: TestGracefulShutdownDrainsInflight (0.07s)961=== CONT TestGCTaskStore_GetEmpty962--- PASS: TestGCTaskStore_GetEmpty (0.00s)963=== CONT TestGCTaskStore_ConflictDifferentParams964--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)965=== CONT TestRegisterCompletedObjectNeedsPendingRow9662026/10/06 10:44:46 INFO Received uploads request method=POST path=/api/pending_closures9672026/10/06 10:44:46 INFO Received uploads request method=POST path=/api/pending_closures9682026/10/06 10:44:46 INFO Received cleanup request method=DELETE path=/api/pending_closures9692026/10/06 10:44:46 INFO Received uploads request method=POST path=/api/pending_closures9702026/10/06 10:44:46 INFO Received cleanup request method=DELETE path=/api/pending_closures9712026/10/06 10:44:46 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket27/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""9722026/10/06 10:44:46 INFO Aborted multipart uploads count=0 kept=19732026/10/06 10:44:46 INFO Received cleanup request method=DELETE path=/api/pending_closures9742026/10/06 10:44:46 INFO Aborted multipart uploads count=1 kept=0975--- PASS: TestMultipartCleanup (2.91s)976=== CONT TestGCTaskStore_DeduplicateSameParams977--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)978=== CONT TestPushWaitsForSweepHoldingRow9792026/10/06 10:44:46 INFO Received uploads request method=POST path=/api/pending_closures980--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (3.17s)981=== CONT TestGCTaskStore_StartNew982--- PASS: TestGCTaskStore_StartNew (0.00s)983=== CONT TestSweepRechecksPendingAfterLocking984=== NAME TestNARDeduplicationMetadataUploadBug985 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-21795-464819160/TestNARDeduplicationMetadataUploadBug808454317/001/store/h04w6yc4rp0bb8s5kyf843m3sgdn31bq-file1.txt9862026/10/06 10:44:47 INFO Received push request method=POST path=/api/pushes9872026/10/06 10:44:47 WARN mTLS auth: subject not in bound subjects subject="CN=reader"9882026/10/06 10:44:47 WARN mTLS auth: subject not in bound subjects subject="CN=reader"989--- PASS: TestService_NativeMTLS (2.37s)990=== CONT TestGCEndsOnShutdown991=== RUN TestGCEndsOnShutdown/before_the_run992=== PAUSE TestGCEndsOnShutdown/before_the_run993=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete994=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete995=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark996=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark997=== CONT TestGetExistingObjectsLocksRows9982026/10/06 10:44:47 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9992026/10/06 10:44:47 INFO Uploading h04w6yc4rp0bb8s5kyf843m3sgdn31bq-file1.txt (160B)10002026/10/06 10:44:47 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"10012026/10/06 10:44:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10022026/10/06 10:44:47 WARN Failed to register uploaded object key=h04w6yc4rp0bb8s5kyf843m3sgdn31bq.ls error="server returned 404: 404 page not found\n"10032026/10/06 10:44:47 INFO Signed narinfos id=1 count=110042026/10/06 10:44:47 INFO Uploading 1 narinfos10052026/10/06 10:44:47 INFO Received complete push request method=POST path=/api/pushes/1/complete10062026/10/06 10:44:47 WARN Failed to register uploaded object key=h04w6yc4rp0bb8s5kyf843m3sgdn31bq.narinfo error="server returned 404: 404 page not found\n"10072026/10/06 10:44:47 INFO Upload complete. (120ms)1008=== NAME TestNARDeduplicationMetadataUploadBug1009 metadata_upload_test.go:54: Retrieved narinfo from S3:1010 StorePath: /nix/var/nix/builds/nix-21795-464819160/TestNARDeduplicationMetadataUploadBug808454317/001/store/h04w6yc4rp0bb8s5kyf843m3sgdn31bq-file1.txt1011 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1012 Compression: zstd1013 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1014 NarSize: 1601015 References: 1016 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1017 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1018 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1019 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1020 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-21795-464819160/TestNARDeduplicationMetadataUploadBug808454317/001/store/m0bz2qx1nj8rsbq8glhjrk62gmj2y2c0-file2.txt10212026/10/06 10:44:47 INFO Received push request method=POST path=/api/pushes10222026/10/06 10:44:47 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)10232026/10/06 10:44:47 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign10242026/10/06 10:44:47 INFO Signed narinfos id=2 count=110252026/10/06 10:44:47 INFO Uploading 1 narinfos10262026/10/06 10:44:47 WARN Failed to register uploaded object key=m0bz2qx1nj8rsbq8glhjrk62gmj2y2c0.ls error="server returned 404: 404 page not found\n"10272026/10/06 10:44:47 INFO Received complete push request method=POST path=/api/pushes/2/complete10282026/10/06 10:44:47 WARN Failed to register uploaded object key=m0bz2qx1nj8rsbq8glhjrk62gmj2y2c0.narinfo error="server returned 404: 404 page not found\n"10292026/10/06 10:44:47 INFO Upload complete. (112ms)1030 metadata_upload_test.go:76: Retrieved narinfo from S3:1031 StorePath: /nix/var/nix/builds/nix-21795-464819160/TestNARDeduplicationMetadataUploadBug808454317/001/store/m0bz2qx1nj8rsbq8glhjrk62gmj2y2c0-file2.txt1032 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1033 Compression: zstd1034 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1035 NarSize: 1601036 References: 1037 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1038 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1039 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1040 {"version":1,"root":{"type":"regular","size":44}}1041--- PASS: TestNARDeduplicationMetadataUploadBug (3.16s)1042=== CONT TestFailedS3DeleteKeepsTombstone10432026/10/06 10:44:48 INFO Aborted multipart uploads count=0 kept=010442026/10/06 10:44:48 WARN Force mode enabled - objects will be deleted immediately without grace period10452026/10/06 10:44:48 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=010462026/10/06 10:44:48 INFO Vacuumed table table=pending_closures10472026/10/06 10:44:48 INFO Vacuumed table table=pending_objects10482026/10/06 10:44:48 INFO Vacuumed table table=multipart_uploads10492026/10/06 10:44:48 INFO Vacuumed table table=closures10502026/10/06 10:44:48 INFO Vacuumed table table=objects1051--- PASS: TestCommitRacingPendingCleanupKeepsObjects (2.46s)1052=== CONT TestProxyWriteTimeout1053=== RUN TestProxyWriteTimeout/narinfo1054=== PAUSE TestProxyWriteTimeout/narinfo1055=== RUN TestProxyWriteTimeout/1_GiB_nar1056=== PAUSE TestProxyWriteTimeout/1_GiB_nar1057=== RUN TestProxyWriteTimeout/10_GiB_nar1058=== PAUSE TestProxyWriteTimeout/10_GiB_nar1059=== RUN TestProxyWriteTimeout/unknown_size1060=== PAUSE TestProxyWriteTimeout/unknown_size1061=== CONT TestSweepSkipsRowsLockedByPush1062=== NAME TestOrphanedObjectsGCStressTest1063 orphaned_objects_gc_test.go:509: Stress test completed successfully:1064 orphaned_objects_gc_test.go:510: - Active objects preserved: 201065 orphaned_objects_gc_test.go:511: - Objects deleted: 2101066 orphaned_objects_gc_test.go:512: - Total GC'd: 2101067--- PASS: TestOrphanedObjectsGCStressTest (10.50s)1068=== CONT TestReadProxy40410692026/10/06 10:44:48 WARN readiness check failed error="closed pool"1070--- PASS: TestService_readinessHandler (2.35s)1071=== CONT TestReadProxyRangeRequest1072--- PASS: TestService_healthCheckHandler (2.49s)1073=== CONT TestReadRedirectKeepsNarinfoProxied1074--- PASS: TestRegisterCompletedObjectNeedsPendingRow (2.68s)1075=== CONT TestReadRedirectNar10762026/10/06 10:44:49 INFO Received uploads request method=POST path=/api/pending_closures10772026/10/06 10:44:49 INFO Aborted multipart uploads count=0 kept=010782026/10/06 10:44:49 WARN Force mode enabled - objects will be deleted immediately without grace period10792026/10/06 10:44:49 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=010802026/10/06 10:44:49 INFO Vacuumed table table=pending_closures10812026/10/06 10:44:49 INFO Vacuumed table table=pending_objects10822026/10/06 10:44:49 INFO Vacuumed table table=multipart_uploads10832026/10/06 10:44:49 INFO Vacuumed table table=closures10842026/10/06 10:44:49 INFO Vacuumed table table=objects1085--- PASS: TestSweepRechecksPendingAfterLocking (2.94s)1086=== CONT TestReadProxyDisabled1087--- PASS: TestPushWaitsForSweepHoldingRow (3.10s)1088=== CONT TestReadProxyRootRedirectsToIndexHTML1089--- PASS: TestGetExistingObjectsLocksRows (2.44s)1090=== CONT TestReadProxyConditionalGet10912026/10/06 10:44:50 INFO Received uploads request method=POST path=/api/pending_closures10922026/10/06 10:44:50 INFO Aborted multipart uploads count=0 kept=010932026/10/06 10:44:50 WARN Force mode enabled - objects will be deleted immediately without grace period10942026/10/06 10:44:50 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."10952026/10/06 10:44:50 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1096--- PASS: TestFailedS3DeleteKeepsTombstone (2.52s)1097=== CONT TestReadProxyOutlastsServerWriteTimeout1098--- PASS: TestReadProxyRangeRequest (2.15s)1099=== CONT TestReadProxyHead11002026/10/06 10:44:50 INFO Aborted multipart uploads count=0 kept=011012026/10/06 10:44:50 WARN Force mode enabled - objects will be deleted immediately without grace period11022026/10/06 10:44:50 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 10:44:50 INFO Vacuumed table table=pending_closures11042026/10/06 10:44:50 INFO Vacuumed table table=pending_objects11052026/10/06 10:44:50 INFO Vacuumed table table=multipart_uploads11062026/10/06 10:44:50 INFO Vacuumed table table=closures11072026/10/06 10:44:50 INFO Vacuumed table table=objects11082026/10/06 10:44:50 INFO Aborted multipart uploads count=0 kept=011092026/10/06 10:44:50 WARN Force mode enabled - objects will be deleted immediately without grace period11102026/10/06 10:44:50 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 10:44:50 INFO Vacuumed table table=pending_closures11122026/10/06 10:44:50 INFO Vacuumed table table=pending_objects11132026/10/06 10:44:50 INFO Vacuumed table table=multipart_uploads11142026/10/06 10:44:50 INFO Vacuumed table table=closures11152026/10/06 10:44:50 INFO Vacuumed table table=objects1116--- PASS: TestSweepSkipsRowsLockedByPush (2.52s)1117=== CONT TestReadProxyInvalidPath1118--- PASS: TestReadProxy404 (2.69s)1119=== CONT TestClientFallsBackToClosures1120--- PASS: TestReadRedirectKeepsNarinfoProxied (2.63s)1121=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1122--- PASS: TestReadRedirectNar (2.61s)1123=== CONT TestGCSweepDeliversEachKeyOnce1124--- PASS: TestReadProxyDisabled (1.93s)1125=== CONT TestTombstonedObjectOfferedWithoutWaiting1126--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.18s)1127=== CONT TestGCSweepSkipsPendingObjects1128--- PASS: TestReadProxyConditionalGet (2.34s)1129=== CONT TestDeduplicatedObjectsRecordedAsPending11302026/10/06 10:44:52 INFO Aborted multipart uploads count=1 kept=011312026/10/06 10:44:52 INFO Received cleanup request method=DELETE path=/api/pending_closures11322026/10/06 10:44:52 INFO Aborted multipart uploads count=1 kept=01133--- PASS: TestPendingCleanupUsesOneCutoff (9.48s)1134=== CONT TestPushDedupSurvivesConcurrentGC1135--- PASS: TestReadProxyHead (2.44s)1136=== CONT TestGCMetrics1137--- PASS: TestReadProxyInvalidPath (2.44s)1138=== CONT TestGCBugBareHashReferences11392026/10/06 10:44:53 INFO Received uploads request method=POST path=/api/pending_closures11402026/10/06 10:44:53 INFO Received uploads request method=POST path=/api/pending_closures11412026/10/06 10:44:53 INFO Received uploads request method=POST path=/api/pending_closures11422026/10/06 10:44:53 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11432026/10/06 10:44:53 INFO Uploading kx3slbmas815qbi431fmasvp1xb40mww-a (248B)11442026/10/06 10:44:53 INFO Uploading crxyff61lr53a0k03pav7b7qv6qk5rfn-shared-dep (136B)11452026/10/06 10:44:53 WARN Failed to register uploaded object key=kx3slbmas815qbi431fmasvp1xb40mww.ls error="server returned 404: 404 page not found\n"11462026/10/06 10:44:53 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11472026/10/06 10:44:53 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11482026/10/06 10:44:53 WARN Failed to register uploaded object key=nar/1vdwxwzy9y01957g4pdqspy6pjkf7mvl8aky1930xz51y2a25lgv.nar.zst error="server returned 404: 404 page not found\n"11492026/10/06 10:44:53 WARN Failed to register uploaded object key=crxyff61lr53a0k03pav7b7qv6qk5rfn.ls error="server returned 404: 404 page not found\n"11502026/10/06 10:44:53 WARN Failed to register uploaded object key=b3cbl0xqr6nim6q1wk56ljjbp2x0fm2d.ls error="server returned 404: 404 page not found\n"11512026/10/06 10:44:53 INFO Signed narinfos id=1 count=211522026/10/06 10:44:53 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign11532026/10/06 10:44:53 INFO Signed narinfos id=2 count=211542026/10/06 10:44:53 INFO Uploading 4 narinfos11552026/10/06 10:44:53 WARN Failed to register uploaded object key=b3cbl0xqr6nim6q1wk56ljjbp2x0fm2d.narinfo error="server returned 404: 404 page not found\n"11562026/10/06 10:44:53 WARN Failed to register uploaded object key=crxyff61lr53a0k03pav7b7qv6qk5rfn.narinfo error="server returned 404: 404 page not found\n"11572026/10/06 10:44:53 WARN Failed to register uploaded object key=kx3slbmas815qbi431fmasvp1xb40mww.narinfo error="server returned 404: 404 page not found\n"11582026/10/06 10:44:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11592026/10/06 10:44:54 WARN Failed to register uploaded object key=crxyff61lr53a0k03pav7b7qv6qk5rfn.narinfo error="server returned 404: 404 page not found\n"11602026/10/06 10:44:54 INFO Completed upload id=111612026/10/06 10:44:54 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11622026/10/06 10:44:54 INFO Completed upload id=211632026/10/06 10:44:54 INFO Upload complete. (118ms)1164=== NAME TestClientFallsBackToClosures1165 client_pushes_test.go:112: Retrieved narinfo from S3:1166 StorePath: /nix/var/nix/builds/nix-21795-464819160/TestClientFallsBackToClosures2410289971/001/store/crxyff61lr53a0k03pav7b7qv6qk5rfn-shared-dep1167 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1168 Compression: zstd1169 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821170 NarSize: 1361171 References: 1172 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1173 client_pushes_test.go:112: Retrieved narinfo from S3:1174 StorePath: /nix/var/nix/builds/nix-21795-464819160/TestClientFallsBackToClosures2410289971/001/store/kx3slbmas815qbi431fmasvp1xb40mww-a1175 URL: nar/1vdwxwzy9y01957g4pdqspy6pjkf7mvl8aky1930xz51y2a25lgv.nar.zst1176 Compression: zstd1177 NarHash: sha256:1vdwxwzy9y01957g4pdqspy6pjkf7mvl8aky1930xz51y2a25lgv1178 NarSize: 2481179 References: /nix/var/nix/builds/nix-21795-464819160/TestClientFallsBackToClosures2410289971/001/store/crxyff61lr53a0k03pav7b7qv6qk5rfn-shared-dep1180 CA: text:sha256:1s9f2x0rnidh0yz44bpcl9fz8ybvxf1x4043f5gai8ilf0i8i1cl1181 client_pushes_test.go:112: Retrieved narinfo from S3:1182 StorePath: /nix/var/nix/builds/nix-21795-464819160/TestClientFallsBackToClosures2410289971/001/store/b3cbl0xqr6nim6q1wk56ljjbp2x0fm2d-b1183 URL: nar/1vdwxwzy9y01957g4pdqspy6pjkf7mvl8aky1930xz51y2a25lgv.nar.zst1184 Compression: zstd1185 NarHash: sha256:1vdwxwzy9y01957g4pdqspy6pjkf7mvl8aky1930xz51y2a25lgv1186 NarSize: 2481187 References: /nix/var/nix/builds/nix-21795-464819160/TestClientFallsBackToClosures2410289971/001/store/crxyff61lr53a0k03pav7b7qv6qk5rfn-shared-dep1188 CA: text:sha256:1s9f2x0rnidh0yz44bpcl9fz8ybvxf1x4043f5gai8ilf0i8i1cl1189--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (2.70s)1190=== CONT TestGCAdvisoryLockBlocksConcurrentRun11912026/10/06 10:44:54 INFO Aborted multipart uploads count=0 kept=011922026/10/06 10:44:54 WARN Force mode enabled - objects will be deleted immediately without grace period1193--- PASS: TestClientFallsBackToClosures (2.95s)1194=== CONT TestLeadEndsOnShutdown11952026/10/06 10:44:54 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=011962026/10/06 10:44:54 INFO Vacuumed table table=pending_closures11972026/10/06 10:44:54 INFO Vacuumed table table=pending_objects11982026/10/06 10:44:54 INFO Vacuumed table table=multipart_uploads11992026/10/06 10:44:54 INFO Vacuumed table table=closures12002026/10/06 10:44:54 INFO Vacuumed table table=objects1201--- PASS: TestGCSweepDeliversEachKeyOnce (2.54s)1202=== CONT TestLeadIncumbentAnnouncesAtOnce12032026/10/06 10:44:54 INFO Received uploads request method=POST path=/api/pending_closures1204--- PASS: TestTombstonedObjectOfferedWithoutWaiting (2.40s)1205=== CONT TestLeadElectsOneAndHandsOver12062026/10/06 10:44:54 INFO Received uploads request method=POST path=/api/pending_closures12072026/10/06 10:44:54 INFO Aborted multipart uploads count=0 kept=012082026/10/06 10:44:54 WARN Force mode enabled - objects will be deleted immediately without grace period12092026/10/06 10:44:54 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=012102026/10/06 10:44:54 INFO Vacuumed table table=pending_closures12112026/10/06 10:44:54 INFO Vacuumed table table=pending_objects12122026/10/06 10:44:54 INFO Vacuumed table table=multipart_uploads12132026/10/06 10:44:54 INFO Vacuumed table table=closures12142026/10/06 10:44:54 INFO Vacuumed table table=objects1215--- PASS: TestGCSweepSkipsPendingObjects (2.40s)1216=== CONT TestConnectWaitsForAPeerMigration12172026/10/06 10:44:54 INFO Received uploads request method=POST path=/api/pending_closures1218--- PASS: TestDeduplicatedObjectsRecordedAsPending (2.20s)1219=== CONT TestResolveDBConnectionString1220=== RUN TestResolveDBConnectionString/flag_wins1221=== PAUSE TestResolveDBConnectionString/flag_wins1222=== RUN TestResolveDBConnectionString/file_when_flag_empty1223=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1224=== RUN TestResolveDBConnectionString/missing_file_is_an_error1225=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1226=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1227=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1228=== RUN TestResolveDBConnectionString/nothing_configured1229=== PAUSE TestResolveDBConnectionString/nothing_configured1230=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock12312026/10/06 10:44:54 INFO Received uploads request method=POST path=/api/pending_closures12322026/10/06 10:44:55 INFO Aborted multipart uploads count=0 kept=012332026/10/06 10:44:55 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=012342026/10/06 10:44:55 INFO Vacuumed table table=pending_closures12352026/10/06 10:44:55 INFO Aborted multipart uploads count=0 kept=012362026/10/06 10:44:55 WARN Force mode enabled - objects will be deleted immediately without grace period12372026/10/06 10:44:55 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=012382026/10/06 10:44:55 INFO Vacuumed table table=pending_closures12392026/10/06 10:44:55 INFO Vacuumed table table=pending_objects12402026/10/06 10:44:55 INFO Vacuumed table table=multipart_uploads12412026/10/06 10:44:55 INFO Vacuumed table table=closures12422026/10/06 10:44:55 INFO Vacuumed table table=objects1243--- PASS: TestGCMetrics (2.08s)1244=== CONT TestClientCADerivations12452026/10/06 10:44:55 INFO Vacuumed table table=pending_objects12462026/10/06 10:44:55 INFO Vacuumed table table=multipart_uploads12472026/10/06 10:44:55 INFO Vacuumed table table=closures12482026/10/06 10:44:55 INFO Vacuumed table table=objects12492026/10/06 10:44:55 INFO Aborted multipart uploads count=0 kept=012502026/10/06 10:44:55 WARN Force mode enabled - objects will be deleted immediately without grace period12512026/10/06 10:44:55 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=012522026/10/06 10:44:55 INFO Vacuumed table table=pending_closures12532026/10/06 10:44:55 INFO Vacuumed table table=pending_objects12542026/10/06 10:44:55 INFO Vacuumed table table=multipart_uploads12552026/10/06 10:44:55 INFO Vacuumed table table=closures12562026/10/06 10:44:55 INFO Vacuumed table table=objects1257--- PASS: TestPushDedupSurvivesConcurrentGC (2.66s)1258=== CONT TestClientPushesUseOnePush1259--- PASS: TestGCBugBareHashReferences (2.29s)1260=== CONT TestIsValidCachePath1261=== RUN TestIsValidCachePath/narinfo1262=== PAUSE TestIsValidCachePath/narinfo1263=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1264=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1265=== RUN TestIsValidCachePath/nar_zst1266=== PAUSE TestIsValidCachePath/nar_zst1267=== RUN TestIsValidCachePath/nar_xz1268=== PAUSE TestIsValidCachePath/nar_xz1269=== RUN TestIsValidCachePath/nar_bz21270=== PAUSE TestIsValidCachePath/nar_bz21271=== RUN TestIsValidCachePath/nar_uncompressed1272=== PAUSE TestIsValidCachePath/nar_uncompressed1273=== RUN TestIsValidCachePath/ls1274=== PAUSE TestIsValidCachePath/ls1275=== RUN TestIsValidCachePath/log1276=== PAUSE TestIsValidCachePath/log1277=== RUN TestIsValidCachePath/realisation1278=== PAUSE TestIsValidCachePath/realisation1279=== RUN TestIsValidCachePath/nix-cache-info1280=== PAUSE TestIsValidCachePath/nix-cache-info1281=== RUN TestIsValidCachePath/index.html1282=== PAUSE TestIsValidCachePath/index.html1283=== RUN TestIsValidCachePath/traversal_parent1284=== PAUSE TestIsValidCachePath/traversal_parent1285=== RUN TestIsValidCachePath/traversal_in_middle1286=== PAUSE TestIsValidCachePath/traversal_in_middle1287=== RUN TestIsValidCachePath/invalid_char_e1288=== PAUSE TestIsValidCachePath/invalid_char_e1289=== RUN TestIsValidCachePath/invalid_char_u1290=== PAUSE TestIsValidCachePath/invalid_char_u1291=== RUN TestIsValidCachePath/random_path1292=== PAUSE TestIsValidCachePath/random_path1293=== RUN TestIsValidCachePath/empty1294=== PAUSE TestIsValidCachePath/empty1295=== RUN TestIsValidCachePath/leading_slash1296=== PAUSE TestIsValidCachePath/leading_slash1297=== RUN TestIsValidCachePath/wrong_extension1298=== PAUSE TestIsValidCachePath/wrong_extension1299=== RUN TestIsValidCachePath/short_hash1300=== PAUSE TestIsValidCachePath/short_hash1301=== CONT TestReadProxyNarStreaming13022026/10/06 10:44:55 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_nixbld1 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1303--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (1.58s)1304=== CONT TestReadProxyContentNegotiation13052026/10/06 10:44:55 INFO lead: acquired remote=192.0.2.1:123413062026/10/06 10:44:56 INFO lead: acquired remote=192.0.2.1:123413072026/10/06 10:44:56 INFO lead: released remote=192.0.2.1:12341308--- PASS: TestLeadIncumbentAnnouncesAtOnce (1.91s)1309=== CONT TestReadProxyNarinfoAlreadyDecompressed13102026/10/06 10:44:56 INFO lead: acquired remote=192.0.2.1:123413112026/10/06 10:44:56 INFO lead: released remote=192.0.2.1:12341312--- PASS: TestLeadEndsOnShutdown (2.80s)1313=== CONT TestReadProxyNarinfo1314--- PASS: TestReadProxyOutlastsServerWriteTimeout (6.43s)1315=== CONT TestService_RequireScope_OIDC13162026/10/06 10:44:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52959/oidc1317=== NAME TestClientCADerivations1318 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-21795-464819160/TestClientCADerivations759746249/001/store/6pgs51jvj4kdzv9znm8n2rwisnk21nfx-ca-test1319 client_ca_test.go:139: Found 1 dependencies (including self)1320--- PASS: TestReadProxyContentNegotiation (1.57s)1321=== CONT TestProxyHeadersOnlyTrustedOnSocket13222026/10/06 10:44:57 INFO Received push request method=POST path=/api/pushes13232026/10/06 10:44:57 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13242026/10/06 10:44:57 INFO Uploading 6b556adrp3p2ra37slnz8ybav50g6lwz-shared-dep (136B)13252026/10/06 10:44:57 INFO Uploading w6mlwc1dwrs4zmqwibf0hq6brqlmjmfg-a (248B)13262026/10/06 10:44:57 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13272026/10/06 10:44:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13282026/10/06 10:44:57 WARN Failed to register uploaded object key=nar/1i0r7d5anbqinblyj5s0g8fi6r38l58vlljck91vdcini45344j0.nar.zst error="server returned 404: 404 page not found\n"13292026/10/06 10:44:57 WARN Failed to register uploaded object key=vbrxclwkkljfph9ayq5p870md957p5vk.ls error="server returned 404: 404 page not found\n"13302026/10/06 10:44:57 WARN Failed to register uploaded object key=w6mlwc1dwrs4zmqwibf0hq6brqlmjmfg.ls error="server returned 404: 404 page not found\n"13312026/10/06 10:44:57 WARN Failed to register uploaded object key=6b556adrp3p2ra37slnz8ybav50g6lwz.ls error="server returned 404: 404 page not found\n"13322026/10/06 10:44:57 INFO Signed narinfos id=1 count=313332026/10/06 10:44:57 INFO Uploading 3 narinfos13342026/10/06 10:44:57 INFO Received push request method=POST path=/api/pushes13352026/10/06 10:44:57 WARN Failed to register uploaded object key=vbrxclwkkljfph9ayq5p870md957p5vk.narinfo error="server returned 404: 404 page not found\n"13362026/10/06 10:44:57 INFO Received complete push request method=POST path=/api/pushes/1/complete13372026/10/06 10:44:57 WARN Failed to register uploaded object key=6b556adrp3p2ra37slnz8ybav50g6lwz.narinfo error="server returned 404: 404 page not found\n"13382026/10/06 10:44:57 WARN Failed to register uploaded object key=w6mlwc1dwrs4zmqwibf0hq6brqlmjmfg.narinfo error="server returned 404: 404 page not found\n"13392026/10/06 10:44:57 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13402026/10/06 10:44:57 INFO Uploading 6pgs51jvj4kdzv9znm8n2rwisnk21nfx-ca-test (144B)13412026/10/06 10:44:57 WARN Failed to register uploaded object key=6pgs51jvj4kdzv9znm8n2rwisnk21nfx.ls error="server returned 404: 404 page not found\n"13422026/10/06 10:44:57 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13432026/10/06 10:44:57 INFO Upload complete. (119ms)1344=== NAME TestClientPushesUseOnePush1345 client_pushes_test.go:97: Retrieved narinfo from S3:1346 StorePath: /nix/var/nix/builds/nix-21795-464819160/TestClientPushesUseOnePush1210081161/001/store/6b556adrp3p2ra37slnz8ybav50g6lwz-shared-dep1347 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1348 Compression: zstd1349 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821350 NarSize: 1361351 References: 1352 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1353 client_pushes_test.go:97: Retrieved narinfo from S3:1354 StorePath: /nix/var/nix/builds/nix-21795-464819160/TestClientPushesUseOnePush1210081161/001/store/w6mlwc1dwrs4zmqwibf0hq6brqlmjmfg-a1355 URL: nar/1i0r7d5anbqinblyj5s0g8fi6r38l58vlljck91vdcini45344j0.nar.zst1356 Compression: zstd1357 NarHash: sha256:1i0r7d5anbqinblyj5s0g8fi6r38l58vlljck91vdcini45344j01358 NarSize: 2481359 References: /nix/var/nix/builds/nix-21795-464819160/TestClientPushesUseOnePush1210081161/001/store/6b556adrp3p2ra37slnz8ybav50g6lwz-shared-dep1360 CA: text:sha256:1wddldnh4zpx8wc8zvjkih9v0z1dwyq7i8hcl1l90vnb4p7l3v551361 client_pushes_test.go:97: Retrieved narinfo from S3:1362 StorePath: /nix/var/nix/builds/nix-21795-464819160/TestClientPushesUseOnePush1210081161/001/store/vbrxclwkkljfph9ayq5p870md957p5vk-b1363 URL: nar/1i0r7d5anbqinblyj5s0g8fi6r38l58vlljck91vdcini45344j0.nar.zst1364 Compression: zstd1365 NarHash: sha256:1i0r7d5anbqinblyj5s0g8fi6r38l58vlljck91vdcini45344j01366 NarSize: 2481367 References: /nix/var/nix/builds/nix-21795-464819160/TestClientPushesUseOnePush1210081161/001/store/6b556adrp3p2ra37slnz8ybav50g6lwz-shared-dep1368 CA: text:sha256:1wddldnh4zpx8wc8zvjkih9v0z1dwyq7i8hcl1l90vnb4p7l3v5513692026/10/06 10:44:57 WARN Failed to register uploaded object key=log/in8fvs0kijjfjyhgnb8zd2cxniyhd01m-ca-test.drv error="server returned 404: 404 page not found\n"13702026/10/06 10:44:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13712026/10/06 10:44:57 INFO Signed narinfos id=1 count=113722026/10/06 10:44:57 INFO Uploading 1 narinfos13732026/10/06 10:44:57 INFO Received complete push request method=POST path=/api/pushes/1/complete13742026/10/06 10:44:57 WARN Failed to register uploaded object key=6pgs51jvj4kdzv9znm8n2rwisnk21nfx.narinfo error="server returned 404: 404 page not found\n"1375--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (2.68s)1376=== CONT TestParseSingleRange1377=== RUN TestParseSingleRange/none1378=== PAUSE TestParseSingleRange/none1379=== RUN TestParseSingleRange/unknown_unit1380=== PAUSE TestParseSingleRange/unknown_unit1381=== RUN TestParseSingleRange/multi-range_ignored1382=== PAUSE TestParseSingleRange/multi-range_ignored1383=== RUN TestParseSingleRange/malformed_no_dash1384=== PAUSE TestParseSingleRange/malformed_no_dash1385=== RUN TestParseSingleRange/malformed_both_empty1386=== PAUSE TestParseSingleRange/malformed_both_empty1387=== RUN TestParseSingleRange/malformed_end_before_start1388=== PAUSE TestParseSingleRange/malformed_end_before_start1389=== RUN TestParseSingleRange/closed1390=== PAUSE TestParseSingleRange/closed1391=== RUN TestParseSingleRange/open-ended1392=== PAUSE TestParseSingleRange/open-ended1393=== RUN TestParseSingleRange/end_clamped_to_size1394=== PAUSE TestParseSingleRange/end_clamped_to_size1395=== RUN TestParseSingleRange/suffix1396=== PAUSE TestParseSingleRange/suffix1397=== RUN TestParseSingleRange/suffix_exceeds_size1398=== PAUSE TestParseSingleRange/suffix_exceeds_size1399=== RUN TestParseSingleRange/single_byte1400=== PAUSE TestParseSingleRange/single_byte1401=== RUN TestParseSingleRange/start_past_EOF1402=== PAUSE TestParseSingleRange/start_past_EOF1403=== RUN TestParseSingleRange/start_far_past_EOF1404=== PAUSE TestParseSingleRange/start_far_past_EOF1405=== CONT TestPresentNotReportedWhileGCDeletesClosure14062026/10/06 10:44:57 INFO Upload complete. (193ms)1407--- PASS: TestReadProxyNarStreaming (1.76s)1408=== CONT TestPresentReportsOnlyClosureRoots1409=== NAME TestClientCADerivations1410 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-21795-464819160/TestClientCADerivations759746249/001/store/6pgs51jvj4kdzv9znm8n2rwisnk21nfx-ca-test1411 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1412 Compression: zstd1413 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1414 NarSize: 1441415 References: 1416 Deriver: /nix/var/nix/builds/nix-21795-464819160/TestClientCADerivations759746249/001/store/in8fvs0kijjfjyhgnb8zd2cxniyhd01m-ca-test.drv1417 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1418 client_ca_test.go:185: Checking for realisation files in S3...1419 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1420 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1421--- PASS: TestClientPushesUseOnePush (2.16s)1422=== CONT TestPinProtectsFromGC1423=== NAME TestClientCADerivations1424 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket64?endpoint=http://localhost:52718®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-21795-464819160/TestClientCADerivations759746249/001/store'1425 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11426--- PASS: TestClientCADerivations (2.34s)1427=== CONT TestClientSharedPathCommittedMidPush14282026/10/06 10:44:57 INFO lead: released remote=192.0.2.1:123414292026/10/06 10:44:57 INFO lead: acquired remote=192.0.2.1:12341430--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.49s)1431=== CONT TestCacheConfigHandler1432=== RUN TestCacheConfigHandler/full_config,_no_issuer1433=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1434=== RUN TestCacheConfigHandler/no_cache_url_configured1435=== PAUSE TestCacheConfigHandler/no_cache_url_configured1436=== RUN TestCacheConfigHandler/no_signing_keys1437=== PAUSE TestCacheConfigHandler/no_signing_keys1438=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1439=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1440=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check14412026/10/06 10:44:57 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1442--- PASS: TestReadProxyNarinfo (1.01s)1443=== CONT TestClientIntegration1444=== RUN TestService_RequireScope_OIDC/builder_may_write1445=== PAUSE TestService_RequireScope_OIDC/builder_may_write1446=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1447=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1448=== RUN TestService_RequireScope_OIDC/ops_may_admin1449=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1450=== RUN TestService_RequireScope_OIDC/ops_may_not_write1451=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1452=== RUN TestService_RequireScope_OIDC/reader_may_not_write1453=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1454=== RUN TestService_RequireScope_OIDC/static_token_may_admin1455=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1456=== RUN TestService_RequireScope_OIDC/static_token_may_write1457=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1458=== RUN TestService_RequireScope_OIDC/reader_may_read1459=== PAUSE TestService_RequireScope_OIDC/reader_may_read1460=== RUN TestService_RequireScope_OIDC/writer_implies_read1461=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1462=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1463=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1464=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1465=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1466=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1467=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1468=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1469=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1470=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1471=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1472=== CONT TestService_ReadScope_PublicByDefault14732026/10/06 10:44:58 INFO Starting HTTP server address=/nix/var/nix/builds/nix-21795-464819160/TestProxyHeadersOnlyTrustedOnSocket752778460/001/proxy.sock14742026/10/06 10:44:58 INFO Starting HTTP server address=127.0.0.1:5300514752026/10/06 10:44:58 WARN mTLS auth: subject not in bound subjects subject="CN=someone"14762026/10/06 10:44:58 INFO Shutdown signal received, draining in-flight requests timeout=10s1477=== CONT TestClientErrorHandling1478--- PASS: TestProxyHeadersOnlyTrustedOnSocket (1.25s)1479=== RUN TestClientErrorHandling/InvalidStorePath1480=== PAUSE TestClientErrorHandling/InvalidStorePath1481=== RUN TestClientErrorHandling/InvalidAuthToken1482=== PAUSE TestClientErrorHandling/InvalidAuthToken1483=== RUN TestClientErrorHandling/ServerNotAvailable1484=== PAUSE TestClientErrorHandling/ServerNotAvailable1485=== CONT TestService_ReadAuthMiddleware14862026/10/06 10:44:58 INFO lead: released remote=192.0.2.1:12341487--- PASS: TestLeadElectsOneAndHandsOver (4.30s)1488=== CONT TestClientWithDependencies1489=== NAME TestPinProtectsFromGC1490 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-21795-464819160/TestPinProtectsFromGC3378949074/001/store/k3s292j9xmpxp33c8alq1v28rijsn9q6-pinned-file.txt1491 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-21795-464819160/TestPinProtectsFromGC3378949074/001/store/208zvrc29rmpcbdjmsj1hy2r6rd1bq8g-unpinned-file.txt14922026/10/06 10:44:59 INFO Received push request method=POST path=/api/pushes14932026/10/06 10:44:59 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14942026/10/06 10:44:59 INFO Uploading k3s292j9xmpxp33c8alq1v28rijsn9q6-pinned-file.txt (128B)1495--- PASS: TestPresentNotReportedWhileGCDeletesClosure (1.81s)1496=== CONT TestService_AuthMiddleware_OIDC14972026/10/06 10:44:59 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14982026/10/06 10:44:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14992026/10/06 10:44:59 WARN Failed to register uploaded object key=k3s292j9xmpxp33c8alq1v28rijsn9q6.ls error="server returned 404: 404 page not found\n"15002026/10/06 10:44:59 INFO Signed narinfos id=1 count=115012026/10/06 10:44:59 INFO Uploading 1 narinfos15022026/10/06 10:44:59 INFO Received complete push request method=POST path=/api/pushes/1/complete15032026/10/06 10:44:59 WARN Failed to register uploaded object key=k3s292j9xmpxp33c8alq1v28rijsn9q6.narinfo error="server returned 404: 404 page not found\n"15042026/10/06 10:44:59 INFO Upload complete. (105ms)15052026/10/06 10:44:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53024/oidc15062026/10/06 10:44:59 INFO Received push request method=POST path=/api/pushes15072026/10/06 10:44:59 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15082026/10/06 10:44:59 INFO Uploading 208zvrc29rmpcbdjmsj1hy2r6rd1bq8g-unpinned-file.txt (128B)15092026/10/06 10:44:59 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15102026/10/06 10:44:59 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15112026/10/06 10:44:59 INFO Signed narinfos id=2 count=115122026/10/06 10:44:59 INFO Uploading 1 narinfos15132026/10/06 10:44:59 WARN Failed to register uploaded object key=208zvrc29rmpcbdjmsj1hy2r6rd1bq8g.ls error="server returned 404: 404 page not found\n"1514--- PASS: TestPresentReportsOnlyClosureRoots (1.92s)1515=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15162026/10/06 10:44:59 INFO Received complete push request method=POST path=/api/pushes/2/complete15172026/10/06 10:44:59 WARN Failed to register uploaded object key=208zvrc29rmpcbdjmsj1hy2r6rd1bq8g.narinfo error="server returned 404: 404 page not found\n"15182026/10/06 10:44:59 INFO Upload complete. (87ms)15192026/10/06 10:44:59 INFO Received push request method=POST path=/api/pushes15202026/10/06 10:44:59 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)15212026/10/06 10:44:59 INFO Uploading qanbx3mcvbfqgmakva8fdkq6xc4rlsys-top (256B)15222026/10/06 10:44:59 INFO Uploading 7j5lbq14b2vbbciqj4wqwm4jymirl4ii-shared-dep (136B)15232026/10/06 10:44:59 INFO Starting cleanup of old closures method=DELETE path=/api/closures15242026/10/06 10:44:59 INFO Garbage collection started15252026/10/06 10:44:59 INFO Aborted multipart uploads count=0 kept=015262026/10/06 10:44:59 WARN Failed to register uploaded object key=7j5lbq14b2vbbciqj4wqwm4jymirl4ii.ls error="server returned 404: 404 page not found\n"15272026/10/06 10:44:59 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15282026/10/06 10:44:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15292026/10/06 10:44:59 WARN Failed to register uploaded object key=nar/1srrb28ghsrrn3xrxf90ccnlpdqlvidaqxvzc74p21gk53jajx4d.nar.zst error="server returned 404: 404 page not found\n"15302026/10/06 10:44:59 WARN Failed to register uploaded object key=qanbx3mcvbfqgmakva8fdkq6xc4rlsys.ls error="server returned 404: 404 page not found\n"15312026/10/06 10:44:59 INFO Signed narinfos id=1 count=215322026/10/06 10:44:59 INFO Uploading 2 narinfos15332026/10/06 10:44:59 WARN Force mode enabled - objects will be deleted immediately without grace period15342026/10/06 10:44:59 INFO Received complete push request method=POST path=/api/pushes/1/complete15352026/10/06 10:44:59 WARN Failed to register uploaded object key=qanbx3mcvbfqgmakva8fdkq6xc4rlsys.narinfo error="server returned 404: 404 page not found\n"15362026/10/06 10:44:59 WARN Failed to register uploaded object key=7j5lbq14b2vbbciqj4wqwm4jymirl4ii.narinfo error="server returned 404: 404 page not found\n"15372026/10/06 10:44:59 INFO Upload complete. (144ms)1538=== NAME TestClientSharedPathCommittedMidPush1539 client_integration_test.go:680: Retrieved narinfo from S3:1540 StorePath: /nix/var/nix/builds/nix-21795-464819160/TestClientSharedPathCommittedMidPush3804276231/001/store/7j5lbq14b2vbbciqj4wqwm4jymirl4ii-shared-dep1541 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1542 Compression: zstd1543 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821544 NarSize: 1361545 References: 1546 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1547 client_integration_test.go:680: Retrieved narinfo from S3:1548 StorePath: /nix/var/nix/builds/nix-21795-464819160/TestClientSharedPathCommittedMidPush3804276231/001/store/qanbx3mcvbfqgmakva8fdkq6xc4rlsys-top1549 URL: nar/1srrb28ghsrrn3xrxf90ccnlpdqlvidaqxvzc74p21gk53jajx4d.nar.zst1550 Compression: zstd1551 NarHash: sha256:1srrb28ghsrrn3xrxf90ccnlpdqlvidaqxvzc74p21gk53jajx4d1552 NarSize: 2561553 References: /nix/var/nix/builds/nix-21795-464819160/TestClientSharedPathCommittedMidPush3804276231/001/store/7j5lbq14b2vbbciqj4wqwm4jymirl4ii-shared-dep1554 CA: text:sha256:1zlg9h9ifsyv50c60k8dvsv3aq6dy6mkzr79bi0dhxdimw2d14qf15552026/10/06 10:44:59 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=015562026/10/06 10:44:59 INFO Vacuumed table table=pending_closures1557--- PASS: TestClientSharedPathCommittedMidPush (2.00s)1558=== CONT TestClientMultipleUploads15592026/10/06 10:44:59 INFO Vacuumed table table=pending_objects15602026/10/06 10:44:59 INFO Vacuumed table table=multipart_uploads15612026/10/06 10:44:59 INFO Vacuumed table table=closures15622026/10/06 10:44:59 INFO Received uploads request method=POST path=/api/pending_closures15632026/10/06 10:44:59 INFO Vacuumed table table=objects15642026/10/06 10:44:59 INFO Aborted multipart uploads count=0 kept=015652026/10/06 10:44:59 WARN Force mode enabled - objects will be deleted immediately without grace period15662026/10/06 10:44:59 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=015672026/10/06 10:44:59 INFO Vacuumed table table=pending_closures15682026/10/06 10:44:59 INFO Vacuumed table table=pending_objects15692026/10/06 10:44:59 INFO Vacuumed table table=multipart_uploads15702026/10/06 10:44:59 INFO Vacuumed table table=closures15712026/10/06 10:44:59 INFO Vacuumed table table=objects1572=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1573--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1574 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.70s)1575 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (2.19s)1576=== NAME TestClientIntegration1577 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-21795-464819160/TestClientIntegration2550294968/002/store/yc665k7lmj424yr3z4byg1wckavmq4wk-test-file.txt1578--- PASS: TestService_ReadScope_PublicByDefault (1.96s)1579=== CONT TestService_AuthMiddleware_MTLSProxyHeader15802026/10/06 10:45:00 INFO Received push request method=POST path=/api/pushes15812026/10/06 10:45:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15822026/10/06 10:45:00 INFO Uploading yc665k7lmj424yr3z4byg1wckavmq4wk-test-file.txt (152B)15832026/10/06 10:45:00 WARN Failed to register uploaded object key=yc665k7lmj424yr3z4byg1wckavmq4wk.ls error="server returned 404: 404 page not found\n"15842026/10/06 10:45:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15852026/10/06 10:45:00 INFO Signed narinfos id=1 count=115862026/10/06 10:45:00 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15872026/10/06 10:45:00 INFO Uploading 1 narinfos15882026/10/06 10:45:00 INFO Received complete push request method=POST path=/api/pushes/1/complete15892026/10/06 10:45:00 WARN Failed to register uploaded object key=yc665k7lmj424yr3z4byg1wckavmq4wk.narinfo error="server returned 404: 404 page not found\n"15902026/10/06 10:45:00 INFO Upload complete. (118ms)15912026/10/06 10:45:00 INFO All 1 paths already cached1592=== NAME TestClientIntegration1593 client_integration_test.go:312: Retrieved narinfo from S3:1594 StorePath: /nix/var/nix/builds/nix-21795-464819160/TestClientIntegration2550294968/002/store/yc665k7lmj424yr3z4byg1wckavmq4wk-test-file.txt1595 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1596 Compression: zstd1597 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11598 NarSize: 1521599 References: 1600 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11601 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1602 client_integration_test.go:313: Decompressed .ls content (64 bytes):1603 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1604 client_integration_test.go:316: Testing garbage collection...16052026/10/06 10:45:00 INFO Starting cleanup of old closures method=DELETE path=/api/closures16062026/10/06 10:45:00 INFO Garbage collection started16072026/10/06 10:45:00 INFO Aborted multipart uploads count=0 kept=016082026/10/06 10:45:00 WARN Force mode enabled - objects will be deleted immediately without grace period1609--- PASS: TestService_ReadAuthMiddleware (1.91s)1610=== CONT TestSkippedUploadsHandler16112026/10/06 10:45:00 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001612--- PASS: TestSkippedUploadsHandler (0.00s)1613=== CONT TestCacheStatsHandler16142026/10/06 10:45:00 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=016152026/10/06 10:45:00 INFO Vacuumed table table=pending_closures16162026/10/06 10:45:00 INFO Vacuumed table table=pending_objects16172026/10/06 10:45:00 INFO Vacuumed table table=multipart_uploads16182026/10/06 10:45:00 INFO Vacuumed table table=closures16192026/10/06 10:45:00 INFO Vacuumed table table=objects1620--- PASS: TestConnectWaitsForAPeerMigration (6.37s)1621=== CONT TestPendingClosureWriteTimeout1622=== RUN TestPendingClosureWriteTimeout/empty1623=== PAUSE TestPendingClosureWriteTimeout/empty1624=== RUN TestPendingClosureWriteTimeout/400_objects1625=== PAUSE TestPendingClosureWriteTimeout/400_objects1626=== RUN TestPendingClosureWriteTimeout/670k_objects1627=== PAUSE TestPendingClosureWriteTimeout/670k_objects1628=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1629=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1630=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1631=== CONT TestIsValidUploadKey/narinfo1632=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1633=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1634=== CONT TestIsValidUploadKey/index.html1635=== CONT TestIsValidUploadKey/nix-cache-info1636=== CONT TestIsValidUploadKey/realisation_plus_in_output1637=== CONT TestIsValidUploadKey/realisation1638=== CONT TestIsValidUploadKey/build_log_equals1639=== CONT TestIsValidUploadKey/build_log_question_mark1640=== CONT TestIsValidUploadKey/build_log_plus_in_name1641=== CONT TestIsValidUploadKey/build_log_home-manager_file1642=== CONT TestIsValidUploadKey/build_log1643=== CONT TestIsValidUploadKey/listing1644=== CONT TestIsValidUploadKey/nar_plain1645=== CONT TestIsValidUploadKey/nar_xz1646=== CONT TestIsValidUploadKey/nar_zst1647=== CONT TestIsValidUploadKey/absolute1648=== CONT TestIsValidUploadKey/unknown_type1649=== CONT TestIsValidUploadKey/empty_key1650=== CONT TestIsValidUploadKey/traversal_nar1651=== CONT TestIsValidUploadKey/traversal1652--- PASS: TestIsValidUploadKey (0.00s)1653 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1654 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1655 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1656 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1657 --- PASS: TestIsValidUploadKey/index.html (0.00s)1658 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1659 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1660 --- PASS: TestIsValidUploadKey/realisation (0.00s)1661 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1662 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1663 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1664 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1665 --- PASS: TestIsValidUploadKey/build_log (0.00s)1666 --- PASS: TestIsValidUploadKey/listing (0.00s)1667 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1668 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1669 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1670 --- PASS: TestIsValidUploadKey/absolute (0.00s)1671 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1672 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1673 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1674 --- PASS: TestIsValidUploadKey/traversal (0.00s)1675=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16762026/10/06 10:45:00 INFO Received uploads request method=POST path=/1677=== NAME TestClientWithDependencies1678 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-21795-464819160/TestClientWithDependencies3419477846/001/store/55d1kwwzbrxvb3szmvgbx4hggn68929n-test-script1679 client_integration_test.go:615: Found 1 dependencies (including self)16802026/10/06 10:45:01 INFO Received push request method=POST path=/api/pushes16812026/10/06 10:45:01 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16822026/10/06 10:45:01 INFO Uploading 55d1kwwzbrxvb3szmvgbx4hggn68929n-test-script (136B)1683=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1684=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1685=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1686=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1687=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1688=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1689=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1690=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1691=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16922026/10/06 10:45:01 INFO Received request for more parts method=POST path=/16932026/10/06 10:45:01 WARN Failed to register uploaded object key=55d1kwwzbrxvb3szmvgbx4hggn68929n.ls error="server returned 404: 404 page not found\n"16942026/10/06 10:45:01 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"1695=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16962026/10/06 10:45:01 INFO Received complete multipart upload request method=POST path=/16972026/10/06 10:45:01 WARN Failed to register uploaded object key=log/hrk4iwfg95yx2nv5yw06f53pnb81dskn-test-script.drv error="server returned 404: 404 page not found\n"16982026/10/06 10:45:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16992026/10/06 10:45:01 INFO Signed narinfos id=1 count=117002026/10/06 10:45:01 INFO Uploading 1 narinfos1701=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17022026/10/06 10:45:01 INFO Received uploads request method=POST path=/1703=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17042026/10/06 10:45:01 INFO Received complete multipart upload request method=POST path=/1705=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17062026/10/06 10:45:01 INFO Received request for more parts method=POST path=/1707=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17082026/10/06 10:45:01 INFO Received uploads request method=POST path=/1709--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1710 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1711 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1712 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1713 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1714=== CONT TestPush_RejectsBadRequests/no_roots17152026/10/06 10:45:01 INFO Received push request method=POST path=/api/pushes1716=== CONT TestPush_RejectsBadRequests/bad_root17172026/10/06 10:45:01 INFO Received push request method=POST path=/api/pushes1718=== CONT TestPush_RejectsBadRequests/root_not_in_objects17192026/10/06 10:45:01 INFO Received push request method=POST path=/api/pushes1720=== CONT TestPush_RejectsBadRequests/no_objects17212026/10/06 10:45:01 INFO Received push request method=POST path=/api/pushes1722=== CONT TestServerTLSConfig/no_client_CA1723=== CONT TestServerTLSConfig/not_a_PEM_file1724--- PASS: TestPush_RejectsBadRequests (3.24s)1725 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1726 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1727 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1728 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1729=== CONT TestServerTLSConfig/missing_CA_file1730--- PASS: TestUploadHandlersRejectOversizedBody (0.03s)1731 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1732 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1733 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.28s)1734=== CONT TestGCEndsOnShutdown/before_the_run17352026/10/06 10:45:01 INFO Received complete push request method=POST path=/api/pushes/1/complete17362026/10/06 10:45:01 WARN Failed to register uploaded object key=55d1kwwzbrxvb3szmvgbx4hggn68929n.narinfo error="server returned 404: 404 page not found\n"1737--- PASS: TestServerTLSConfig (0.00s)1738 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1739 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1740 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.03s)1741=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark17422026/10/06 10:45:01 INFO Upload complete. (147ms)1743=== NAME TestClientWithDependencies1744 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-21795-464819160/TestClientWithDependencies3419477846/001/store) requires matching store prefix1745--- PASS: TestClientWithDependencies (2.72s)1746=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete17472026/10/06 10:45:01 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=017482026/10/06 10:45:01 INFO Received create pin request method=POST path=/api/pins/myapp17492026/10/06 10:45:01 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-21795-464819160/TestPinProtectsFromGC3378949074/001/store/k3s292j9xmpxp33c8alq1v28rijsn9q6-pinned-file.txt narinfo_key=k3s292j9xmpxp33c8alq1v28rijsn9q6.narinfo17502026/10/06 10:45:01 INFO Starting cleanup of old closures method=DELETE path=/api/closures17512026/10/06 10:45:01 INFO Garbage collection started17522026/10/06 10:45:01 INFO Aborted multipart uploads count=0 kept=017532026/10/06 10:45:01 WARN Force mode enabled - objects will be deleted immediately without grace period17542026/10/06 10:45:01 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=017552026/10/06 10:45:01 INFO Vacuumed table table=pending_closures17562026/10/06 10:45:01 INFO Vacuumed table table=pending_objects17572026/10/06 10:45:01 INFO Vacuumed table table=multipart_uploads17582026/10/06 10:45:01 INFO Vacuumed table table=closures17592026/10/06 10:45:01 INFO Vacuumed table table=objects17602026/10/06 10:45:01 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17612026/10/06 10:45:01 WARN mTLS auth: bound subjects configured but subject DN unavailable17622026/10/06 10:45:01 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1763--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.18s)1764=== CONT TestProxyWriteTimeout/narinfo1765=== CONT TestProxyWriteTimeout/10_GiB_nar1766=== CONT TestProxyWriteTimeout/unknown_size1767=== CONT TestProxyWriteTimeout/1_GiB_nar1768--- PASS: TestProxyWriteTimeout (0.00s)1769 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1770 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1771 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1772 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1773=== CONT TestResolveDBConnectionString/flag_wins1774=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1775=== CONT TestResolveDBConnectionString/nothing_configured1776=== CONT TestResolveDBConnectionString/missing_file_is_an_error1777=== CONT TestResolveDBConnectionString/file_when_flag_empty1778=== CONT TestIsValidCachePath/narinfo1779=== CONT TestIsValidCachePath/index.html1780=== CONT TestIsValidCachePath/nix-cache-info1781=== CONT TestIsValidCachePath/realisation1782=== CONT TestIsValidCachePath/log1783=== CONT TestIsValidCachePath/ls1784=== CONT TestIsValidCachePath/nar_uncompressed1785=== CONT TestIsValidCachePath/nar_bz21786=== CONT TestIsValidCachePath/nar_xz1787=== CONT TestIsValidCachePath/nar_zst1788=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1789=== CONT TestIsValidCachePath/empty1790=== CONT TestIsValidCachePath/traversal_parent1791=== CONT TestIsValidCachePath/random_path1792=== CONT TestIsValidCachePath/invalid_char_u1793=== CONT TestIsValidCachePath/invalid_char_e1794=== CONT TestIsValidCachePath/traversal_in_middle1795=== CONT TestIsValidCachePath/short_hash1796=== CONT TestIsValidCachePath/leading_slash1797=== CONT TestIsValidCachePath/wrong_extension1798--- PASS: TestIsValidCachePath (0.00s)1799 --- PASS: TestIsValidCachePath/narinfo (0.00s)1800 --- PASS: TestIsValidCachePath/index.html (0.00s)1801 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1802 --- PASS: TestIsValidCachePath/realisation (0.00s)1803 --- PASS: TestIsValidCachePath/log (0.00s)1804 --- PASS: TestIsValidCachePath/ls (0.00s)1805 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1806 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1807 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1808 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1809 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1810 --- PASS: TestIsValidCachePath/empty (0.00s)1811 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1812 --- PASS: TestIsValidCachePath/random_path (0.00s)1813 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1814 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1815 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1816 --- PASS: TestIsValidCachePath/short_hash (0.00s)1817 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1818 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1819=== CONT TestParseSingleRange/none1820=== CONT TestParseSingleRange/open-ended1821=== CONT TestParseSingleRange/start_far_past_EOF1822=== CONT TestParseSingleRange/start_past_EOF1823=== CONT TestParseSingleRange/single_byte1824=== CONT TestParseSingleRange/suffix_exceeds_size1825=== CONT TestParseSingleRange/suffix1826=== CONT TestParseSingleRange/end_clamped_to_size1827=== CONT TestParseSingleRange/malformed_both_empty1828=== CONT TestParseSingleRange/closed1829=== CONT TestParseSingleRange/malformed_end_before_start1830=== CONT TestParseSingleRange/multi-range_ignored1831=== CONT TestParseSingleRange/malformed_no_dash1832=== CONT TestParseSingleRange/unknown_unit1833--- PASS: TestParseSingleRange (0.00s)1834 --- PASS: TestParseSingleRange/none (0.00s)1835 --- PASS: TestParseSingleRange/open-ended (0.00s)1836 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1837 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1838 --- PASS: TestParseSingleRange/single_byte (0.00s)1839 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1840 --- PASS: TestParseSingleRange/suffix (0.00s)1841 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1842 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1843 --- PASS: TestParseSingleRange/closed (0.00s)1844 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1845 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1846 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1847 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1848=== CONT TestCacheConfigHandler/full_config,_no_issuer1849=== CONT TestCacheConfigHandler/no_signing_keys1850=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1851=== CONT TestCacheConfigHandler/no_cache_url_configured1852--- PASS: TestCacheConfigHandler (0.00s)1853 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1854 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1855 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1856 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1857=== CONT TestService_RequireScope_OIDC/builder_may_write1858=== CONT TestService_RequireScope_OIDC/reader_may_read1859=== CONT TestService_RequireScope_OIDC/writer_implies_read1860=== CONT TestService_RequireScope_OIDC/static_token_may_write1861=== CONT TestService_RequireScope_OIDC/static_token_may_admin1862=== CONT TestService_RequireScope_OIDC/reader_may_not_write1863=== CONT TestService_RequireScope_OIDC/ops_may_not_write1864=== CONT TestService_RequireScope_OIDC/ops_may_admin1865=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1866=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1867=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1868=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18692026/10/06 10:45:01 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]1870=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1871=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1872=== CONT TestClientErrorHandling/InvalidStorePath1873--- PASS: TestResolveDBConnectionString (0.02s)1874 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1875 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1876 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1877 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1878 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1879--- PASS: TestService_RequireScope_OIDC (1.20s)1880 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1881 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1882 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1883 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1884 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1885 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1886 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1887 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1888 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1889 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1890 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1891 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1892 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1893 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1894=== NAME TestClientMultipleUploads1895 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-21795-464819160/TestClientMultipleUploads2686995365/001/store/i15hrdf55q6j8mv5wla3ayvr4kp838dv-test-file-0.txt18962026/10/06 10:45:02 INFO Received uploads request method=POST path=/api/pending_closures1897 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-21795-464819160/TestClientMultipleUploads2686995365/001/store/ps5wjhwy9qsrpvhngwv7vmvs9zmrxamc-test-file-1.txt1898 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-21795-464819160/TestClientMultipleUploads2686995365/001/store/qac4nb1x14ns8ahc7bvlb4g86597jz6c-test-file-2.txt18992026/10/06 10:45:02 INFO Received push request method=POST path=/api/pushes19002026/10/06 10:45:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1901--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (2.20s)1902=== CONT TestClientErrorHandling/ServerNotAvailable19032026/10/06 10:45:02 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)19042026/10/06 10:45:02 INFO Uploading ps5wjhwy9qsrpvhngwv7vmvs9zmrxamc-test-file-1.txt (160B)19052026/10/06 10:45:02 INFO Uploading qac4nb1x14ns8ahc7bvlb4g86597jz6c-test-file-2.txt (160B)19062026/10/06 10:45:02 INFO Uploading i15hrdf55q6j8mv5wla3ayvr4kp838dv-test-file-0.txt (160B)19072026/10/06 10:45:02 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01908=== NAME TestClientIntegration1909 client_integration_test.go:323: Objects in database after GC:1910 client_integration_test.go:323: Successfully deleted all objects with GC --force19112026/10/06 10:45:02 WARN Failed to register uploaded object key=ps5wjhwy9qsrpvhngwv7vmvs9zmrxamc.ls error="server returned 404: 404 page not found\n"19122026/10/06 10:45:02 WARN Failed to register uploaded object key=i15hrdf55q6j8mv5wla3ayvr4kp838dv.ls error="server returned 404: 404 page not found\n"19132026/10/06 10:45:02 WARN Failed to register uploaded object key=qac4nb1x14ns8ahc7bvlb4g86597jz6c.ls error="server returned 404: 404 page not found\n"19142026/10/06 10:45:02 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"19152026/10/06 10:45:02 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"19162026/10/06 10:45:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19172026/10/06 10:45:02 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"19182026/10/06 10:45:02 INFO Signed narinfos id=1 count=319192026/10/06 10:45:02 INFO Uploading 3 narinfos19202026/10/06 10:45:02 WARN Failed to register uploaded object key=qac4nb1x14ns8ahc7bvlb4g86597jz6c.narinfo error="server returned 404: 404 page not found\n"19212026/10/06 10:45:02 INFO Received complete push request method=POST path=/api/pushes/1/complete19222026/10/06 10:45:02 WARN Failed to register uploaded object key=i15hrdf55q6j8mv5wla3ayvr4kp838dv.narinfo error="server returned 404: 404 page not found\n"19232026/10/06 10:45:02 WARN Failed to register uploaded object key=ps5wjhwy9qsrpvhngwv7vmvs9zmrxamc.narinfo error="server returned 404: 404 page not found\n"19242026/10/06 10:45:02 INFO Upload complete. (156ms)1925=== NAME TestClientMultipleUploads1926 client_integration_test.go:369: Uploaded 3 paths in 187.137291ms1927--- PASS: TestClientIntegration (4.54s)1928=== CONT TestClientErrorHandling/InvalidAuthToken1929--- PASS: TestClientMultipleUploads (3.03s)1930=== CONT TestPendingClosureWriteTimeout/empty1931=== CONT TestPendingClosureWriteTimeout/670k_objects1932=== CONT TestPendingClosureWriteTimeout/400_objects1933=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline19342026/10/06 10:45:02 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/present1935--- PASS: TestCacheStatsHandler (2.28s)1936=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token19372026/10/06 10:45:02 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=200.518964ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1938=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19392026/10/06 10:45:02 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1940=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1941=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19422026/10/06 10:45:02 WARN Authentication failed token_preview=eyJhbGciOi...kNx3JVYgbg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1943--- PASS: TestService_AuthMiddleware_OIDC (2.00s)1944 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1945 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1946 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1947 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)19482026/10/06 10:45:02 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=388.321665ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19492026/10/06 10:45:03 INFO Aborted multipart uploads count=0 kept=019502026/10/06 10:45:03 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=798.132128ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19512026/10/06 10:45:03 WARN Force mode enabled - objects will be deleted immediately without grace period19522026-10-06 10:45:03.233 UTC [22293] ERROR: canceling statement due to user request19532026-10-06 10:45:03.233 UTC [22293] STATEMENT: -- name: MarkStaleObjects :execrows1954 WITH RECURSIVE ct AS (1955 SELECT timezone('UTC', now()) AS now1956 ),1957 closure_reach AS (1958 -- Start with all closure keys1959 SELECT o.key, o.refs1960 FROM objects o1961 INNER JOIN closures c ON o.key = c.key1962 UNION1963 -- Recursively add all referenced objects1964 SELECT o.key, o.refs1965 FROM objects o1966 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1967 ),1968 reachable_objects AS (1969 SELECT DISTINCT key FROM closure_reach1970 ),1971 stale_objects AS (1972 SELECT o.key1973 FROM objects AS o, ct1974 WHERE1975 NOT EXISTS (1976 SELECT 11977 FROM reachable_objects ro1978 WHERE ro.key = o.key1979 )1980 AND NOT EXISTS (1981 SELECT 11982 FROM pending_objects AS po1983 WHERE po.key = o.key1984 )1985 AND o.deleted_at IS NULL -- Only mark fresh objects1986 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure1987 FOR UPDATE1988 )1989 UPDATE objects1990 SET1991 deleted_at = ct.now,1992 first_deleted_at = COALESCE(first_deleted_at, ct.now)1993 FROM stale_objects, ct1994 WHERE objects.key = stale_objects.key1995 1996=== NAME TestPinProtectsFromGC1997 client_integration_test.go:840: Pin successfully protected closure from garbage collection1998--- PASS: TestPinProtectsFromGC (6.12s)19992026/10/06 10:45:03 INFO Aborted multipart uploads count=0 kept=020002026/10/06 10:45:03 WARN Force mode enabled - objects will be deleted immediately without grace period20012026/10/06 10:45:03 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:52718/bucket89/?delete=\": context canceled"2002--- PASS: TestGCEndsOnShutdown (0.00s)2003 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (2.02s)2004 --- PASS: TestGCEndsOnShutdown/before_the_run (2.29s)2005 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (2.48s)20062026/10/06 10:45:04 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.503981879s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20072026/10/06 10:45:04 INFO Received uploads request method=POST path=/api/pending_closures20082026/10/06 10:45:04 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20092026/10/06 10:45:04 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2010--- PASS: TestPendingClosureWriteTimeout (0.00s)2011 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2012 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2013 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2014 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (2.86s)20152026/10/06 10:45:05 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-config20162026/10/06 10:45:05 WARN Rate limiter enabled after throttle name=s3-test rate=520172026/10/06 10:45:05 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2018=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2019 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102020 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002021--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.89s)20222026/10/06 10:45:05 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=203.281611ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20232026/10/06 10:45:05 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=436.139396ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20242026/10/06 10:45:06 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=811.655448ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20252026/10/06 10:45:07 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.6280393s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20262026/10/06 10:45:08 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"20272026/10/06 10:45:08 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20282026/10/06 10:45:08 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=185.535319ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20292026/10/06 10:45:09 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=385.328679ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20302026/10/06 10:45:09 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=774.895861ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20312026/10/06 10:45:10 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.682892646s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20322026/10/06 10:45:11 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20332026/10/06 10:45:12 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=217.228956ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20342026/10/06 10:45:12 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=379.084275ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20352026/10/06 10:45:12 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=774.117325ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20362026/10/06 10:45:13 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.570804262s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2037--- PASS: TestClientErrorHandling (0.00s)2038 --- PASS: TestClientErrorHandling/InvalidStorePath (2.60s)2039 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.20s)2040 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.69s)2041PASS20422026-10-06 10:45:15.156 UTC [21832] LOG: received smart shutdown request20432026-10-06 10:45:15.157 UTC [21832] LOG: background worker "logical replication launcher" (PID 21842) exited with exit code 120442026-10-06 10:45:15.160 UTC [21837] LOG: shutting down20452026-10-06 10:45:15.160 UTC [21837] LOG: checkpoint starting: shutdown immediate20462026-10-06 10:45:16.377 UTC [21837] LOG: checkpoint complete: wrote 12582 buffers (76.8%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 27 recycled; write=0.649 s, sync=0.556 s, total=1.217 s; sync files=31336, longest=0.026 s, average=0.001 s; distance=440332 kB, estimate=440332 kB; lsn=0/1C590280, redo lsn=0/1C59028020472026-10-06 10:45:16.383 UTC [21832] LOG: database system is shut down2048Running OIDC tests...2049=== RUN TestAudienceForIssuer2050=== PAUSE TestAudienceForIssuer2051=== RUN TestGlobMatch2052=== PAUSE TestGlobMatch2053=== RUN TestValidateToken_ValidToken2054=== PAUSE TestValidateToken_ValidToken2055=== RUN TestValidateToken_WrongAudience2056=== PAUSE TestValidateToken_WrongAudience2057=== RUN TestValidateToken_Expired2058=== PAUSE TestValidateToken_Expired2059=== RUN TestValidateToken_BoundClaimsMismatch2060=== PAUSE TestValidateToken_BoundClaimsMismatch2061=== RUN TestValidateToken_BoundSubjectMismatch2062=== PAUSE TestValidateToken_BoundSubjectMismatch2063=== RUN TestValidateToken_MultipleProviders2064=== PAUSE TestValidateToken_MultipleProviders2065=== RUN TestValidateToken_NoMatchingProvider2066=== PAUSE TestValidateToken_NoMatchingProvider2067=== RUN TestValidateToken_KubernetesServiceAccount2068=== PAUSE TestValidateToken_KubernetesServiceAccount2069=== RUN TestNewValidator_KubernetesRequiresCA2070=== PAUSE TestNewValidator_KubernetesRequiresCA2071=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2072=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2073=== RUN TestPins_ReservedForMatchingRule2074=== PAUSE TestPins_ReservedForMatchingRule2075=== RUN TestPins_TopLevelShorthand2076=== PAUSE TestPins_TopLevelShorthand2077=== RUN TestPins_ConfigValidation2078=== PAUSE TestPins_ConfigValidation2079=== RUN TestScopes_LegacyProviderDefaultsToWrite2080=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2081=== RUN TestScopes_Rules2082=== PAUSE TestScopes_Rules2083=== RUN TestScopes_ConfigValidation2084=== PAUSE TestScopes_ConfigValidation2085=== CONT TestAudienceForIssuer2086--- PASS: TestAudienceForIssuer (0.00s)2087=== CONT TestValidateToken_NoMatchingProvider2088=== CONT TestValidateToken_KubernetesServiceAccount2089=== CONT TestPins_ConfigValidation2090=== CONT TestScopes_Rules2091=== CONT TestValidateToken_Expired2092=== CONT TestScopes_LegacyProviderDefaultsToWrite2093=== CONT TestValidateToken_BoundSubjectMismatch2094=== CONT TestValidateToken_BoundClaimsMismatch2095=== CONT TestValidateToken_ValidToken2096=== CONT TestScopes_ConfigValidation2097--- PASS: TestPins_ConfigValidation (0.01s)2098=== CONT TestGlobMatch2099=== RUN TestGlobMatch/foo_foo2100=== PAUSE TestGlobMatch/foo_foo2101=== RUN TestGlobMatch/foo_bar2102=== PAUSE TestGlobMatch/foo_bar2103=== RUN TestGlobMatch/*_2104=== PAUSE TestGlobMatch/*_2105=== RUN TestGlobMatch/*_anything2106=== PAUSE TestGlobMatch/*_anything2107=== RUN TestGlobMatch/foo*_foo2108=== PAUSE TestGlobMatch/foo*_foo2109=== RUN TestGlobMatch/foo*_foobar2110=== PAUSE TestGlobMatch/foo*_foobar2111=== RUN TestGlobMatch/foo*_bar2112=== PAUSE TestGlobMatch/foo*_bar2113=== RUN TestGlobMatch/*bar_bar2114=== PAUSE TestGlobMatch/*bar_bar2115=== RUN TestGlobMatch/*bar_foobar2116=== PAUSE TestGlobMatch/*bar_foobar2117=== RUN TestGlobMatch/*bar_foo2118=== PAUSE TestGlobMatch/*bar_foo2119=== RUN TestGlobMatch/foo*bar_foobar2120=== PAUSE TestGlobMatch/foo*bar_foobar2121=== RUN TestGlobMatch/foo*bar_foo123bar2122=== PAUSE TestGlobMatch/foo*bar_foo123bar2123=== RUN TestGlobMatch/foo*bar_foobarbaz2124=== PAUSE TestGlobMatch/foo*bar_foobarbaz2125=== RUN TestGlobMatch/*/*_foo/bar2126=== PAUSE TestGlobMatch/*/*_foo/bar2127=== RUN TestGlobMatch/*/*_foo2128=== PAUSE TestGlobMatch/*/*_foo2129=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2130=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2131=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02132=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02133=== RUN TestGlobMatch/refs/*/main_refs/heads/main2134=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2135=== RUN TestGlobMatch/fo?_foo2136=== PAUSE TestGlobMatch/fo?_foo2137=== RUN TestGlobMatch/fo?_fo2138=== PAUSE TestGlobMatch/fo?_fo2139=== RUN TestGlobMatch/fo?_fooo2140=== PAUSE TestGlobMatch/fo?_fooo2141=== RUN TestGlobMatch/?oo_foo2142=== PAUSE TestGlobMatch/?oo_foo2143=== RUN TestGlobMatch/?oo_boo2144=== PAUSE TestGlobMatch/?oo_boo2145=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2146=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2147=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2148=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2149=== CONT TestPins_TopLevelShorthand2150--- PASS: TestScopes_ConfigValidation (0.01s)2151=== CONT TestPins_ReservedForMatchingRule21522026/10/06 10:45:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53179/oidc2153--- PASS: TestValidateToken_BoundClaimsMismatch (0.04s)2154=== CONT TestValidateToken_KubernetesIssuerFromOwnToken21552026/10/06 10:45:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53182/oidc2156--- PASS: TestPins_TopLevelShorthand (0.05s)2157=== CONT TestNewValidator_KubernetesRequiresCA21582026/10/06 10:45:17 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:5318121592026/10/06 10:45:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53185/oidc2160--- PASS: TestValidateToken_KubernetesServiceAccount (0.07s)2161=== CONT TestGlobMatch/foo_foo2162=== CONT TestValidateToken_WrongAudience2163--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.07s)2164=== CONT TestValidateToken_MultipleProviders21652026/10/06 10:45:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53188/oidc2166--- PASS: TestValidateToken_Expired (0.08s)2167=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2168=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2169=== CONT TestGlobMatch/?oo_boo2170=== CONT TestGlobMatch/?oo_foo2171=== CONT TestGlobMatch/fo?_fooo2172=== CONT TestGlobMatch/fo?_fo2173=== CONT TestGlobMatch/fo?_foo2174=== CONT TestGlobMatch/refs/*/main_refs/heads/main2175=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02176=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2177=== CONT TestGlobMatch/*/*_foo2178=== CONT TestGlobMatch/*/*_foo/bar2179=== CONT TestGlobMatch/foo*bar_foobarbaz2180=== CONT TestGlobMatch/foo*bar_foo123bar2181=== CONT TestGlobMatch/foo*bar_foobar2182=== CONT TestGlobMatch/*bar_foo2183=== CONT TestGlobMatch/*bar_foobar2184=== CONT TestGlobMatch/*bar_bar2185=== CONT TestGlobMatch/foo*_bar2186=== CONT TestGlobMatch/foo*_foobar2187=== CONT TestGlobMatch/foo*_foo2188=== CONT TestGlobMatch/*_anything2189=== CONT TestGlobMatch/*_2190=== CONT TestGlobMatch/foo_bar2191--- PASS: TestGlobMatch (0.00s)2192 --- PASS: TestGlobMatch/foo_foo (0.00s)2193 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2194 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2195 --- PASS: TestGlobMatch/?oo_boo (0.00s)2196 --- PASS: TestGlobMatch/?oo_foo (0.00s)2197 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2198 --- PASS: TestGlobMatch/fo?_fo (0.00s)2199 --- PASS: TestGlobMatch/fo?_foo (0.00s)2200 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2201 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2202 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2203 --- PASS: TestGlobMatch/*/*_foo (0.00s)2204 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2205 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2206 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2207 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2208 --- PASS: TestGlobMatch/*bar_foo (0.00s)2209 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2210 --- PASS: TestGlobMatch/*bar_bar (0.00s)2211 --- PASS: TestGlobMatch/foo*_bar (0.00s)2212 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2213 --- PASS: TestGlobMatch/foo*_foo (0.00s)2214 --- PASS: TestGlobMatch/*_anything (0.00s)2215 --- PASS: TestGlobMatch/*_ (0.00s)2216 --- PASS: TestGlobMatch/foo_bar (0.00s)22172026/10/06 10:45:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53192/oidc2218--- PASS: TestValidateToken_ValidToken (0.09s)22192026/10/06 10:45:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53194/oidc22202026/10/06 10:45:17 http: TLS handshake error from 127.0.0.1:53191: remote error: tls: bad certificate2221--- PASS: TestNewValidator_KubernetesRequiresCA (0.03s)22222026/10/06 10:45:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53196/oidc2223--- PASS: TestPins_ReservedForMatchingRule (0.09s)2224--- PASS: TestScopes_Rules (0.10s)22252026/10/06 10:45:17 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232226--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.07s)22272026/10/06 10:45:17 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:53178/oidc2228--- PASS: TestValidateToken_NoMatchingProvider (0.13s)22292026/10/06 10:45:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53202/oidc2230--- PASS: TestValidateToken_WrongAudience (0.07s)22312026/10/06 10:45:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53205/oidc2232--- PASS: TestValidateToken_BoundSubjectMismatch (0.19s)22332026/10/06 10:45:17 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:53204/oidc22342026/10/06 10:45:17 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:53207/oidc2235--- PASS: TestValidateToken_MultipleProviders (0.13s)2236PASS2237Running hook tests...2238=== RUN TestSendPathsEmpty2239=== PAUSE TestSendPathsEmpty2240=== RUN TestQueueEnqueueAndFetch2241=== PAUSE TestQueueEnqueueAndFetch2242=== RUN TestQueueDeduplication2243=== PAUSE TestQueueDeduplication2244=== RUN TestQueueRemove2245=== PAUSE TestQueueRemove2246=== RUN TestQueueFetchBatchLimit2247=== PAUSE TestQueueFetchBatchLimit2248=== RUN TestQueueRetryMovesToBack2249=== PAUSE TestQueueRetryMovesToBack2250=== RUN TestQueueFetchRemoveLifecycle2251=== PAUSE TestQueueFetchRemoveLifecycle2252=== RUN TestQueueConcurrentWriters2253=== PAUSE TestQueueConcurrentWriters2254=== RUN TestQueueRemoveLargeClosure2255=== PAUSE TestQueueRemoveLargeClosure2256=== RUN TestServerClientIntegration2257=== PAUSE TestServerClientIntegration2258=== RUN TestServerQueueError2259=== PAUSE TestServerQueueError2260=== RUN TestGetListenerSocketActivation2261 server_test.go:210: === RUN TestGetListenerSocketActivation2262 --- PASS: TestGetListenerSocketActivation (0.00s)2263 PASS2264 2265--- PASS: TestGetListenerSocketActivation (0.01s)2266=== RUN TestDrainIsolatesPoisonPath2267=== PAUSE TestDrainIsolatesPoisonPath2268=== RUN TestRunNotBlockedByPoisonHead2269=== PAUSE TestRunNotBlockedByPoisonHead2270=== RUN TestDrainGivesUpWhenServerDown2271=== PAUSE TestDrainGivesUpWhenServerDown2272=== RUN TestFailedPathPrunedByLaterClosure2273=== PAUSE TestFailedPathPrunedByLaterClosure2274=== RUN TestWorkerUploadsAndRemoves2275=== PAUSE TestWorkerUploadsAndRemoves2276=== RUN TestWorkerSkipsGCdPaths2277=== PAUSE TestWorkerSkipsGCdPaths2278=== RUN TestWorkerPrunesClosureDeps2279=== PAUSE TestWorkerPrunesClosureDeps2280=== RUN TestDrainTimeout2281=== PAUSE TestDrainTimeout2282=== CONT TestSendPathsEmpty2283--- PASS: TestSendPathsEmpty (0.00s)2284=== CONT TestServerClientIntegration2285=== CONT TestServerQueueError2286=== CONT TestWorkerUploadsAndRemoves2287=== CONT TestWorkerPrunesClosureDeps2288=== CONT TestWorkerSkipsGCdPaths2289=== CONT TestQueueRetryMovesToBack2290=== CONT TestQueueRemoveLargeClosure2291=== CONT TestQueueConcurrentWriters2292=== CONT TestQueueFetchRemoveLifecycle2293=== CONT TestFailedPathPrunedByLaterClosure22942026/10/06 10:45:18 ERROR Failed to queue paths error="permission denied" count=12295--- PASS: TestServerClientIntegration (0.00s)2296=== CONT TestRunNotBlockedByPoisonHead2297--- PASS: TestServerQueueError (0.00s)2298=== CONT TestDrainIsolatesPoisonPath22992026/10/06 10:45:18 INFO Upload queue status pending=323002026/10/06 10:45:18 INFO Uploading batch count=123012026/10/06 10:45:18 ERROR Upload failed error="upload failed" count=123022026/10/06 10:45:18 INFO Uploading batch count=123032026/10/06 10:45:18 ERROR Upload failed error="upload failed" count=123042026/10/06 10:45:18 INFO Upload queue status pending=223052026/10/06 10:45:18 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-21795-464819160/TestWorkerSkipsGCdPaths3496439783/002/nonexistent23062026/10/06 10:45:18 INFO Uploading batch count=123072026/10/06 10:45:18 INFO Uploading batch count=123082026/10/06 10:45:18 INFO Uploading batch count=423092026/10/06 10:45:18 ERROR Upload failed error="upload failed" count=423102026/10/06 10:45:18 INFO Uploading batch count=123112026/10/06 10:45:18 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-21795-464819160/TestDrainIsolatesPoisonPath2958055298/002/bbb23122026/10/06 10:45:18 INFO Upload queue status pending=223132026/10/06 10:45:18 INFO Upload queue status pending=223142026/10/06 10:45:18 INFO Uploading batch count=223152026/10/06 10:45:18 INFO Uploading batch count=12316--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2317=== CONT TestDrainTimeout2318--- PASS: TestQueueRetryMovesToBack (0.01s)2319=== CONT TestQueueRemove23202026/10/06 10:45:18 INFO Uploading batch count=123212026/10/06 10:45:18 ERROR Upload failed error="upload failed" count=123222026/10/06 10:45:18 INFO Uploading batch count=123232026/10/06 10:45:18 ERROR Upload failed error="upload failed" count=123242026/10/06 10:45:18 INFO Uploading batch count=123252026/10/06 10:45:18 ERROR Upload failed error="upload failed" count=123262026/10/06 10:45:18 ERROR Drain finished with paths left in queue remaining=12327--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)2328=== CONT TestQueueFetchBatchLimit2329--- PASS: TestDrainIsolatesPoisonPath (0.01s)2330=== CONT TestQueueDeduplication23312026/10/06 10:45:18 INFO Uploading batch count=22332--- PASS: TestQueueRemove (0.00s)2333=== CONT TestQueueEnqueueAndFetch2334--- PASS: TestQueueFetchBatchLimit (0.00s)2335=== CONT TestDrainGivesUpWhenServerDown2336--- PASS: TestQueueDeduplication (0.00s)2337--- PASS: TestQueueEnqueueAndFetch (0.00s)23382026/10/06 10:45:18 INFO Uploading batch count=223392026/10/06 10:45:18 ERROR Upload failed error="upload failed" count=223402026/10/06 10:45:18 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-21795-464819160/TestDrainGivesUpWhenServerDown4111445155/002/a23412026/10/06 10:45:18 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-21795-464819160/TestDrainGivesUpWhenServerDown4111445155/002/b23422026/10/06 10:45:18 INFO Uploading batch count=223432026/10/06 10:45:18 ERROR Upload failed error="upload failed" count=223442026/10/06 10:45:18 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-21795-464819160/TestDrainGivesUpWhenServerDown4111445155/002/c23452026/10/06 10:45:18 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-21795-464819160/TestDrainGivesUpWhenServerDown4111445155/002/d23462026/10/06 10:45:18 INFO Uploading batch count=223472026/10/06 10:45:18 ERROR Upload failed error="upload failed" count=223482026/10/06 10:45:18 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-21795-464819160/TestDrainGivesUpWhenServerDown4111445155/002/e23492026/10/06 10:45:18 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-21795-464819160/TestDrainGivesUpWhenServerDown4111445155/002/f23502026/10/06 10:45:18 ERROR Drain finished with paths left in queue remaining=102351--- PASS: TestDrainGivesUpWhenServerDown (0.00s)2352--- PASS: TestWorkerSkipsGCdPaths (0.03s)2353--- PASS: TestWorkerUploadsAndRemoves (0.03s)2354--- PASS: TestWorkerPrunesClosureDeps (0.03s)2355--- PASS: TestQueueRemoveLargeClosure (0.04s)2356--- PASS: TestQueueConcurrentWriters (0.13s)23572026/10/06 10:45:18 ERROR Upload failed error="context deadline exceeded" count=223582026/10/06 10:45:18 ERROR Drain finished with paths left in queue remaining=42359--- PASS: TestDrainTimeout (0.21s)23602026/10/06 10:45:19 INFO Uploading batch count=123612026/10/06 10:45:19 INFO Uploading batch count=123622026/10/06 10:45:19 INFO Uploading batch count=123632026/10/06 10:45:19 ERROR Upload failed error="upload failed" count=123642026/10/06 10:45:19 INFO Uploading batch count=123652026/10/06 10:45:19 ERROR Upload failed error="upload failed" count=123662026/10/06 10:45:19 INFO Uploading batch count=123672026/10/06 10:45:19 ERROR Upload failed error="upload failed" count=123682026/10/06 10:45:19 INFO Uploading batch count=123692026/10/06 10:45:19 ERROR Upload failed error="upload failed" count=123702026/10/06 10:45:19 ERROR Drain finished with paths left in queue remaining=12371--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2372PASS2373Running signing tests...2374=== RUN TestExternalSigner2375=== PAUSE TestExternalSigner2376=== RUN TestExternalSignerWrongPublicKey2377=== PAUSE TestExternalSignerWrongPublicKey2378=== RUN TestExternalSignerErrors2379=== PAUSE TestExternalSignerErrors2380=== RUN TestExternalSignerRestartsAfterCrash2381=== PAUSE TestExternalSignerRestartsAfterCrash2382=== RUN TestExternalSignerProgramErrorKeepsProcess2383=== PAUSE TestExternalSignerProgramErrorKeepsProcess2384=== RUN TestExternalSignerClose2385=== PAUSE TestExternalSignerClose2386=== RUN TestExternalSignerRejectsInvalidPublicKey2387=== PAUSE TestExternalSignerRejectsInvalidPublicKey2388=== RUN TestExternalSignerCancellation2389=== PAUSE TestExternalSignerCancellation2390=== RUN TestGenerateFingerprint2391=== PAUSE TestGenerateFingerprint2392=== RUN TestParseSigningKey2393=== PAUSE TestParseSigningKey2394=== RUN TestSign2395=== PAUSE TestSign2396=== RUN TestSignBatch2397=== PAUSE TestSignBatch2398=== RUN TestNilKeyPublicKey2399=== PAUSE TestNilKeyPublicKey2400=== RUN TestSignErrors2401=== PAUSE TestSignErrors2402=== CONT TestExternalSigner2403=== CONT TestExternalSignerProgramErrorKeepsProcess2404=== CONT TestParseSigningKey2405=== RUN TestParseSigningKey/valid_32-byte_key2406=== PAUSE TestParseSigningKey/valid_32-byte_key2407=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2408=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2409=== RUN TestParseSigningKey/no_colon2410=== PAUSE TestParseSigningKey/no_colon2411=== CONT TestExternalSignerCancellation2412=== CONT TestSignBatch2413=== CONT TestSignErrors2414=== CONT TestNilKeyPublicKey2415--- PASS: TestNilKeyPublicKey (0.00s)2416=== CONT TestSign2417=== CONT TestExternalSignerErrors2418=== RUN TestExternalSignerErrors/program_error2419=== PAUSE TestExternalSignerErrors/program_error2420=== RUN TestExternalSignerErrors/exit_at_startup2421=== PAUSE TestExternalSignerErrors/exit_at_startup2422=== RUN TestParseSigningKey/empty_name2423=== PAUSE TestParseSigningKey/empty_name2424=== RUN TestParseSigningKey/invalid_base642425=== PAUSE TestParseSigningKey/invalid_base642426=== RUN TestParseSigningKey/wrong_length2427=== PAUSE TestParseSigningKey/wrong_length2428=== CONT TestExternalSignerRestartsAfterCrash2429=== CONT TestExternalSignerRejectsInvalidPublicKey2430=== RUN TestExternalSignerRejectsInvalidPublicKey/#002431=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002432=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2433=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2434=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2435=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2436=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2437=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2438=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2439=== CONT TestGenerateFingerprint2440=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2441=== RUN TestExternalSignerErrors/exit_on_request2442=== PAUSE TestExternalSignerErrors/exit_on_request2443=== RUN TestGenerateFingerprint/basic_with_references2444=== RUN TestExternalSignerErrors/invalid_JSON2445=== PAUSE TestGenerateFingerprint/basic_with_references2446=== PAUSE TestExternalSignerErrors/invalid_JSON2447=== CONT TestExternalSignerWrongPublicKey2448=== RUN TestExternalSignerErrors/wrong_shape2449=== PAUSE TestExternalSignerErrors/wrong_shape2450=== RUN TestExternalSignerErrors/null2451=== PAUSE TestExternalSignerErrors/null2452=== RUN TestExternalSignerErrors/wrong_id2453=== PAUSE TestExternalSignerErrors/wrong_id2454=== RUN TestExternalSignerErrors/too_few_signatures2455=== PAUSE TestExternalSignerErrors/too_few_signatures2456=== RUN TestExternalSignerErrors/wrong_signature_name2457=== PAUSE TestExternalSignerErrors/wrong_signature_name2458=== RUN TestExternalSignerErrors/unrequested_key2459=== RUN TestGenerateFingerprint/no_references2460=== PAUSE TestExternalSignerErrors/unrequested_key2461=== PAUSE TestGenerateFingerprint/no_references2462=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2463=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2464=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2465=== RUN TestExternalSignerErrors/invalid_signature_base642466=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2467=== RUN TestGenerateFingerprint/invalid_nar_hash_length2468=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2469=== RUN TestGenerateFingerprint/invalid_store_path_prefix2470=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2471=== PAUSE TestExternalSignerErrors/invalid_signature_base642472=== RUN TestGenerateFingerprint/invalid_reference_prefix2473=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2474=== CONT TestExternalSignerClose2475=== RUN TestExternalSignerErrors/missing_signatures2476=== PAUSE TestExternalSignerErrors/missing_signatures2477=== RUN TestExternalSignerErrors/null_signatures2478=== PAUSE TestExternalSignerErrors/null_signatures2479=== RUN TestExternalSignerErrors/missing_signature_name2480=== PAUSE TestExternalSignerErrors/missing_signature_name2481=== RUN TestExternalSignerErrors/wrong_signature_length2482=== PAUSE TestExternalSignerErrors/wrong_signature_length2483=== RUN TestExternalSignerErrors/wrong_signatures_shape2484=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2485=== CONT TestParseSigningKey/valid_32-byte_key2486=== RUN TestSignErrors/nil_key2487=== PAUSE TestSignErrors/nil_key2488=== RUN TestSignErrors/nil_narinfo2489=== PAUSE TestSignErrors/nil_narinfo2490=== RUN TestSignErrors/invalid_narinfo2491=== PAUSE TestSignErrors/invalid_narinfo2492=== RUN TestSignErrors/canceled2493--- PASS: TestSign (0.00s)2494=== CONT TestParseSigningKey/invalid_base642495=== CONT TestParseSigningKey/no_colon2496=== CONT TestParseSigningKey/empty_name2497=== CONT TestParseSigningKey/wrong_length2498=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2499=== CONT TestExternalSignerRejectsInvalidPublicKey/#002500--- PASS: TestParseSigningKey (0.00s)2501 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2502 --- PASS: TestParseSigningKey/no_colon (0.00s)2503 --- PASS: TestParseSigningKey/empty_name (0.00s)2504 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2505 --- PASS: TestParseSigningKey/wrong_length (0.00s)2506 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2507=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2508=== PAUSE TestSignErrors/canceled2509=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2510=== CONT TestGenerateFingerprint/basic_with_references2511=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2512=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2513=== CONT TestGenerateFingerprint/invalid_nar_hash_length2514=== CONT TestGenerateFingerprint/invalid_reference_prefix2515--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2516 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2517 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2518 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2519 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2520 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2521=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2522=== CONT TestGenerateFingerprint/invalid_store_path_prefix2523=== CONT TestExternalSignerErrors/program_error2524=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2525=== CONT TestExternalSignerErrors/unrequested_key2526--- PASS: TestSignBatch (0.01s)2527=== CONT TestExternalSignerErrors/too_few_signatures2528=== CONT TestExternalSignerErrors/wrong_signature_name2529--- PASS: TestExternalSigner (0.10s)2530=== CONT TestExternalSignerErrors/wrong_id2531--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.16s)2532=== CONT TestExternalSignerErrors/null2533--- PASS: TestExternalSignerCancellation (0.26s)2534=== CONT TestExternalSignerErrors/wrong_shape2535--- PASS: TestExternalSignerWrongPublicKey (0.30s)2536=== CONT TestExternalSignerErrors/invalid_JSON2537--- PASS: TestExternalSignerClose (0.37s)2538=== CONT TestExternalSignerErrors/exit_on_request2539--- PASS: TestExternalSignerRestartsAfterCrash (0.46s)2540=== CONT TestExternalSignerErrors/exit_at_startup2541/nix/var/nix/builds/nix-21795-464819160/TestExternalSignerRestartsAfterCrash3439288594/001/sign program: line 7: /nix/var/nix/builds/nix-21795-464819160/TestExternalSignerRestartsAfterCrash3439288594/001/sign program.starts: No such file or directory2542=== CONT TestGenerateFingerprint/no_references2543--- PASS: TestGenerateFingerprint (0.00s)2544 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2545 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2546 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2547 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2548 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2549 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2550 --- PASS: TestGenerateFingerprint/no_references (0.00s)2551=== CONT TestExternalSignerErrors/wrong_signatures_shape2552=== CONT TestExternalSignerErrors/wrong_signature_length2553=== CONT TestExternalSignerErrors/missing_signature_name2554=== CONT TestExternalSignerErrors/null_signatures2555=== CONT TestExternalSignerErrors/missing_signatures2556=== CONT TestExternalSignerErrors/invalid_signature_base642557=== CONT TestSignErrors/nil_key2558=== CONT TestSignErrors/nil_narinfo2559=== CONT TestSignErrors/canceled2560=== CONT TestSignErrors/invalid_narinfo2561--- PASS: TestSignErrors (0.00s)2562 --- PASS: TestSignErrors/nil_key (0.00s)2563 --- PASS: TestSignErrors/nil_narinfo (0.00s)2564 --- PASS: TestSignErrors/canceled (0.00s)2565 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2566--- PASS: TestExternalSignerErrors (0.00s)2567 --- PASS: TestExternalSignerErrors/unrequested_key (0.51s)2568 --- PASS: TestExternalSignerErrors/program_error (0.58s)2569 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.65s)2570 --- PASS: TestExternalSignerErrors/too_few_signatures (0.72s)2571 --- PASS: TestExternalSignerErrors/wrong_id (0.70s)2572 --- PASS: TestExternalSignerErrors/null (0.71s)2573 --- PASS: TestExternalSignerErrors/wrong_shape (0.69s)2574 --- PASS: TestExternalSignerErrors/invalid_JSON (0.71s)2575 --- PASS: TestExternalSignerErrors/exit_on_request (0.71s)2576 --- PASS: TestExternalSignerErrors/exit_at_startup (0.69s)2577 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.71s)2578 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.71s)2579 --- PASS: TestExternalSignerErrors/missing_signature_name (0.71s)2580 --- PASS: TestExternalSignerErrors/null_signatures (0.71s)2581 --- PASS: TestExternalSignerErrors/missing_signatures (0.71s)2582 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.71s)2583PASS2584Running OpenBao signer tests...2585=== RUN TestSign2586=== PAUSE TestSign2587=== RUN TestSignErrors2588=== PAUSE TestSignErrors2589=== RUN TestServe2590=== PAUSE TestServe2591=== RUN TestServeRejectsGarbage2592=== PAUSE TestServeRejectsGarbage2593=== CONT TestSign2594=== CONT TestServeRejectsGarbage2595=== CONT TestServe2596--- PASS: TestServeRejectsGarbage (0.00s)2597=== CONT TestSignErrors2598=== RUN TestSignErrors/http_error2599=== PAUSE TestSignErrors/http_error2600=== RUN TestSignErrors/invalid_json2601=== PAUSE TestSignErrors/invalid_json2602=== RUN TestSignErrors/no_prefix2603=== PAUSE TestSignErrors/no_prefix2604=== RUN TestSignErrors/invalid_base642605=== PAUSE TestSignErrors/invalid_base642606=== CONT TestSignErrors/http_error2607=== CONT TestSignErrors/no_prefix2608=== CONT TestSignErrors/invalid_json2609=== CONT TestSignErrors/invalid_base642610--- PASS: TestServe (0.00s)2611--- PASS: TestSignErrors (0.00s)2612 --- PASS: TestSignErrors/invalid_json (0.00s)2613 --- PASS: TestSignErrors/http_error (0.00s)2614 --- PASS: TestSignErrors/no_prefix (0.00s)2615 --- PASS: TestSignErrors/invalid_base64 (0.00s)2616--- PASS: TestSign (0.00s)2617PASS