niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #368
· 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.24s)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 TestScriptTokenEmptyCommand101=== CONT TestStreamPushGivesUpOnDeadServer102=== CONT TestSetClientTLSErrors103--- PASS: TestScriptTokenEmptyCommand (0.00s)104=== CONT TestScriptTokenScriptFails105=== CONT TestScriptTokenEmptyToken1062026/10/06 10:42:30 ERROR Upload failed error="connection refused" count=201072026/10/06 10:42:30 ERROR Server seems unavailable, giving up on batch untried=17108=== CONT TestScriptTokenCachesUntilRefresh109=== CONT TestScriptTokenNoExpiryRerunsEveryCall110=== CONT TestFileTokenEmpty111=== CONT TestScriptTokenBadJSON112--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)113=== CONT TestFileTokenMissing114--- PASS: TestFileTokenEmpty (0.00s)115=== CONT TestFileTokenReadsAndCaches116--- PASS: TestFileTokenMissing (0.00s)117=== CONT TestStaticToken118--- PASS: TestStaticToken (0.00s)119=== CONT TestEncodeNixBase321202026/10/06 10:42:30 WARN Rate limiter enabled after throttle name=server-test rate=51212026/10/06 10:42:30 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:52013122=== RUN TestEncodeNixBase32/test_string_hash123=== PAUSE TestEncodeNixBase32/test_string_hash124=== RUN TestEncodeNixBase32/empty_input125=== PAUSE TestEncodeNixBase32/empty_input126=== CONT TestResolveStorePath127--- PASS: TestDoServerRequestAttachesToken (0.01s)128=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1292026/10/06 10:42:30 WARN Rate limiter enabled after throttle name=server-test rate=5130--- PASS: TestScriptTokenScriptFails (0.01s)131=== CONT TestRateLimiterFeedback132=== RUN TestRateLimiterFeedback/429_enables_limiter133=== PAUSE TestRateLimiterFeedback/429_enables_limiter134=== RUN TestRateLimiterFeedback/503_enables_limiter135=== PAUSE TestRateLimiterFeedback/503_enables_limiter136=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter137=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter138=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter139=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter140=== CONT TestPathInfoCACompatibility141=== RUN TestPathInfoCACompatibility/null_ca_field142=== PAUSE TestPathInfoCACompatibility/null_ca_field143=== RUN TestPathInfoCACompatibility/old_string_format_-_text144=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text145=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive146=== PAUSE TestPathInfoCACompatibility/old_string_forma2026/10/06 10:42:30 WARN Rate limiter backed off name=server-test rate=5147t_-_fixed_recursive148=== RUN TestPathInfoCACompatibility/new_structured_format_-_text149=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text150=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method1512026/10/06 10:42:30 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:52013152=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method153=== CONT TestParsePathInfoJSONMultiplePaths154=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths155=== RUN TestSetClientTLSErrors/missing_cert_file156=== PAUSE TestSetClientTLSErrors/missing_cert_file157=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths158=== RUN TestSetClientTLSErrors/missing_key_file159=== PAUSE TestSetClientTLSErrors/missing_key_file160=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths161=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths162=== RUN TestSetClientTLSErrors/missing_ca_file163=== PAUSE TestSetClientTLSErrors/missing_ca_file164=== CONT TestParsePathInfoJSON165=== RUN TestParsePathInfoJSON/Nix_format166=== PAUSE TestParsePathInfoJSON/Nix_format167=== RUN TestParsePathInfoJSON/Lix_format168=== PAUSE TestParsePathInfoJSON/Lix_format169--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)170=== RUN TestParsePathInfoJSON/empty_input171=== CONT TestPathInfoHashCompatibility172--- PASS: TestFileTokenReadsAndCaches (0.00s)173=== CONT TestGetStorePathHash174=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)175=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)176=== RUN TestGetStorePathHash/valid_store_path177=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon178=== PAUSE TestGetStorePathHash/valid_store_path179=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon180=== RUN TestSetClientTLSErrors/invalid_ca_file181=== RUN TestGetStorePathHash/basename_without_hyphen_should_error182=== PAUSE TestSetClientTLSErrors/invalid_ca_file183=== PAUSE TestParsePathInfoJSON/empty_input184=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI185=== RUN TestParsePathInfoJSON/whitespace_only186--- PASS: TestResolveStorePath (0.00s)187=== PAUSE TestParsePathInfoJSON/whitespace_only188=== CONT TestEncodeNixBase32WithRealHash189=== RUN TestParsePathInfoJSON/invalid_JSON190=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI191=== CONT TestStreamPushIsolatesFailures192--- PASS: TestEncodeNixBase32WithRealHash (0.00s)193=== PAUSE TestParsePathInfoJSON/invalid_JSON194=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512195=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error196=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512197=== CONT TestConvertHashToNix32198=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error199=== CONT TestUploadMultipart_PartsInParallel200=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error2012026/10/06 10:42:30 ERROR Upload failed error="bad path" count=3202=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error203=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error204=== RUN TestConvertHashToNix32/SRI_format_to_Nix32205=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32206=== RUN TestConvertHashToNix32/already_Nix32_format207=== PAUSE TestConvertHashToNix32/already_Nix32_format208=== CONT TestDumpPathMatchesNix209=== CONT TestDumpPathWriterError210=== CONT TestDumpPathSingleFile211--- PASS: TestStreamPushIsolatesFailures (0.00s)212=== RUN TestConvertHashToNix32/invalid_format213=== PAUSE TestConvertHashToNix32/invalid_format214=== CONT TestUploadMultipart_SupersededByPeer215=== RUN TestUploadMultipart_SupersededByPeer/exists216=== PAUSE TestUploadMultipart_SupersededByPeer/exists217=== RUN TestUploadMultipart_SupersededByPeer/missing218=== PAUSE TestUploadMultipart_SupersededByPeer/missing219=== CONT TestPartSizeForNAR220=== RUN TestPartSizeForNAR/zero_stays_at_minimum221=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum222=== RUN TestPartSizeForNAR/small_stays_at_minimum223=== PAUSE TestPartSizeForNAR/small_stays_at_minimum224=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum225=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum226=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts227=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts228=== RUN TestPartSizeForNAR/1_TiB229=== PAUSE TestPartSizeForNAR/1_TiB230=== RUN TestPartSizeForNAR/5_TiB_S3_max_object231=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object232=== RUN TestPartSizeForNAR/capped_at_5_GiB233=== PAUSE TestPartSizeForNAR/capped_at_5_GiB234=== CONT TestClientSignaturesByStorePath235--- PASS: TestClientSignaturesByStorePath (0.00s)236=== CONT TestSetClientTLSDoesNotMutateDefaultTransport237--- PASS: TestScriptTokenBadJSON (0.01s)238=== CONT TestSetClientTLS239--- PASS: TestScriptTokenEmptyToken (0.02s)240=== CONT TestStreamPushBatchesUnderLoad241--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)242=== CONT TestShellSplitErrors243--- PASS: TestShellSplitErrors (0.00s)244=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun245=== RUN TestSetClientTLS/rejects_connection_without_client_cert246=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert247=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA248=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA249=== RUN TestSetClientTLS/preserves_debug_logging_transport250=== PAUSE TestSetClientTLS/preserves_debug_logging_transport251=== CONT TestFilterOversizedClosures252=== RUN TestFilterOversizedClosures/no_limit_keeps_everything253=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything254=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped255=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped256=== RUN TestFilterOversizedClosures/all_closures_skipped257=== PAUSE TestFilterOversizedClosures/all_closures_skipped258=== CONT TestCaseHackSuffix2592026/10/06 10:42:30 INFO Garbage collection started260--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)261=== CONT TestStreamPushReportsSignatures2622026/10/06 10:42:30 ERROR Upload failed error=boom count=1263--- PASS: TestStreamPushReportsSignatures (0.00s)264=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica2652026/10/06 10:42:30 INFO Garbage collection started2662026/10/06 10:42:30 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=02672026/10/06 10:42:30 WARN Garbage collection finished on another replica. Its statistics are not available here268--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)269=== CONT TestStreamPushRequestLine2702026/10/06 10:42:30 ERROR Upload failed error=boom count=1271--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)272=== CONT TestRegisterUploadedObjectReusesConnections273--- PASS: TestStreamPushRequestLine (0.01s)274=== CONT TestShellSplit275--- PASS: TestShellSplit (0.00s)276=== CONT TestStreamPushReportsEveryPath277--- PASS: TestStreamPushReportsEveryPath (0.00s)278=== CONT TestEncodeNixBase32/test_string_hash279=== CONT TestEncodeNixBase32/empty_input280--- PASS: TestEncodeNixBase32 (0.00s)281 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)282 --- PASS: TestEncodeNixBase32/empty_input (0.00s)283=== CONT TestRateLimiterFeedback/429_enables_limiter284--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)285=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter2862026/10/06 10:42:30 WARN Rate limiter enabled after throttle name=server-test rate=52872026/10/06 10:42:30 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:52038288=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter2892026/10/06 10:42:30 WARN Rate limiter backed off name=server-test rate=5290=== CONT TestRateLimiterFeedback/503_enables_limiter291=== CONT TestPathInfoCACompatibility/null_ca_field292=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method293=== CONT TestPathInfoCACompatibility/new_structured_format_-_text294=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive295=== CONT TestPathInfoCACompatibility/old_string_format_-_text296--- PASS: TestPathInfoCACompatibility (0.00s)297 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)298 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)299 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)300 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)301 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)302=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths303=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths304--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)305 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)306 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)307=== CONT TestSetClientTLSErrors/missing_cert_file308=== CONT TestSetClientTLSErrors/invalid_ca_file3092026/10/06 10:42:30 WARN Rate limiter enabled after throttle name=server-test rate=53102026/10/06 10:42:30 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:52100311=== CONT TestSetClientTLSErrors/missing_ca_file312=== CONT TestSetClientTLSErrors/missing_key_file313=== CONT TestParsePathInfoJSON/Nix_format314=== CONT TestParsePathInfoJSON/invalid_JSON315=== CONT TestParsePathInfoJSON/whitespace_only316=== CONT TestParsePathInfoJSON/empty_input317=== CONT TestParsePathInfoJSON/Lix_format318--- PASS: TestParsePathInfoJSON (0.00s)319 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)320 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)321 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)322 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)323 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)324--- PASS: TestSetClientTLSErrors (0.01s)325 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)326 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)327 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)328 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)329=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)330=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512331=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI332=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon333--- PASS: TestPathInfoHashCompatibility (0.00s)334 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)335 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)336 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)337 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)338=== CONT TestGetStorePathHash/valid_store_path339=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error340=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error341=== CONT TestGetStorePathHash/basename_without_hyphen_should_error342--- PASS: TestGetStorePathHash (0.00s)343 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)344 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)345 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)346 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)347=== CONT TestConvertHashToNix32/SRI_format_to_Nix32348=== CONT TestConvertHashToNix32/invalid_format349=== CONT TestConvertHashToNix32/already_Nix32_format350--- PASS: TestConvertHashToNix32 (0.00s)351 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)352 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)353 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)354=== CONT TestUploadMultipart_SupersededByPeer/exists3552026/10/06 10:42:30 WARN Rate limiter backed off name=server-test rate=5356--- PASS: TestRateLimiterFeedback (0.00s)357 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)358 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)359 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)360 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)361=== CONT TestUploadMultipart_SupersededByPeer/missing362=== CONT TestPartSizeForNAR/zero_stays_at_minimum363=== CONT TestPartSizeForNAR/1_TiB364=== CONT TestPartSizeForNAR/capped_at_5_GiB365=== CONT TestPartSizeForNAR/5_TiB_S3_max_object366=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum367=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts368=== CONT TestPartSizeForNAR/small_stays_at_minimum369--- PASS: TestPartSizeForNAR (0.00s)370 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)371 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)372 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)373 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)374 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)375 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (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 TestFilterOversizedClosures/no_limit_keeps_everything382=== CONT TestSetClientTLS/preserves_debug_logging_transport383--- PASS: TestDumpPathWriterError (0.04s)384=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA385=== CONT TestFilterOversizedClosures/all_closures_skipped3862026/10/06 10:42:30 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:42:30 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)393--- PASS: TestRegisterUploadedObjectReusesConnections (0.02s)3942026/10/06 10:42:30 http: TLS handshake error from 127.0.0.1:52106: remote error: tls: bad certificate395--- PASS: TestSetClientTLS (0.00s)396 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)397 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)398 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)399--- PASS: TestDumpPathSingleFile (0.06s)400--- PASS: TestCaseHackSuffix (0.05s)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-19021-1960143159/postgres4013219003/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-19021-1960143159/postgres4013219003/data -l logfile start4334342026-10-06 10:42:32.290 UTC [19058] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4352026-10-06 10:42:32.290 UTC [19058] LOG: listening on Unix socket "/nix/var/nix/builds/nix-19021-1960143159/postgres4013219003/.s.PGSQL.5432"4362026-10-06 10:42:32.292 UTC [19065] LOG: database system was shut down at 2026-10-06 10:42:32 UTC4372026-10-06 10:42:32.292 UTC [19066] FATAL: the database system is starting up438/nix/var/nix/builds/nix-19021-1960143159/postgres4013219003:5432 - rejecting connections4392026-10-06 10:42:32.293 UTC [19058] LOG: database system is ready to accept connections440/nix/var/nix/builds/nix-19021-1960143159/postgres4013219003:5432 - accepting connections441{"timestamp":"2026-10-06T10:42:32.549903Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"3d6f342f-dd85-40f6-9fce-ed4b900d7760","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":9,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(5)"}442{"timestamp":"2026-10-06T10:42:32.657063Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"c8706a53-e9b9-4efe-8684-e49af186b8dd","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(10)"}443{"timestamp":"2026-10-06T10:42:32.761433Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"7c9bc301-d0b4-45ce-9a06-c3a3ce5c49e2","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}444=== RUN TestService_AuthMiddleware445=== PAUSE TestService_AuthMiddleware446=== RUN TestService_AuthMiddleware_MTLSProxyHeader447=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader448=== RUN TestService_AuthMiddleware_MTLSBoundSubjects449=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects450=== RUN TestService_ReadAuthMiddleware451=== PAUSE TestService_ReadAuthMiddleware452=== RUN TestService_AuthMiddleware_OIDC453=== PAUSE TestService_AuthMiddleware_OIDC454=== RUN TestService_RequireScope_OIDC455=== PAUSE TestService_RequireScope_OIDC456=== RUN TestService_ReadScope_PublicByDefault457=== PAUSE TestService_ReadScope_PublicByDefault458=== RUN TestCacheConfigHandler459=== PAUSE TestCacheConfigHandler460=== RUN TestCacheStatsHandler461=== PAUSE TestCacheStatsHandler462=== RUN TestClientCADerivations463=== PAUSE TestClientCADerivations464=== RUN TestClientErrorHandling465=== PAUSE TestClientErrorHandling466=== RUN TestClientIntegration467=== PAUSE TestClientIntegration468=== RUN TestClientMultipleUploads469=== PAUSE TestClientMultipleUploads470=== RUN TestClientWithDependencies471=== PAUSE TestClientWithDependencies472=== RUN TestClientSharedPathCommittedMidPush473=== PAUSE TestClientSharedPathCommittedMidPush474=== RUN TestPinProtectsFromGC475=== PAUSE TestPinProtectsFromGC476=== RUN TestClientPushesUseOnePush477=== PAUSE TestClientPushesUseOnePush478=== RUN TestClientFallsBackToClosures479=== PAUSE TestClientFallsBackToClosures480=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock481=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock482=== RUN TestResolveDBConnectionString483=== PAUSE TestResolveDBConnectionString484=== RUN TestConnectWaitsForAPeerMigration485=== PAUSE TestConnectWaitsForAPeerMigration486=== RUN TestLeadElectsOneAndHandsOver487=== PAUSE TestLeadElectsOneAndHandsOver488=== RUN TestLeadIncumbentWinsAfterRestart4892026/10/06 10:42:33 INFO lead: acquired remote=192.0.2.1:12344902026/10/06 10:42:33 INFO lead: released remote=192.0.2.1:12344912026/10/06 10:42:33 INFO lead: acquired remote=192.0.2.1:12344922026/10/06 10:42:34 INFO lead: released remote=192.0.2.1:1234493--- PASS: TestLeadIncumbentWinsAfterRestart (2.04s)494=== RUN TestLeadIncumbentAnnouncesAtOnce495=== PAUSE TestLeadIncumbentAnnouncesAtOnce496=== RUN TestLeadEndsOnShutdown497=== PAUSE TestLeadEndsOnShutdown498=== RUN TestLeadEndsWhenItsConnectionHangs4992026/10/06 10:42:35 INFO lead: acquired remote=192.0.2.1:12345002026-10-06 10:42:36.270 UTC [19104] FATAL: terminating connection due to administrator command5012026/10/06 10:42:36 INFO lead: acquired remote=192.0.2.1:12345022026/10/06 10:42:37 WARN lead: lock connection lost error="timeout: context deadline exceeded"5032026/10/06 10:42:37 INFO lead: released remote=192.0.2.1:12345042026/10/06 10:42:37 INFO lead: released remote=192.0.2.1:1234505--- PASS: TestLeadEndsWhenItsConnectionHangs (2.76s)506=== RUN TestGCAdvisoryLockBlocksConcurrentRun507=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun508=== RUN TestGCBugBareHashReferences509=== PAUSE TestGCBugBareHashReferences510=== RUN TestGCMetrics511=== PAUSE TestGCMetrics512=== RUN TestPushDedupSurvivesConcurrentGC513=== PAUSE TestPushDedupSurvivesConcurrentGC514=== RUN TestDeduplicatedObjectsRecordedAsPending515=== PAUSE TestDeduplicatedObjectsRecordedAsPending516=== RUN TestGCSweepSkipsPendingObjects517=== PAUSE TestGCSweepSkipsPendingObjects518=== RUN TestTombstonedObjectOfferedWithoutWaiting519=== PAUSE TestTombstonedObjectOfferedWithoutWaiting520=== RUN TestGCSweepDeliversEachKeyOnce521=== PAUSE TestGCSweepDeliversEachKeyOnce522=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection524=== RUN TestForceGCDuringPushOffersSweptObject525=== PAUSE TestForceGCDuringPushOffersSweptObject526=== RUN TestFailedS3DeleteKeepsTombstone527=== PAUSE TestFailedS3DeleteKeepsTombstone528=== RUN TestSweepSkipsRowsLockedByPush529=== PAUSE TestSweepSkipsRowsLockedByPush530=== RUN TestRegisterCompletedObjectNeedsPendingRow531=== PAUSE TestRegisterCompletedObjectNeedsPendingRow532=== RUN TestGetExistingObjectsLocksRows533=== PAUSE TestGetExistingObjectsLocksRows534=== RUN TestSweepRechecksPendingAfterLocking535=== PAUSE TestSweepRechecksPendingAfterLocking536=== RUN TestPushWaitsForSweepHoldingRow537=== PAUSE TestPushWaitsForSweepHoldingRow538=== RUN TestCommitRacingPendingCleanupKeepsObjects539=== PAUSE TestCommitRacingPendingCleanupKeepsObjects540=== RUN TestGCEndsOnShutdown541=== PAUSE TestGCEndsOnShutdown542=== RUN TestGCTaskStore_StartNew543=== PAUSE TestGCTaskStore_StartNew544=== RUN TestGCTaskStore_DeduplicateSameParams545=== PAUSE TestGCTaskStore_DeduplicateSameParams546=== RUN TestGCTaskStore_ConflictDifferentParams547=== PAUSE TestGCTaskStore_ConflictDifferentParams548=== RUN TestGCTaskStore_GetEmpty549=== PAUSE TestGCTaskStore_GetEmpty550=== RUN TestGCTaskStore_GetReturnsLatest551=== PAUSE TestGCTaskStore_GetReturnsLatest552=== RUN TestGCTaskStore_CompletedAllowsNewTask553=== PAUSE TestGCTaskStore_CompletedAllowsNewTask554=== RUN TestGCTaskStore_PhaseUpdates555=== PAUSE TestGCTaskStore_PhaseUpdates556=== RUN TestGCTaskStore_Fail557=== PAUSE TestGCTaskStore_Fail558=== RUN TestGracefulShutdownDrainsInflight559=== PAUSE TestGracefulShutdownDrainsInflight560=== RUN TestService_healthCheckHandler561=== PAUSE TestService_healthCheckHandler562=== RUN TestService_readinessHandler563=== PAUSE TestService_readinessHandler564=== RUN TestGenerateLandingPage565=== PAUSE TestGenerateLandingPage566=== RUN TestCacheConfigHandlerMaxNarSize567=== PAUSE TestCacheConfigHandlerMaxNarSize568=== RUN TestCreatePendingClosureRejectsOversizedNAR569=== PAUSE TestCreatePendingClosureRejectsOversizedNAR570=== RUN TestNARDeduplicationMetadataUploadBug571=== PAUSE TestNARDeduplicationMetadataUploadBug572=== RUN TestMetricsInventory573=== PAUSE TestMetricsInventory574=== RUN TestService_NativeMTLS575=== PAUSE TestService_NativeMTLS576=== RUN TestServerTLSConfig577=== PAUSE TestServerTLSConfig578=== RUN TestMultipartCleanup579=== PAUSE TestMultipartCleanup580=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded581=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded582=== RUN TestPendingCleanupUsesOneCutoff583=== PAUSE TestPendingCleanupUsesOneCutoff584=== RUN TestObjectStatsTrigger585=== PAUSE TestObjectStatsTrigger586=== RUN TestOrphanedObjectsGC587=== PAUSE TestOrphanedObjectsGC588=== RUN TestOrphanedObjectsGCStressTest589=== PAUSE TestOrphanedObjectsGCStressTest590=== RUN TestCreatePin_ReservedPins591=== PAUSE TestCreatePin_ReservedPins592=== RUN TestPresentReportsOnlyClosureRoots593=== PAUSE TestPresentReportsOnlyClosureRoots594=== RUN TestPresentNotReportedWhileGCDeletesClosure595=== PAUSE TestPresentNotReportedWhileGCDeletesClosure596=== RUN TestParseSingleRange597=== PAUSE TestParseSingleRange598=== RUN TestProxyHeadersOnlyTrustedOnSocket599=== PAUSE TestProxyHeadersOnlyTrustedOnSocket600=== RUN TestIsValidCachePath601=== PAUSE TestIsValidCachePath602=== RUN TestReadProxyNarinfo603=== PAUSE TestReadProxyNarinfo604=== RUN TestReadProxyNarinfoAlreadyDecompressed605=== PAUSE TestReadProxyNarinfoAlreadyDecompressed606=== RUN TestReadProxyContentNegotiation607=== PAUSE TestReadProxyContentNegotiation608=== RUN TestReadProxyNarStreaming609=== PAUSE TestReadProxyNarStreaming610=== RUN TestReadProxy404611=== PAUSE TestReadProxy404612=== RUN TestReadProxyInvalidPath613=== PAUSE TestReadProxyInvalidPath614=== RUN TestReadProxyHead615=== PAUSE TestReadProxyHead616=== RUN TestReadProxyOutlastsServerWriteTimeout617=== PAUSE TestReadProxyOutlastsServerWriteTimeout618=== RUN TestReadProxyConditionalGet619=== PAUSE TestReadProxyConditionalGet620=== RUN TestReadProxyRootRedirectsToIndexHTML621=== PAUSE TestReadProxyRootRedirectsToIndexHTML622=== RUN TestReadProxyDisabled623=== PAUSE TestReadProxyDisabled624=== RUN TestReadRedirectNar625=== PAUSE TestReadRedirectNar626=== RUN TestReadRedirectKeepsNarinfoProxied627=== PAUSE TestReadRedirectKeepsNarinfoProxied628=== RUN TestReadProxyRangeRequest629=== PAUSE TestReadProxyRangeRequest630=== RUN TestReadRedirectUsesPublicS3URL631=== PAUSE TestReadRedirectUsesPublicS3URL632=== RUN TestPush_OverlappingRootsStoreOneRowPerKey633=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey634=== RUN TestPush_CompleteCommitsEveryRoot635=== PAUSE TestPush_CompleteCommitsEveryRoot636=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit637=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit638=== RUN TestPush_RejectsBadRequests639=== PAUSE TestPush_RejectsBadRequests640=== RUN TestPush_SignsNarinfosOfItsPendingObjects641=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects642=== RUN TestRedundantMultipartUpload643=== PAUSE TestRedundantMultipartUpload644=== RUN TestCompleteMultipartUpload_ErrorButObjectExists645=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists646=== RUN TestCompletedNarNotReofferedAcrossClosures647=== PAUSE TestCompletedNarNotReofferedAcrossClosures648=== RUN TestPresignedUploadRegisteredBeforeCommit649=== PAUSE TestPresignedUploadRegisteredBeforeCommit650=== RUN TestService_Rustfstest651=== PAUSE TestService_Rustfstest652=== RUN TestParseSize653=== PAUSE TestParseSize654=== RUN TestSkippedUploadsHandler655=== PAUSE TestSkippedUploadsHandler656=== RUN TestSystemdListenerNotActivated657--- PASS: TestSystemdListenerNotActivated (0.00s)658=== RUN TestWatchdogBeatsWhenHealthy659--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)660=== RUN TestWatchdogSkipsWhenUnhealthy6612026/10/06 10:42:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/06 10:42:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/06 10:42:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/06 10:42:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/06 10:42:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/06 10:42:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/06 10:42:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6682026/10/06 10:42:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6692026/10/06 10:42:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6702026/10/06 10:42:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"671--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)672=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle673=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle674=== RUN TestProxyWriteTimeout675=== PAUSE TestProxyWriteTimeout676=== RUN TestPendingClosureWriteTimeout677=== PAUSE TestPendingClosureWriteTimeout678=== RUN TestIsValidUploadKey679=== PAUSE TestIsValidUploadKey680=== RUN TestUploadHandlersRejectInvalidKeys681=== PAUSE TestUploadHandlersRejectInvalidKeys682=== RUN TestUploadHandlersRejectOversizedBody683=== PAUSE TestUploadHandlersRejectOversizedBody684=== RUN TestService_cleanupPendingClosuresHandler685=== PAUSE TestService_cleanupPendingClosuresHandler686=== RUN TestService_createPendingClosureHandler687=== PAUSE TestService_createPendingClosureHandler688=== RUN TestService_verifyS3Integrity689=== PAUSE TestService_verifyS3Integrity690=== RUN TestCompleteMultipartUnregistered691=== PAUSE TestCompleteMultipartUnregistered692=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT693=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT694=== CONT TestReadRedirectKeepsNarinfoProxied695=== CONT TestParseSize696=== CONT TestService_AuthMiddleware697--- PASS: TestParseSize (0.00s)698=== CONT TestReadProxyDisabled699=== CONT TestGCTaskStore_StartNew700--- PASS: TestGCTaskStore_StartNew (0.00s)701=== CONT TestUploadHandlersRejectOversizedBody702=== CONT TestReadRedirectNar703=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT704=== CONT TestCompleteMultipartUnregistered705=== CONT TestService_verifyS3Integrity706=== CONT TestService_createPendingClosureHandler707=== CONT TestService_cleanupPendingClosuresHandler708=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure709=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure710=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart711=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart712=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts713=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts714=== CONT TestUploadHandlersRejectInvalidKeys715=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info716=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info717=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal718=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal719=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key720=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key721=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key722=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key723=== CONT TestIsValidUploadKey724=== RUN TestIsValidUploadKey/narinfo725=== PAUSE TestIsValidUploadKey/narinfo726=== RUN TestIsValidUploadKey/nar_zst727=== PAUSE TestIsValidUploadKey/nar_zst728=== RUN TestIsValidUploadKey/nar_xz729=== PAUSE TestIsValidUploadKey/nar_xz730=== RUN TestIsValidUploadKey/nar_plain731=== PAUSE TestIsValidUploadKey/nar_plain732=== RUN TestIsValidUploadKey/listing733=== PAUSE TestIsValidUploadKey/listing734=== RUN TestIsValidUploadKey/build_log735=== PAUSE TestIsValidUploadKey/build_log736=== RUN TestIsValidUploadKey/build_log_home-manager_file737=== PAUSE TestIsValidUploadKey/build_log_home-manager_file738=== RUN TestIsValidUploadKey/build_log_plus_in_name739=== PAUSE TestIsValidUploadKey/build_log_plus_in_name740=== RUN TestIsValidUploadKey/build_log_question_mark741=== PAUSE TestIsValidUploadKey/build_log_question_mark742=== RUN TestIsValidUploadKey/build_log_equals743=== PAUSE TestIsValidUploadKey/build_log_equals744=== RUN TestIsValidUploadKey/realisation745=== PAUSE TestIsValidUploadKey/realisation746=== RUN TestIsValidUploadKey/realisation_plus_in_output747=== PAUSE TestIsValidUploadKey/realisation_plus_in_output748=== RUN TestIsValidUploadKey/nix-cache-info749=== PAUSE TestIsValidUploadKey/nix-cache-info750=== RUN TestIsValidUploadKey/index.html751=== PAUSE TestIsValidUploadKey/index.html752=== RUN TestIsValidUploadKey/narinfo_key,_nar_type753=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type754=== RUN TestIsValidUploadKey/nar_key,_narinfo_type755=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type756=== RUN TestIsValidUploadKey/listing_key,_narinfo_type757=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type758=== RUN TestIsValidUploadKey/traversal759=== PAUSE TestIsValidUploadKey/traversal760=== RUN TestIsValidUploadKey/traversal_nar761=== PAUSE TestIsValidUploadKey/traversal_nar762=== RUN TestIsValidUploadKey/absolute763=== PAUSE TestIsValidUploadKey/absolute764=== RUN TestIsValidUploadKey/empty_key765=== PAUSE TestIsValidUploadKey/empty_key766=== RUN TestIsValidUploadKey/unknown_type767=== PAUSE TestIsValidUploadKey/unknown_type768=== CONT TestPendingClosureWriteTimeout769=== RUN TestPendingClosureWriteTimeout/empty770=== PAUSE TestPendingClosureWriteTimeout/empty771=== RUN TestPendingClosureWriteTimeout/400_objects772=== PAUSE TestPendingClosureWriteTimeout/400_objects773=== RUN TestPendingClosureWriteTimeout/670k_objects774=== PAUSE TestPendingClosureWriteTimeout/670k_objects775=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline776=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline777=== CONT TestProxyWriteTimeout778=== RUN TestProxyWriteTimeout/narinfo779=== PAUSE TestProxyWriteTimeout/narinfo780=== RUN TestProxyWriteTimeout/1_GiB_nar781=== PAUSE TestProxyWriteTimeout/1_GiB_nar782=== RUN TestProxyWriteTimeout/10_GiB_nar783=== PAUSE TestProxyWriteTimeout/10_GiB_nar784=== RUN TestProxyWriteTimeout/unknown_size785=== PAUSE TestProxyWriteTimeout/unknown_size786=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle787--- PASS: TestReadProxyDisabled (0.49s)788=== CONT TestSkippedUploadsHandler7892026/10/06 10:42:38 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000790--- PASS: TestSkippedUploadsHandler (0.00s)791=== CONT TestLeadElectsOneAndHandsOver7922026/10/06 10:42:38 INFO Received uploads request method=POST path=/api/pending_closures793--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.78s)794=== CONT TestGCEndsOnShutdown795=== RUN TestGCEndsOnShutdown/before_the_run796=== PAUSE TestGCEndsOnShutdown/before_the_run797=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete798=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete799=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark800=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark801=== CONT TestCommitRacingPendingCleanupKeepsObjects8022026/10/06 10:42:38 INFO Received uploads request method=POST path=/api/pending_closures8032026/10/06 10:42:38 INFO Received uploads request method=POST path=/api/pending_closures8042026/10/06 10:42:38 INFO Received uploads request method=POST path=/api/pending_closures805--- PASS: TestReadRedirectNar (1.12s)806=== CONT TestPushWaitsForSweepHoldingRow8072026/10/06 10:42:39 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"808--- PASS: TestService_AuthMiddleware (1.29s)809=== CONT TestSweepRechecksPendingAfterLocking810--- PASS: TestReadRedirectKeepsNarinfoProxied (1.52s)811=== CONT TestGetExistingObjectsLocksRows8122026/10/06 10:42:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8132026/10/06 10:42:39 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst814--- PASS: TestCompleteMultipartUnregistered (1.72s)815=== CONT TestRegisterCompletedObjectNeedsPendingRow8162026/10/06 10:42:39 INFO Received cleanup request method=DELETE path=/api/pending_closures8172026/10/06 10:42:39 INFO Aborted multipart uploads count=0 kept=08182026/10/06 10:42:39 INFO Received uploads request method=POST path=/api/pending_closures8192026/10/06 10:42:39 INFO Received cleanup request method=DELETE path=/api/pending_closures8202026/10/06 10:42:39 INFO Aborted multipart uploads count=1 kept=08212026/10/06 10:42:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8222026-10-06 10:42:39.944 UTC [19133] ERROR: Closure does not exist: id=18232026-10-06 10:42:39.944 UTC [19133] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE8242026-10-06 10:42:39.944 UTC [19133] STATEMENT: -- name: CommitPendingClosure :exec825 SELECT commit_pending_closure($1::bigint)826 827--- PASS: TestService_cleanupPendingClosuresHandler (2.02s)828=== CONT TestSweepSkipsRowsLockedByPush8292026/10/06 10:42:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8302026/10/06 10:42:40 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=Y2MyZDc1MmMtNGU1Ni00NDU4LWIyMGMtZmQ5NGM0MjQ0ZmQ0LjlhZDA0ZmQ1LTRhY2MtNDY3Mi04YTQxLTc3OWVhNGE4M2Y2OXgxNzkxMjgzMzU4ODYwMzE4MDAw parts=108312026/10/06 10:42:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8322026/10/06 10:42:40 INFO Completed upload id=18332026/10/06 10:42:40 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000008342026/10/06 10:42:40 INFO Received uploads request method=POST path=/api/pending_closures8352026/10/06 10:42:40 INFO Starting cleanup of old closures method=DELETE path=/api/closures8362026/10/06 10:42:40 INFO Aborted multipart uploads count=0 kept=08372026/10/06 10:42:40 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=08382026/10/06 10:42:40 INFO Received uploads request method=POST path=/api/pending_closures8392026/10/06 10:42:40 INFO Vacuumed table table=pending_closures8402026/10/06 10:42:40 INFO Vacuumed table table=pending_objects8412026/10/06 10:42:40 INFO Vacuumed table table=multipart_uploads8422026/10/06 10:42:40 INFO Vacuumed table table=closures8432026/10/06 10:42:40 INFO Vacuumed table table=objects8442026/10/06 10:42:40 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000845--- PASS: TestService_createPendingClosureHandler (2.29s)846=== CONT TestFailedS3DeleteKeepsTombstone8472026/10/06 10:42:40 INFO Received uploads request method=POST path=/api/pending_closures8482026/10/06 10:42:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8492026/10/06 10:42:40 INFO lead: acquired remote=192.0.2.1:12348502026/10/06 10:42:40 INFO Aborted multipart uploads count=0 kept=08512026/10/06 10:42:40 WARN Force mode enabled - objects will be deleted immediately without grace period8522026/10/06 10:42:40 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=08532026/10/06 10:42:41 INFO Vacuumed table table=pending_closures8542026/10/06 10:42:41 INFO Vacuumed table table=pending_objects8552026/10/06 10:42:41 INFO Vacuumed table table=multipart_uploads8562026/10/06 10:42:41 INFO Vacuumed table table=closures8572026/10/06 10:42:41 INFO Vacuumed table table=objects858--- PASS: TestCommitRacingPendingCleanupKeepsObjects (2.40s)859=== CONT TestForceGCDuringPushOffersSweptObject860=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows861=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows862=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check863=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check864=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection8652026/10/06 10:42:41 INFO Received uploads request method=POST path=/api/pending_closures8662026/10/06 10:42:41 INFO Aborted multipart uploads count=0 kept=08672026/10/06 10:42:41 WARN Force mode enabled - objects will be deleted immediately without grace period8682026/10/06 10:42:41 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=08692026/10/06 10:42:41 INFO Vacuumed table table=pending_closures8702026/10/06 10:42:41 INFO Vacuumed table table=pending_objects8712026/10/06 10:42:41 INFO Vacuumed table table=multipart_uploads8722026/10/06 10:42:41 INFO Vacuumed table table=closures8732026/10/06 10:42:41 INFO Vacuumed table table=objects874--- PASS: TestSweepRechecksPendingAfterLocking (2.34s)875=== CONT TestGCSweepDeliversEachKeyOnce876--- PASS: TestPushWaitsForSweepHoldingRow (2.64s)877=== CONT TestTombstonedObjectOfferedWithoutWaiting878--- PASS: TestGetExistingObjectsLocksRows (2.25s)879=== CONT TestGCSweepSkipsPendingObjects8802026/10/06 10:42:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8812026/10/06 10:42:41 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=Y2MyZDc1MmMtNGU1Ni00NDU4LWIyMGMtZmQ5NGM0MjQ0ZmQ0LjU3Njc0MGFmLTk4MjMtNGFmYS1iNDBmLWQxMmVjZDNmMTUwNXgxNzkxMjgzMzYwNDAxODc3MDAw parts=108822026/10/06 10:42:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8832026/10/06 10:42:41 INFO Completed upload id=18842026/10/06 10:42:41 INFO Received uploads request method=POST path=/api/pending_closures8852026/10/06 10:42:41 INFO Received uploads request method=POST path=/api/pending_closures8862026/10/06 10:42:41 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo8872026/10/06 10:42:41 WARN Found objects in DB but missing from S3, will re-upload count=1888--- PASS: TestService_verifyS3Integrity (3.87s)889=== CONT TestDeduplicatedObjectsRecordedAsPending8902026/10/06 10:42:41 INFO lead: released remote=192.0.2.1:12348912026/10/06 10:42:41 INFO lead: acquired remote=192.0.2.1:1234892--- PASS: TestRegisterCompletedObjectNeedsPendingRow (2.29s)893=== CONT TestPushDedupSurvivesConcurrentGC8942026/10/06 10:42:42 INFO Aborted multipart uploads count=0 kept=08952026/10/06 10:42:42 WARN Force mode enabled - objects will be deleted immediately without grace period8962026/10/06 10:42:42 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=08972026/10/06 10:42:42 INFO Vacuumed table table=pending_closures8982026/10/06 10:42:42 INFO Vacuumed table table=pending_objects8992026/10/06 10:42:42 INFO Vacuumed table table=multipart_uploads9002026/10/06 10:42:42 INFO Vacuumed table table=closures9012026/10/06 10:42:42 INFO Vacuumed table table=objects9022026/10/06 10:42:42 INFO Aborted multipart uploads count=0 kept=09032026/10/06 10:42:42 WARN Force mode enabled - objects will be deleted immediately without grace period9042026/10/06 10:42:42 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=09052026/10/06 10:42:42 INFO Vacuumed table table=pending_closures9062026/10/06 10:42:42 INFO Vacuumed table table=pending_objects9072026/10/06 10:42:42 INFO Vacuumed table table=multipart_uploads9082026/10/06 10:42:42 INFO Vacuumed table table=closures9092026/10/06 10:42:42 INFO Vacuumed table table=objects910--- PASS: TestSweepSkipsRowsLockedByPush (2.31s)911=== CONT TestGCMetrics9122026/10/06 10:42:42 INFO Received uploads request method=POST path=/api/pending_closures9132026/10/06 10:42:42 INFO Aborted multipart uploads count=0 kept=09142026/10/06 10:42:42 WARN Force mode enabled - objects will be deleted immediately without grace period9152026/10/06 10:42:42 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."9162026/10/06 10:42:42 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."917--- PASS: TestFailedS3DeleteKeepsTombstone (2.23s)918=== CONT TestGCBugBareHashReferences9192026/10/06 10:42:42 INFO Received uploads request method=POST path=/api/pending_closures920--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (1.79s)921=== CONT TestGCAdvisoryLockBlocksConcurrentRun9222026/10/06 10:42:42 INFO lead: released remote=192.0.2.1:1234923--- PASS: TestLeadElectsOneAndHandsOver (4.51s)924=== CONT TestLeadEndsOnShutdown9252026/10/06 10:42:42 INFO Aborted multipart uploads count=0 kept=09262026/10/06 10:42:42 WARN Force mode enabled - objects will be deleted immediately without grace period9272026/10/06 10:42:43 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=09282026/10/06 10:42:43 INFO Vacuumed table table=pending_closures9292026/10/06 10:42:43 INFO Vacuumed table table=pending_objects9302026/10/06 10:42:43 INFO Vacuumed table table=multipart_uploads9312026/10/06 10:42:43 INFO Vacuumed table table=closures9322026/10/06 10:42:43 INFO Vacuumed table table=objects933--- PASS: TestGCSweepDeliversEachKeyOnce (1.50s)934=== CONT TestLeadIncumbentAnnouncesAtOnce9352026/10/06 10:42:43 INFO Received uploads request method=POST path=/api/pending_closures9362026/10/06 10:42:43 INFO Aborted multipart uploads count=0 kept=09372026/10/06 10:42:43 WARN Force mode enabled - objects will be deleted immediately without grace period9382026/10/06 10:42:43 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=09392026/10/06 10:42:43 INFO Vacuumed table table=pending_closures9402026/10/06 10:42:43 INFO Vacuumed table table=pending_objects9412026/10/06 10:42:43 INFO Vacuumed table table=multipart_uploads9422026/10/06 10:42:43 INFO Vacuumed table table=closures9432026/10/06 10:42:43 INFO Vacuumed table table=objects944--- PASS: TestGCSweepSkipsPendingObjects (1.73s)945=== CONT TestClientIntegration9462026/10/06 10:42:43 INFO Received uploads request method=POST path=/api/pending_closures947--- PASS: TestTombstonedObjectOfferedWithoutWaiting (1.92s)948=== CONT TestConnectWaitsForAPeerMigration9492026/10/06 10:42:43 INFO Received uploads request method=POST path=/api/pending_closures950--- PASS: TestDeduplicatedObjectsRecordedAsPending (1.98s)951=== CONT TestResolveDBConnectionString952=== RUN TestResolveDBConnectionString/flag_wins953=== PAUSE TestResolveDBConnectionString/flag_wins954=== RUN TestResolveDBConnectionString/file_when_flag_empty955=== PAUSE TestResolveDBConnectionString/file_when_flag_empty956=== RUN TestResolveDBConnectionString/missing_file_is_an_error957=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error958=== RUN TestResolveDBConnectionString/PGHOST_allows_empty959=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty960=== RUN TestResolveDBConnectionString/nothing_configured961=== PAUSE TestResolveDBConnectionString/nothing_configured962=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock9632026/10/06 10:42:44 INFO Received uploads request method=POST path=/api/pending_closures9642026/10/06 10:42:44 INFO Aborted multipart uploads count=0 kept=09652026/10/06 10:42:44 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=09662026/10/06 10:42:44 INFO Vacuumed table table=pending_closures9672026/10/06 10:42:44 INFO Vacuumed table table=pending_objects9682026/10/06 10:42:44 INFO Vacuumed table table=multipart_uploads9692026/10/06 10:42:44 INFO Vacuumed table table=closures9702026/10/06 10:42:44 INFO Aborted multipart uploads count=0 kept=09712026/10/06 10:42:44 WARN Force mode enabled - objects will be deleted immediately without grace period9722026/10/06 10:42:44 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09732026/10/06 10:42:44 INFO Vacuumed table table=pending_closures9742026/10/06 10:42:44 INFO Vacuumed table table=pending_objects9752026/10/06 10:42:44 INFO Vacuumed table table=multipart_uploads9762026/10/06 10:42:44 INFO Vacuumed table table=closures9772026/10/06 10:42:44 INFO Vacuumed table table=objects978--- PASS: TestGCMetrics (2.26s)979=== CONT TestClientFallsBackToClosures9802026/10/06 10:42:44 INFO Vacuumed table table=objects9812026/10/06 10:42:44 INFO Aborted multipart uploads count=0 kept=09822026/10/06 10:42:44 WARN Force mode enabled - objects will be deleted immediately without grace period9832026/10/06 10:42:44 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09842026/10/06 10:42:44 INFO Vacuumed table table=pending_closures9852026/10/06 10:42:44 INFO Vacuumed table table=pending_objects9862026/10/06 10:42:44 INFO Vacuumed table table=multipart_uploads9872026/10/06 10:42:44 INFO Vacuumed table table=closures9882026/10/06 10:42:44 INFO Vacuumed table table=objects989--- PASS: TestPushDedupSurvivesConcurrentGC (2.69s)990=== CONT TestClientPushesUseOnePush9912026/10/06 10:42:44 WARN Rate limiter enabled after throttle name=s3-test rate=59922026/10/06 10:42:44 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."993=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle994 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=10995 throttle_test.go:215: Rate limiter: enabled=true, rate=5.00996--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.71s)997=== CONT TestPinProtectsFromGC998--- PASS: TestGCBugBareHashReferences (2.69s)999=== CONT TestClientSharedPathCommittedMidPush10002026/10/06 10:42:45 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"1001--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (2.43s)1002=== CONT TestClientWithDependencies10032026/10/06 10:42:45 INFO lead: acquired remote=192.0.2.1:123410042026/10/06 10:42:45 INFO lead: acquired remote=192.0.2.1:123410052026/10/06 10:42:45 INFO lead: released remote=192.0.2.1:12341006--- PASS: TestLeadIncumbentAnnouncesAtOnce (2.92s)1007=== CONT TestClientMultipleUploads1008=== NAME TestClientIntegration1009 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-19021-1960143159/TestClientIntegration4077712788/002/store/81y9zfyvy0ks2qby46chrs9mj7qj7qm9-test-file.txt10102026/10/06 10:42:46 INFO lead: released remote=192.0.2.1:12341011--- PASS: TestLeadEndsOnShutdown (3.73s)1012=== CONT TestPendingCleanupUsesOneCutoff10132026/10/06 10:42:46 INFO Received push request method=POST path=/api/pushes10142026/10/06 10:42:46 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10152026/10/06 10:42:46 INFO Uploading 81y9zfyvy0ks2qby46chrs9mj7qj7qm9-test-file.txt (152B)10162026/10/06 10:42:46 WARN Failed to register uploaded object key=81y9zfyvy0ks2qby46chrs9mj7qj7qm9.ls error="server returned 404: 404 page not found\n"10172026/10/06 10:42:46 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"10182026/10/06 10:42:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10192026/10/06 10:42:46 INFO Signed narinfos id=1 count=110202026/10/06 10:42:46 INFO Uploading 1 narinfos10212026/10/06 10:42:46 INFO Received complete push request method=POST path=/api/pushes/1/complete10222026/10/06 10:42:46 WARN Failed to register uploaded object key=81y9zfyvy0ks2qby46chrs9mj7qj7qm9.narinfo error="server returned 404: 404 page not found\n"10232026/10/06 10:42:46 INFO Upload complete. (127ms)10242026/10/06 10:42:46 INFO All 1 paths already cached1025=== NAME TestClientIntegration1026 client_integration_test.go:312: Retrieved narinfo from S3:1027 StorePath: /nix/var/nix/builds/nix-19021-1960143159/TestClientIntegration4077712788/002/store/81y9zfyvy0ks2qby46chrs9mj7qj7qm9-test-file.txt1028 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1029 Compression: zstd1030 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11031 NarSize: 1521032 References: 1033 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11034 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1035 client_integration_test.go:313: Decompressed .ls content (64 bytes):1036 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1037 client_integration_test.go:316: Testing garbage collection...10382026/10/06 10:42:46 INFO Starting cleanup of old closures method=DELETE path=/api/closures10392026/10/06 10:42:46 INFO Garbage collection started10402026/10/06 10:42:46 INFO Aborted multipart uploads count=0 kept=010412026/10/06 10:42:46 WARN Force mode enabled - objects will be deleted immediately without grace period10422026/10/06 10:42:46 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=010432026/10/06 10:42:46 INFO Vacuumed table table=pending_closures10442026/10/06 10:42:46 INFO Vacuumed table table=pending_objects10452026/10/06 10:42:46 INFO Vacuumed table table=multipart_uploads10462026/10/06 10:42:46 INFO Vacuumed table table=closures10472026/10/06 10:42:46 INFO Vacuumed table table=objects10482026/10/06 10:42:47 INFO Received uploads request method=POST path=/api/pending_closures10492026/10/06 10:42:47 INFO Received uploads request method=POST path=/api/pending_closures10502026/10/06 10:42:47 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)10512026/10/06 10:42:47 INFO Uploading ln4lcwv49vblksaym8vlrbmcvbk23hz1-shared-dep (136B)10522026/10/06 10:42:47 INFO Uploading z8higzmxzpd1057bqx8kygpy1r86s8ql-b (248B)10532026/10/06 10:42:47 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10542026/10/06 10:42:47 WARN Failed to register uploaded object key=nar/0380874mizgvj9jyph1zvs95pxili4amk1ws9lwbr24grdf7w0n5.nar.zst error="server returned 404: 404 page not found\n"10552026/10/06 10:42:47 WARN Failed to register uploaded object key=z8higzmxzpd1057bqx8kygpy1r86s8ql.ls error="server returned 404: 404 page not found\n"10562026/10/06 10:42:47 WARN Failed to register uploaded object key=ln4lcwv49vblksaym8vlrbmcvbk23hz1.ls error="server returned 404: 404 page not found\n"10572026/10/06 10:42:47 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10582026/10/06 10:42:47 WARN Failed to register uploaded object key=m0zvcngipiqvpxvl3yjzmlgpbglkhz4j.ls error="server returned 404: 404 page not found\n"10592026/10/06 10:42:47 INFO Signed narinfos id=2 count=210602026/10/06 10:42:47 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10612026/10/06 10:42:47 INFO Signed narinfos id=1 count=210622026/10/06 10:42:47 INFO Uploading 4 narinfos10632026/10/06 10:42:47 WARN Failed to register uploaded object key=z8higzmxzpd1057bqx8kygpy1r86s8ql.narinfo error="server returned 404: 404 page not found\n"10642026/10/06 10:42:47 WARN Failed to register uploaded object key=ln4lcwv49vblksaym8vlrbmcvbk23hz1.narinfo error="server returned 404: 404 page not found\n"10652026/10/06 10:42:47 WARN Failed to register uploaded object key=m0zvcngipiqvpxvl3yjzmlgpbglkhz4j.narinfo error="server returned 404: 404 page not found\n"10662026/10/06 10:42:47 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10672026/10/06 10:42:47 WARN Failed to register uploaded object key=ln4lcwv49vblksaym8vlrbmcvbk23hz1.narinfo error="server returned 404: 404 page not found\n"1068=== NAME TestPinProtectsFromGC1069 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-19021-1960143159/TestPinProtectsFromGC3138575685/001/store/qrb0ccmvd5rk6h32hh4bj5b55jd8m05p-pinned-file.txt1070 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-19021-1960143159/TestPinProtectsFromGC3138575685/001/store/zvli4kapw8zjxpd2agxgbx400qayanc9-unpinned-file.txt10712026/10/06 10:42:47 INFO Completed upload id=110722026/10/06 10:42:47 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10732026/10/06 10:42:47 INFO Completed upload id=210742026/10/06 10:42:47 INFO Upload complete. (124ms)1075=== NAME TestClientFallsBackToClosures1076 client_pushes_test.go:112: Retrieved narinfo from S3:1077 StorePath: /nix/var/nix/builds/nix-19021-1960143159/TestClientFallsBackToClosures2396683332/001/store/ln4lcwv49vblksaym8vlrbmcvbk23hz1-shared-dep1078 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1079 Compression: zstd1080 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821081 NarSize: 1361082 References: 1083 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1084 client_pushes_test.go:112: Retrieved narinfo from S3:1085 StorePath: /nix/var/nix/builds/nix-19021-1960143159/TestClientFallsBackToClosures2396683332/001/store/m0zvcngipiqvpxvl3yjzmlgpbglkhz4j-a1086 URL: nar/0380874mizgvj9jyph1zvs95pxili4amk1ws9lwbr24grdf7w0n5.nar.zst1087 Compression: zstd1088 NarHash: sha256:0380874mizgvj9jyph1zvs95pxili4amk1ws9lwbr24grdf7w0n51089 NarSize: 2481090 References: /nix/var/nix/builds/nix-19021-1960143159/TestClientFallsBackToClosures2396683332/001/store/ln4lcwv49vblksaym8vlrbmcvbk23hz1-shared-dep1091 CA: text:sha256:1rkzs9anr3p860jijgjka2m1xrx1yx075k0yfqzinv8qsb2m2smv1092 client_pushes_test.go:112: Retrieved narinfo from S3:1093 StorePath: /nix/var/nix/builds/nix-19021-1960143159/TestClientFallsBackToClosures2396683332/001/store/z8higzmxzpd1057bqx8kygpy1r86s8ql-b1094 URL: nar/0380874mizgvj9jyph1zvs95pxili4amk1ws9lwbr24grdf7w0n5.nar.zst1095 Compression: zstd1096 NarHash: sha256:0380874mizgvj9jyph1zvs95pxili4amk1ws9lwbr24grdf7w0n51097 NarSize: 2481098 References: /nix/var/nix/builds/nix-19021-1960143159/TestClientFallsBackToClosures2396683332/001/store/ln4lcwv49vblksaym8vlrbmcvbk23hz1-shared-dep1099 CA: text:sha256:1rkzs9anr3p860jijgjka2m1xrx1yx075k0yfqzinv8qsb2m2smv1100--- PASS: TestClientFallsBackToClosures (2.92s)1101=== CONT TestReadProxyRootRedirectsToIndexHTML11022026/10/06 10:42:47 INFO Received push request method=POST path=/api/pushes11032026/10/06 10:42:47 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11042026/10/06 10:42:47 INFO Uploading qrb0ccmvd5rk6h32hh4bj5b55jd8m05p-pinned-file.txt (128B)11052026/10/06 10:42:47 WARN Failed to register uploaded object key=qrb0ccmvd5rk6h32hh4bj5b55jd8m05p.ls error="server returned 404: 404 page not found\n"11062026/10/06 10:42:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11072026/10/06 10:42:47 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"11082026/10/06 10:42:47 INFO Signed narinfos id=1 count=111092026/10/06 10:42:47 INFO Uploading 1 narinfos11102026/10/06 10:42:47 INFO Received complete push request method=POST path=/api/pushes/1/complete11112026/10/06 10:42:47 WARN Failed to register uploaded object key=qrb0ccmvd5rk6h32hh4bj5b55jd8m05p.narinfo error="server returned 404: 404 page not found\n"1112--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (3.76s)1113=== CONT TestReadProxyConditionalGet11142026/10/06 10:42:47 INFO Upload complete. (131ms)11152026/10/06 10:42:47 INFO Received push request method=POST path=/api/pushes11162026/10/06 10:42:47 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11172026/10/06 10:42:47 INFO Uploading zvli4kapw8zjxpd2agxgbx400qayanc9-unpinned-file.txt (128B)11182026/10/06 10:42:47 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"11192026/10/06 10:42:47 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11202026/10/06 10:42:47 INFO Signed narinfos id=2 count=111212026/10/06 10:42:47 INFO Uploading 1 narinfos11222026/10/06 10:42:47 WARN Failed to register uploaded object key=zvli4kapw8zjxpd2agxgbx400qayanc9.ls error="server returned 404: 404 page not found\n"11232026/10/06 10:42:47 INFO Received complete push request method=POST path=/api/pushes/2/complete11242026/10/06 10:42:47 WARN Failed to register uploaded object key=zvli4kapw8zjxpd2agxgbx400qayanc9.narinfo error="server returned 404: 404 page not found\n"11252026/10/06 10:42:47 INFO Upload complete. (75ms)11262026/10/06 10:42:47 INFO Starting cleanup of old closures method=DELETE path=/api/closures11272026/10/06 10:42:47 INFO Garbage collection started11282026/10/06 10:42:47 INFO Aborted multipart uploads count=0 kept=011292026/10/06 10:42:47 WARN Force mode enabled - objects will be deleted immediately without grace period11302026/10/06 10:42:47 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=011312026/10/06 10:42:47 INFO Received push request method=POST path=/api/pushes11322026/10/06 10:42:47 INFO Vacuumed table table=pending_closures11332026/10/06 10:42:47 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11342026/10/06 10:42:47 INFO Uploading w72y834sdcqvik5yqnq9hh9dryfdki0m-a (248B)11352026/10/06 10:42:47 INFO Uploading wxl449v3giskqx0kwxjgshjfxpd0dvzq-shared-dep (136B)11362026/10/06 10:42:47 INFO Vacuumed table table=pending_objects11372026/10/06 10:42:47 INFO Vacuumed table table=multipart_uploads11382026/10/06 10:42:47 WARN Failed to register uploaded object key=w72y834sdcqvik5yqnq9hh9dryfdki0m.ls error="server returned 404: 404 page not found\n"11392026/10/06 10:42:47 WARN Failed to register uploaded object key=wxl449v3giskqx0kwxjgshjfxpd0dvzq.ls error="server returned 404: 404 page not found\n"11402026/10/06 10:42:47 WARN Failed to register uploaded object key=v45fdn87q9lidh86q33xwj6p7qs9lz3j.ls error="server returned 404: 404 page not found\n"11412026/10/06 10:42:47 WARN Failed to register uploaded object key=nar/16j2ys67zgj69ihlh6cw6sld1z22s6a8g59zk9hlsvs5idg71b5n.nar.zst error="server returned 404: 404 page not found\n"11422026/10/06 10:42:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11432026/10/06 10:42:47 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11442026/10/06 10:42:47 INFO Signed narinfos id=1 count=311452026/10/06 10:42:47 INFO Uploading 3 narinfos11462026/10/06 10:42:47 INFO Vacuumed table table=closures11472026/10/06 10:42:47 WARN Failed to register uploaded object key=w72y834sdcqvik5yqnq9hh9dryfdki0m.narinfo error="server returned 404: 404 page not found\n"11482026/10/06 10:42:47 INFO Received complete push request method=POST path=/api/pushes/1/complete11492026/10/06 10:42:47 WARN Failed to register uploaded object key=wxl449v3giskqx0kwxjgshjfxpd0dvzq.narinfo error="server returned 404: 404 page not found\n"11502026/10/06 10:42:47 WARN Failed to register uploaded object key=v45fdn87q9lidh86q33xwj6p7qs9lz3j.narinfo error="server returned 404: 404 page not found\n"11512026/10/06 10:42:47 INFO Vacuumed table table=objects11522026/10/06 10:42:47 INFO Upload complete. (124ms)1153=== NAME TestClientPushesUseOnePush1154 client_pushes_test.go:97: Retrieved narinfo from S3:1155 StorePath: /nix/var/nix/builds/nix-19021-1960143159/TestClientPushesUseOnePush2459690748/001/store/wxl449v3giskqx0kwxjgshjfxpd0dvzq-shared-dep1156 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1157 Compression: zstd1158 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821159 NarSize: 1361160 References: 1161 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1162 client_pushes_test.go:97: Retrieved narinfo from S3:1163 StorePath: /nix/var/nix/builds/nix-19021-1960143159/TestClientPushesUseOnePush2459690748/001/store/w72y834sdcqvik5yqnq9hh9dryfdki0m-a1164 URL: nar/16j2ys67zgj69ihlh6cw6sld1z22s6a8g59zk9hlsvs5idg71b5n.nar.zst1165 Compression: zstd1166 NarHash: sha256:16j2ys67zgj69ihlh6cw6sld1z22s6a8g59zk9hlsvs5idg71b5n1167 NarSize: 2481168 References: /nix/var/nix/builds/nix-19021-1960143159/TestClientPushesUseOnePush2459690748/001/store/wxl449v3giskqx0kwxjgshjfxpd0dvzq-shared-dep1169 CA: text:sha256:05ssccs6pbh3hyza7vfwmb64l4zgxv2ln1zyn2733ipky6wjwbyz1170 client_pushes_test.go:97: Retrieved narinfo from S3:1171 StorePath: /nix/var/nix/builds/nix-19021-1960143159/TestClientPushesUseOnePush2459690748/001/store/v45fdn87q9lidh86q33xwj6p7qs9lz3j-b1172 URL: nar/16j2ys67zgj69ihlh6cw6sld1z22s6a8g59zk9hlsvs5idg71b5n.nar.zst1173 Compression: zstd1174 NarHash: sha256:16j2ys67zgj69ihlh6cw6sld1z22s6a8g59zk9hlsvs5idg71b5n1175 NarSize: 2481176 References: /nix/var/nix/builds/nix-19021-1960143159/TestClientPushesUseOnePush2459690748/001/store/wxl449v3giskqx0kwxjgshjfxpd0dvzq-shared-dep1177 CA: text:sha256:05ssccs6pbh3hyza7vfwmb64l4zgxv2ln1zyn2733ipky6wjwbyz1178--- PASS: TestClientPushesUseOnePush (3.28s)1179=== CONT TestReadProxyOutlastsServerWriteTimeout11802026/10/06 10:42:47 INFO Received push request method=POST path=/api/pushes11812026/10/06 10:42:47 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)11822026/10/06 10:42:47 INFO Uploading 24pg0xdihfzbhw95mg6q1294cyjmci4n-top (256B)11832026/10/06 10:42:47 INFO Uploading zfyxipm1mn6hpfq98q3afym3hpd6nz43-shared-dep (136B)11842026/10/06 10:42:47 WARN Failed to register uploaded object key=zfyxipm1mn6hpfq98q3afym3hpd6nz43.ls error="server returned 404: 404 page not found\n"11852026/10/06 10:42:47 WARN Failed to register uploaded object key=nar/0gk9mgy6pfj9ic3pyhvrf7q574hg68aqsj3m6a7x1grpsaqkzx55.nar.zst error="server returned 404: 404 page not found\n"11862026/10/06 10:42:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11872026/10/06 10:42:47 WARN Failed to register uploaded object key=24pg0xdihfzbhw95mg6q1294cyjmci4n.ls error="server returned 404: 404 page not found\n"11882026/10/06 10:42:47 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11892026/10/06 10:42:47 INFO Signed narinfos id=1 count=211902026/10/06 10:42:47 INFO Uploading 2 narinfos11912026/10/06 10:42:47 WARN Failed to register uploaded object key=24pg0xdihfzbhw95mg6q1294cyjmci4n.narinfo error="server returned 404: 404 page not found\n"11922026/10/06 10:42:47 INFO Received complete push request method=POST path=/api/pushes/1/complete11932026/10/06 10:42:47 WARN Failed to register uploaded object key=zfyxipm1mn6hpfq98q3afym3hpd6nz43.narinfo error="server returned 404: 404 page not found\n"11942026/10/06 10:42:47 INFO Upload complete. (88ms)1195=== NAME TestClientSharedPathCommittedMidPush1196 client_integration_test.go:680: Retrieved narinfo from S3:1197 StorePath: /nix/var/nix/builds/nix-19021-1960143159/TestClientSharedPathCommittedMidPush997206024/001/store/zfyxipm1mn6hpfq98q3afym3hpd6nz43-shared-dep1198 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1199 Compression: zstd1200 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821201 NarSize: 1361202 References: 1203 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1204 client_integration_test.go:680: Retrieved narinfo from S3:1205 StorePath: /nix/var/nix/builds/nix-19021-1960143159/TestClientSharedPathCommittedMidPush997206024/001/store/24pg0xdihfzbhw95mg6q1294cyjmci4n-top1206 URL: nar/0gk9mgy6pfj9ic3pyhvrf7q574hg68aqsj3m6a7x1grpsaqkzx55.nar.zst1207 Compression: zstd1208 NarHash: sha256:0gk9mgy6pfj9ic3pyhvrf7q574hg68aqsj3m6a7x1grpsaqkzx551209 NarSize: 2561210 References: /nix/var/nix/builds/nix-19021-1960143159/TestClientSharedPathCommittedMidPush997206024/001/store/zfyxipm1mn6hpfq98q3afym3hpd6nz43-shared-dep1211 CA: text:sha256:1hbgz3a5r864fijk36yf1xh87n93nx956ymgw1rypk4bjh091cv61212--- PASS: TestClientSharedPathCommittedMidPush (2.87s)1213=== CONT TestReadProxyHead1214=== NAME TestClientMultipleUploads1215 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-19021-1960143159/TestClientMultipleUploads2191020553/001/store/7zlqjsnl3hw9vlm3a6fpfqja3abwi28x-test-file-0.txt1216=== NAME TestClientWithDependencies1217 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-19021-1960143159/TestClientWithDependencies4107724164/001/store/9z685l1dghb56nsnjvv24lz9f5lyk8qr-test-script12182026/10/06 10:42:48 INFO Received uploads request method=POST path=/api/pending_closures1219 client_integration_test.go:615: Found 1 dependencies (including self)1220=== NAME TestClientMultipleUploads1221 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-19021-1960143159/TestClientMultipleUploads2191020553/001/store/rjh3s0p91f42l5kyliwi46m3py68wpkf-test-file-1.txt12222026/10/06 10:42:48 INFO Received uploads request method=POST path=/api/pending_closures1223 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-19021-1960143159/TestClientMultipleUploads2191020553/001/store/gkknvfb5kyp43y19c192z7sv3lfvsxnd-test-file-2.txt12242026/10/06 10:42:48 INFO Received cleanup request method=DELETE path=/api/pending_closures12252026/10/06 10:42:48 INFO Received push request method=POST path=/api/pushes12262026/10/06 10:42:48 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12272026/10/06 10:42:48 INFO Uploading 9z685l1dghb56nsnjvv24lz9f5lyk8qr-test-script (136B)12282026/10/06 10:42:48 WARN Failed to register uploaded object key=9z685l1dghb56nsnjvv24lz9f5lyk8qr.ls error="server returned 404: 404 page not found\n"12292026/10/06 10:42:48 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"12302026/10/06 10:42:48 WARN Failed to register uploaded object key=log/2a922jygdbhnday0lc1v1kxf752hnqkn-test-script.drv error="server returned 404: 404 page not found\n"12312026/10/06 10:42:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12322026/10/06 10:42:48 INFO Signed narinfos id=1 count=112332026/10/06 10:42:48 INFO Uploading 1 narinfos12342026/10/06 10:42:48 INFO Received complete push request method=POST path=/api/pushes/1/complete12352026/10/06 10:42:48 WARN Failed to register uploaded object key=9z685l1dghb56nsnjvv24lz9f5lyk8qr.narinfo error="server returned 404: 404 page not found\n"12362026/10/06 10:42:48 INFO Upload complete. (82ms)1237=== NAME TestClientWithDependencies1238 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-19021-1960143159/TestClientWithDependencies4107724164/001/store) requires matching store prefix12392026/10/06 10:42:48 INFO Received push request method=POST path=/api/pushes12402026/10/06 10:42:48 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)12412026/10/06 10:42:48 INFO Uploading rjh3s0p91f42l5kyliwi46m3py68wpkf-test-file-1.txt (160B)12422026/10/06 10:42:48 INFO Uploading gkknvfb5kyp43y19c192z7sv3lfvsxnd-test-file-2.txt (160B)12432026/10/06 10:42:48 INFO Uploading 7zlqjsnl3hw9vlm3a6fpfqja3abwi28x-test-file-0.txt (160B)12442026/10/06 10:42:48 WARN Failed to register uploaded object key=rjh3s0p91f42l5kyliwi46m3py68wpkf.ls error="server returned 404: 404 page not found\n"12452026/10/06 10:42:48 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"12462026/10/06 10:42:48 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"12472026/10/06 10:42:48 WARN Failed to register uploaded object key=gkknvfb5kyp43y19c192z7sv3lfvsxnd.ls error="server returned 404: 404 page not found\n"12482026/10/06 10:42:48 WARN Failed to register uploaded object key=7zlqjsnl3hw9vlm3a6fpfqja3abwi28x.ls error="server returned 404: 404 page not found\n"12492026/10/06 10:42:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12502026/10/06 10:42:48 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"12512026/10/06 10:42:48 INFO Signed narinfos id=1 count=312522026/10/06 10:42:48 INFO Uploading 3 narinfos1253--- PASS: TestClientWithDependencies (3.00s)1254=== CONT TestReadProxyInvalidPath12552026/10/06 10:42:48 WARN Failed to register uploaded object key=gkknvfb5kyp43y19c192z7sv3lfvsxnd.narinfo error="server returned 404: 404 page not found\n"12562026/10/06 10:42:48 WARN Failed to register uploaded object key=7zlqjsnl3hw9vlm3a6fpfqja3abwi28x.narinfo error="server returned 404: 404 page not found\n"12572026/10/06 10:42:48 INFO Received complete push request method=POST path=/api/pushes/1/complete12582026/10/06 10:42:48 WARN Failed to register uploaded object key=rjh3s0p91f42l5kyliwi46m3py68wpkf.narinfo error="server returned 404: 404 page not found\n"12592026/10/06 10:42:48 INFO Upload complete. (74ms)1260=== NAME TestClientMultipleUploads1261 client_integration_test.go:369: Uploaded 3 paths in 106.43575ms1262--- PASS: TestClientMultipleUploads (2.42s)1263=== CONT TestReadProxy4041264--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.11s)1265=== CONT TestReadProxyNarStreaming1266--- PASS: TestReadProxyConditionalGet (1.25s)1267=== CONT TestReadProxyContentNegotiation12682026/10/06 10:42:48 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01269=== NAME TestClientIntegration1270 client_integration_test.go:323: Objects in database after GC:1271 client_integration_test.go:323: Successfully deleted all objects with GC --force1272--- PASS: TestClientIntegration (5.46s)1273=== CONT TestReadProxyNarinfoAlreadyDecompressed1274--- PASS: TestReadProxyHead (1.30s)1275=== CONT TestReadProxyNarinfo1276--- PASS: TestReadProxy404 (1.29s)1277=== CONT TestIsValidCachePath1278=== RUN TestIsValidCachePath/narinfo1279=== PAUSE TestIsValidCachePath/narinfo1280=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1281=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1282=== RUN TestIsValidCachePath/nar_zst1283=== PAUSE TestIsValidCachePath/nar_zst1284=== RUN TestIsValidCachePath/nar_xz1285=== PAUSE TestIsValidCachePath/nar_xz1286=== RUN TestIsValidCachePath/nar_bz21287=== PAUSE TestIsValidCachePath/nar_bz21288=== RUN TestIsValidCachePath/nar_uncompressed1289=== PAUSE TestIsValidCachePath/nar_uncompressed1290=== RUN TestIsValidCachePath/ls1291=== PAUSE TestIsValidCachePath/ls1292=== RUN TestIsValidCachePath/log1293=== PAUSE TestIsValidCachePath/log1294=== RUN TestIsValidCachePath/realisation1295=== PAUSE TestIsValidCachePath/realisation1296=== RUN TestIsValidCachePath/nix-cache-info1297=== PAUSE TestIsValidCachePath/nix-cache-info1298=== RUN TestIsValidCachePath/index.html1299=== PAUSE TestIsValidCachePath/index.html1300=== RUN TestIsValidCachePath/traversal_parent1301=== PAUSE TestIsValidCachePath/traversal_parent1302=== RUN TestIsValidCachePath/traversal_in_middle1303=== PAUSE TestIsValidCachePath/traversal_in_middle1304=== RUN TestIsValidCachePath/invalid_char_e1305=== PAUSE TestIsValidCachePath/invalid_char_e1306=== RUN TestIsValidCachePath/invalid_char_u1307=== PAUSE TestIsValidCachePath/invalid_char_u1308=== RUN TestIsValidCachePath/random_path1309=== PAUSE TestIsValidCachePath/random_path1310=== RUN TestIsValidCachePath/empty1311=== PAUSE TestIsValidCachePath/empty1312=== RUN TestIsValidCachePath/leading_slash1313=== PAUSE TestIsValidCachePath/leading_slash1314=== RUN TestIsValidCachePath/wrong_extension1315=== PAUSE TestIsValidCachePath/wrong_extension1316=== RUN TestIsValidCachePath/short_hash1317=== PAUSE TestIsValidCachePath/short_hash1318=== CONT TestProxyHeadersOnlyTrustedOnSocket13192026/10/06 10:42:49 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=013202026/10/06 10:42:49 INFO Received create pin request method=POST path=/api/pins/myapp13212026/10/06 10:42:49 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-19021-1960143159/TestPinProtectsFromGC3138575685/001/store/qrb0ccmvd5rk6h32hh4bj5b55jd8m05p-pinned-file.txt narinfo_key=qrb0ccmvd5rk6h32hh4bj5b55jd8m05p.narinfo13222026/10/06 10:42:49 INFO Starting cleanup of old closures method=DELETE path=/api/closures13232026/10/06 10:42:49 INFO Garbage collection started13242026/10/06 10:42:49 INFO Aborted multipart uploads count=0 kept=013252026/10/06 10:42:49 WARN Force mode enabled - objects will be deleted immediately without grace period13262026/10/06 10:42: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=013272026/10/06 10:42:49 INFO Vacuumed table table=pending_closures13282026/10/06 10:42:49 INFO Vacuumed table table=pending_objects13292026/10/06 10:42:49 INFO Vacuumed table table=multipart_uploads13302026/10/06 10:42:49 INFO Vacuumed table table=closures13312026/10/06 10:42:49 INFO Vacuumed table table=objects1332--- PASS: TestReadProxyInvalidPath (1.50s)1333=== CONT TestParseSingleRange1334=== RUN TestParseSingleRange/none1335=== PAUSE TestParseSingleRange/none1336=== RUN TestParseSingleRange/unknown_unit1337=== PAUSE TestParseSingleRange/unknown_unit1338=== RUN TestParseSingleRange/multi-range_ignored1339=== PAUSE TestParseSingleRange/multi-range_ignored1340=== RUN TestParseSingleRange/malformed_no_dash1341=== PAUSE TestParseSingleRange/malformed_no_dash1342=== RUN TestParseSingleRange/malformed_both_empty1343=== PAUSE TestParseSingleRange/malformed_both_empty1344=== RUN TestParseSingleRange/malformed_end_before_start1345=== PAUSE TestParseSingleRange/malformed_end_before_start1346=== RUN TestParseSingleRange/closed1347=== PAUSE TestParseSingleRange/closed1348=== RUN TestParseSingleRange/open-ended1349=== PAUSE TestParseSingleRange/open-ended1350=== RUN TestParseSingleRange/end_clamped_to_size1351=== PAUSE TestParseSingleRange/end_clamped_to_size1352=== RUN TestParseSingleRange/suffix1353=== PAUSE TestParseSingleRange/suffix1354=== RUN TestParseSingleRange/suffix_exceeds_size1355=== PAUSE TestParseSingleRange/suffix_exceeds_size1356=== RUN TestParseSingleRange/single_byte1357=== PAUSE TestParseSingleRange/single_byte1358=== RUN TestParseSingleRange/start_past_EOF1359=== PAUSE TestParseSingleRange/start_past_EOF1360=== RUN TestParseSingleRange/start_far_past_EOF1361=== PAUSE TestParseSingleRange/start_far_past_EOF1362=== CONT TestPresentNotReportedWhileGCDeletesClosure1363--- PASS: TestReadProxyNarStreaming (1.47s)1364=== CONT TestPresentReportsOnlyClosureRoots1365--- PASS: TestReadProxyContentNegotiation (1.52s)1366=== CONT TestCreatePin_ReservedPins13672026/10/06 10:42:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52359/oidc1368--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.57s)1369=== CONT TestOrphanedObjectsGCStressTest13702026/10/06 10:42:50 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1371--- PASS: TestReadProxyNarinfo (1.42s)1372=== CONT TestOrphanedObjectsGC1373--- PASS: TestConnectWaitsForAPeerMigration (7.21s)1374=== CONT TestObjectStatsTrigger13752026/10/06 10:42:50 INFO Starting HTTP server address=/nix/var/nix/builds/nix-19021-1960143159/TestProxyHeadersOnlyTrustedOnSocket2588385610/001/proxy.sock13762026/10/06 10:42:50 INFO Starting HTTP server address=127.0.0.1:5237013772026/10/06 10:42:50 WARN mTLS auth: subject not in bound subjects subject="CN=someone"13782026/10/06 10:42:50 INFO Shutdown signal received, draining in-flight requests timeout=10s1379--- PASS: TestProxyHeadersOnlyTrustedOnSocket (1.29s)1380=== CONT TestService_ReadScope_PublicByDefault1381--- PASS: TestPresentReportsOnlyClosureRoots (1.38s)1382=== CONT TestClientErrorHandling1383=== RUN TestClientErrorHandling/InvalidStorePath1384=== PAUSE TestClientErrorHandling/InvalidStorePath1385=== RUN TestClientErrorHandling/InvalidAuthToken1386=== PAUSE TestClientErrorHandling/InvalidAuthToken1387=== RUN TestClientErrorHandling/ServerNotAvailable1388=== PAUSE TestClientErrorHandling/ServerNotAvailable1389=== CONT TestClientCADerivations13902026/10/06 10:42:51 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13912026/10/06 10:42:51 WARN Refused reserved pin name=worker-x86_64-linux13922026/10/06 10:42:51 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13932026/10/06 10:42:51 INFO Received create pin request method=POST path=/api/pins/my-app13942026/10/06 10:42:51 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1395--- PASS: TestCreatePin_ReservedPins (1.32s)1396=== CONT TestCacheStatsHandler1397--- PASS: TestPresentNotReportedWhileGCDeletesClosure (1.85s)1398=== CONT TestCacheConfigHandler1399=== RUN TestCacheConfigHandler/full_config,_no_issuer1400=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1401=== RUN TestCacheConfigHandler/no_cache_url_configured1402=== PAUSE TestCacheConfigHandler/no_cache_url_configured1403=== RUN TestCacheConfigHandler/no_signing_keys1404=== PAUSE TestCacheConfigHandler/no_signing_keys1405=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1406=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1407=== CONT TestService_ReadAuthMiddleware1408=== NAME TestPinProtectsFromGC1409 client_integration_test.go:840: Pin successfully protected closure from garbage collection1410--- PASS: TestPinProtectsFromGC (7.07s)1411=== CONT TestService_RequireScope_OIDC14122026/10/06 10:42:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52382/oidc1413--- PASS: TestObjectStatsTrigger (1.52s)1414=== CONT TestService_AuthMiddleware_OIDC14152026/10/06 10:42:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52390/oidc1416--- PASS: TestService_ReadScope_PublicByDefault (1.57s)1417=== CONT TestService_readinessHandler1418=== NAME TestOrphanedObjectsGC1419 orphaned_objects_gc_test.go:290: GC Test Summary:1420 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1421 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1422 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1423 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1424 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1425--- PASS: TestOrphanedObjectsGC (1.94s)1426=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1427--- PASS: TestReadProxyOutlastsServerWriteTimeout (5.38s)1428=== CONT TestMultipartCleanup1429--- PASS: TestService_ReadAuthMiddleware (1.78s)1430=== CONT TestServerTLSConfig1431=== RUN TestServerTLSConfig/no_client_CA1432=== PAUSE TestServerTLSConfig/no_client_CA1433=== RUN TestServerTLSConfig/missing_CA_file1434=== PAUSE TestServerTLSConfig/missing_CA_file1435=== RUN TestServerTLSConfig/not_a_PEM_file1436=== PAUSE TestServerTLSConfig/not_a_PEM_file1437=== CONT TestService_NativeMTLS1438=== NAME TestClientCADerivations1439 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-19021-1960143159/TestClientCADerivations3009994903/001/store/kagmsnbp5h9w9cgsjvg90yjh8v71ics1-ca-test1440 client_ca_test.go:139: Found 1 dependencies (including self)1441--- PASS: TestCacheStatsHandler (2.10s)1442=== CONT TestMetricsInventory14432026/10/06 10:42:53 INFO Received push request method=POST path=/api/pushes14442026/10/06 10:42:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14452026/10/06 10:42:53 INFO Uploading kagmsnbp5h9w9cgsjvg90yjh8v71ics1-ca-test (144B)14462026/10/06 10:42:53 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"14472026/10/06 10:42:53 WARN Failed to register uploaded object key=kagmsnbp5h9w9cgsjvg90yjh8v71ics1.ls error="server returned 404: 404 page not found\n"14482026/10/06 10:42:53 WARN Failed to register uploaded object key=log/k3gfsjqgxiif3kdahkl6bj4v54b4pmhx-ca-test.drv error="server returned 404: 404 page not found\n"14492026/10/06 10:42:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14502026/10/06 10:42:53 INFO Signed narinfos id=1 count=114512026/10/06 10:42:53 INFO Uploading 1 narinfos14522026/10/06 10:42:53 INFO Received complete push request method=POST path=/api/pushes/1/complete14532026/10/06 10:42:53 WARN Failed to register uploaded object key=kagmsnbp5h9w9cgsjvg90yjh8v71ics1.narinfo error="server returned 404: 404 page not found\n"14542026/10/06 10:42:53 INFO Upload complete. (207ms)1455=== NAME TestClientCADerivations1456 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-19021-1960143159/TestClientCADerivations3009994903/001/store/kagmsnbp5h9w9cgsjvg90yjh8v71ics1-ca-test1457 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1458 Compression: zstd1459 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1460 NarSize: 1441461 References: 1462 Deriver: /nix/var/nix/builds/nix-19021-1960143159/TestClientCADerivations3009994903/001/store/k3gfsjqgxiif3kdahkl6bj4v54b4pmhx-ca-test.drv1463 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1464 client_ca_test.go:185: Checking for realisation files in S3...1465 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1466 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1467=== RUN TestService_RequireScope_OIDC/builder_may_write1468=== PAUSE TestService_RequireScope_OIDC/builder_may_write1469=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1470=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1471=== RUN TestService_RequireScope_OIDC/ops_may_admin1472=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1473=== RUN TestService_RequireScope_OIDC/ops_may_not_write1474=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1475=== RUN TestService_RequireScope_OIDC/reader_may_not_write1476=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1477=== RUN TestService_RequireScope_OIDC/static_token_may_admin1478=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1479=== RUN TestService_RequireScope_OIDC/static_token_may_write1480=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1481=== RUN TestService_RequireScope_OIDC/reader_may_read1482=== PAUSE TestService_RequireScope_OIDC/reader_may_read1483=== RUN TestService_RequireScope_OIDC/writer_implies_read1484=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1485=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1486=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1487=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1488=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1489=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1490=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1491=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1492=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1493=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1494=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1495=== CONT TestNARDeduplicationMetadataUploadBug1496=== NAME TestClientCADerivations1497 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket59?endpoint=http://localhost:52111®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-19021-1960143159/TestClientCADerivations3009994903/001/store'1498 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11499--- PASS: TestClientCADerivations (2.65s)1500=== CONT TestCreatePendingClosureRejectsOversizedNAR15012026/10/06 10:42:54 INFO Received uploads request method=POST path=/api/pending_closures1502--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1503=== CONT TestCacheConfigHandlerMaxNarSize1504--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1505=== CONT TestGenerateLandingPage1506--- PASS: TestGenerateLandingPage (0.00s)1507=== CONT TestPush_CompleteCommitsEveryRoot15082026/10/06 10:42:54 INFO Aborted multipart uploads count=1 kept=015092026/10/06 10:42:54 INFO Received cleanup request method=DELETE path=/api/pending_closures15102026/10/06 10:42:54 INFO Aborted multipart uploads count=1 kept=01511--- PASS: TestPendingCleanupUsesOneCutoff (7.65s)1512=== CONT TestPush_RejectsBadRequests1513=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1514=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1515=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1516=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1517=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1518=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1519=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1520=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1521=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit15222026/10/06 10:42:54 WARN readiness check failed error="closed pool"1523--- PASS: TestService_readinessHandler (2.15s)1524=== CONT TestReadRedirectUsesPublicS3URL15252026/10/06 10:42:55 INFO Received uploads request method=POST path=/api/pending_closures1526--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (2.43s)1527=== CONT TestPush_SignsNarinfosOfItsPendingObjects15282026/10/06 10:42:55 INFO Received uploads request method=POST path=/api/pending_closures15292026/10/06 10:42:55 INFO Received cleanup request method=DELETE path=/api/pending_closures15302026/10/06 10:42:55 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket66/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""15312026/10/06 10:42:55 INFO Aborted multipart uploads count=0 kept=115322026/10/06 10:42:55 INFO Received cleanup request method=DELETE path=/api/pending_closures15332026/10/06 10:42:55 INFO Aborted multipart uploads count=1 kept=01534--- PASS: TestMultipartCleanup (2.60s)1535=== CONT TestPush_OverlappingRootsStoreOneRowPerKey15362026/10/06 10:42:55 WARN mTLS auth: subject not in bound subjects subject="CN=reader"15372026/10/06 10:42:55 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1538--- PASS: TestService_NativeMTLS (2.54s)1539=== CONT TestGCTaskStore_CompletedAllowsNewTask1540--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1541=== CONT TestService_Rustfstest1542--- PASS: TestMetricsInventory (2.67s)1543=== CONT TestService_healthCheckHandler15442026/10/06 10:42:57 INFO Received push request method=POST path=/api/pushes1545=== NAME TestNARDeduplicationMetadataUploadBug1546 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-19021-1960143159/TestNARDeduplicationMetadataUploadBug1375151126/001/store/8a5vwn0qxl1zm19fcglvm4qwfprz1m8d-file1.txt15472026/10/06 10:42:57 INFO Received complete push request method=POST path=/api/pushes/1/complete1548--- PASS: TestPush_CompleteCommitsEveryRoot (3.14s)1549=== CONT TestPresignedUploadRegisteredBeforeCommit15502026/10/06 10:42:57 INFO Received push request method=POST path=/api/pushes15512026/10/06 10:42:57 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15522026/10/06 10:42:57 INFO Uploading 8a5vwn0qxl1zm19fcglvm4qwfprz1m8d-file1.txt (160B)15532026/10/06 10:42:57 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"15542026/10/06 10:42:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15552026/10/06 10:42:57 INFO Signed narinfos id=1 count=115562026/10/06 10:42:57 WARN Failed to register uploaded object key=8a5vwn0qxl1zm19fcglvm4qwfprz1m8d.ls error="server returned 404: 404 page not found\n"15572026/10/06 10:42:57 INFO Uploading 1 narinfos15582026/10/06 10:42:57 INFO Received complete push request method=POST path=/api/pushes/1/complete15592026/10/06 10:42:57 WARN Failed to register uploaded object key=8a5vwn0qxl1zm19fcglvm4qwfprz1m8d.narinfo error="server returned 404: 404 page not found\n"15602026/10/06 10:42:57 INFO Upload complete. (184ms)1561=== NAME TestNARDeduplicationMetadataUploadBug1562 metadata_upload_test.go:54: Retrieved narinfo from S3:1563 StorePath: /nix/var/nix/builds/nix-19021-1960143159/TestNARDeduplicationMetadataUploadBug1375151126/001/store/8a5vwn0qxl1zm19fcglvm4qwfprz1m8d-file1.txt1564 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1565 Compression: zstd1566 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1567 NarSize: 1601568 References: 1569 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1570 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1571 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1572 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1573=== RUN TestPush_RejectsBadRequests/no_roots1574=== PAUSE TestPush_RejectsBadRequests/no_roots1575=== RUN TestPush_RejectsBadRequests/no_objects1576=== PAUSE TestPush_RejectsBadRequests/no_objects1577=== RUN TestPush_RejectsBadRequests/bad_root1578=== PAUSE TestPush_RejectsBadRequests/bad_root1579=== RUN TestPush_RejectsBadRequests/root_not_in_objects1580=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1581=== CONT TestGracefulShutdownDrainsInflight15822026/10/06 10:42:57 INFO Starting HTTP server address=127.0.0.1:5244615832026/10/06 10:42:57 INFO Shutdown signal received, draining in-flight requests timeout=10s1584--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1585=== CONT TestCompletedNarNotReofferedAcrossClosures1586=== NAME TestNARDeduplicationMetadataUploadBug1587 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-19021-1960143159/TestNARDeduplicationMetadataUploadBug1375151126/001/store/290ikhqligffajb0wrzi18nhpcsy2pvs-file2.txt1588=== NAME TestOrphanedObjectsGCStressTest1589 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1590 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion15912026/10/06 10:42:57 INFO Received push request method=POST path=/api/pushes15922026/10/06 10:42:57 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)15932026/10/06 10:42:57 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15942026/10/06 10:42:57 INFO Signed narinfos id=2 count=115952026/10/06 10:42:57 INFO Uploading 1 narinfos15962026/10/06 10:42:57 WARN Failed to register uploaded object key=290ikhqligffajb0wrzi18nhpcsy2pvs.ls error="server returned 404: 404 page not found\n"15972026/10/06 10:42:57 INFO Received complete push request method=POST path=/api/pushes/2/complete15982026/10/06 10:42:57 WARN Failed to register uploaded object key=290ikhqligffajb0wrzi18nhpcsy2pvs.narinfo error="server returned 404: 404 page not found\n"15992026/10/06 10:42:57 INFO Received push request method=POST path=/api/pushes16002026/10/06 10:42:57 INFO Upload complete. (182ms)1601=== NAME TestNARDeduplicationMetadataUploadBug1602 metadata_upload_test.go:76: Retrieved narinfo from S3:1603 StorePath: /nix/var/nix/builds/nix-19021-1960143159/TestNARDeduplicationMetadataUploadBug1375151126/001/store/290ikhqligffajb0wrzi18nhpcsy2pvs-file2.txt1604 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1605 Compression: zstd1606 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1607 NarSize: 1601608 References: 1609 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1610 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1611 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1612 {"version":1,"root":{"type":"regular","size":44}}16132026/10/06 10:42:57 INFO Received complete push request method=POST path=/api/pushes/1/complete16142026/10/06 10:42:57 INFO Received push request method=POST path=/api/pushes1615--- PASS: TestNARDeduplicationMetadataUploadBug (3.89s)1616=== CONT TestGCTaskStore_Fail1617--- PASS: TestGCTaskStore_Fail (0.00s)1618=== CONT TestCompleteMultipartUpload_ErrorButObjectExists16192026/10/06 10:42:57 INFO Aborted multipart uploads count=0 kept=016202026/10/06 10:42:57 WARN Force mode enabled - objects will be deleted immediately without grace period16212026/10/06 10:42:57 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=016222026/10/06 10:42:57 INFO Vacuumed table table=pending_closures16232026/10/06 10:42:58 INFO Vacuumed table table=pending_objects1624--- PASS: TestReadRedirectUsesPublicS3URL (3.35s)1625=== CONT TestGCTaskStore_PhaseUpdates1626--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1627=== CONT TestRedundantMultipartUpload16282026/10/06 10:42:58 INFO Vacuumed table table=multipart_uploads16292026/10/06 10:42:58 INFO Vacuumed table table=closures16302026/10/06 10:42:58 INFO Vacuumed table table=objects16312026/10/06 10:42:58 INFO Received complete push request method=POST path=/api/pushes/2/complete1632--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (3.73s)1633=== CONT TestReadProxyRangeRequest16342026/10/06 10:42:58 INFO Received push request method=POST path=/api/pushes16352026/10/06 10:42:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16362026/10/06 10:42:58 INFO Signed narinfos id=1 count=116372026/10/06 10:42:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16382026/10/06 10:42:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16392026/10/06 10:42:58 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"16402026/10/06 10:42:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16412026/10/06 10:42:58 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"16422026/10/06 10:42:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16432026/10/06 10:42:58 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=116442026/10/06 10:42:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16452026/10/06 10:42:58 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1646--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (3.35s)1647=== CONT TestService_AuthMiddleware_MTLSBoundSubjects16482026/10/06 10:42:58 INFO Received push request method=POST path=/api/pushes1649--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (3.24s)1650=== CONT TestGCTaskStore_GetEmpty1651--- PASS: TestGCTaskStore_GetEmpty (0.00s)1652=== CONT TestGCTaskStore_GetReturnsLatest1653--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1654=== CONT TestGCTaskStore_ConflictDifferentParams1655--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1656=== CONT TestGCTaskStore_DeduplicateSameParams1657--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1658=== CONT TestService_AuthMiddleware_MTLSProxyHeader1659--- PASS: TestService_Rustfstest (3.33s)1660=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16612026/10/06 10:42:59 INFO Received uploads request method=POST path=/1662--- PASS: TestService_healthCheckHandler (3.21s)1663=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16642026/10/06 10:42:59 INFO Received request for more parts method=POST path=/1665=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16662026/10/06 10:42:59 INFO Received complete multipart upload request method=POST path=/1667=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16682026/10/06 10:42:59 INFO Received uploads request method=POST path=/1669=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16702026/10/06 10:42:59 INFO Received complete multipart upload request method=POST path=/1671=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16722026/10/06 10:42:59 INFO Received request for more parts method=POST path=/1673=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16742026/10/06 10:42:59 INFO Received uploads request method=POST path=/1675--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1676 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1677 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1678 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1679 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1680=== CONT TestIsValidUploadKey/narinfo1681=== CONT TestPendingClosureWriteTimeout/empty1682=== CONT TestIsValidUploadKey/unknown_type1683=== CONT TestIsValidUploadKey/empty_key1684=== CONT TestIsValidUploadKey/absolute1685=== CONT TestIsValidUploadKey/traversal_nar1686=== CONT TestIsValidUploadKey/traversal1687=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1688=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1689=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1690=== CONT TestIsValidUploadKey/index.html1691=== CONT TestIsValidUploadKey/nix-cache-info1692=== CONT TestIsValidUploadKey/realisation_plus_in_output1693=== CONT TestIsValidUploadKey/realisation1694=== CONT TestIsValidUploadKey/build_log_equals1695=== CONT TestIsValidUploadKey/build_log_question_mark1696=== CONT TestIsValidUploadKey/build_log_plus_in_name1697=== CONT TestIsValidUploadKey/build_log_home-manager_file1698=== CONT TestIsValidUploadKey/build_log1699=== CONT TestIsValidUploadKey/listing1700=== CONT TestIsValidUploadKey/nar_plain1701=== CONT TestIsValidUploadKey/nar_xz1702=== CONT TestPendingClosureWriteTimeout/670k_objects1703=== CONT TestPendingClosureWriteTimeout/400_objects1704=== CONT TestIsValidUploadKey/nar_zst1705--- PASS: TestIsValidUploadKey (0.00s)1706 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1707 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1708 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1709 --- PASS: TestIsValidUploadKey/absolute (0.00s)1710 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1711 --- PASS: TestIsValidUploadKey/traversal (0.00s)1712 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1713 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1714 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1715 --- PASS: TestIsValidUploadKey/index.html (0.00s)1716 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1717 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1718 --- PASS: TestIsValidUploadKey/realisation (0.00s)1719 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1720 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1721 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1722 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1723 --- PASS: TestIsValidUploadKey/build_log (0.00s)1724 --- PASS: TestIsValidUploadKey/listing (0.00s)1725 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1726 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1727 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1728=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1729--- PASS: TestUploadHandlersRejectOversizedBody (0.06s)1730 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.31s)1731 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1732 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1733=== CONT TestProxyWriteTimeout/narinfo1734=== CONT TestProxyWriteTimeout/10_GiB_nar1735=== CONT TestProxyWriteTimeout/unknown_size1736=== CONT TestProxyWriteTimeout/1_GiB_nar1737--- PASS: TestProxyWriteTimeout (0.00s)1738 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1739 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1740 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1741 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1742=== CONT TestGCEndsOnShutdown/before_the_run17432026/10/06 10:43:00 INFO Received uploads request method=POST path=/api/pending_closures17442026/10/06 10:43:00 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst17452026/10/06 10:43:00 INFO Received uploads request method=POST path=/api/pending_closures1746--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.97s)1747=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark17482026/10/06 10:43:00 INFO Received uploads request method=POST path=/api/pending_closures17492026/10/06 10:43:00 INFO Received uploads request method=POST path=/api/pending_closures1750=== NAME TestOrphanedObjectsGCStressTest1751 orphaned_objects_gc_test.go:509: Stress test completed successfully:1752 orphaned_objects_gc_test.go:510: - Active objects preserved: 201753 orphaned_objects_gc_test.go:511: - Objects deleted: 2101754 orphaned_objects_gc_test.go:512: - Total GC'd: 2101755--- PASS: TestOrphanedObjectsGCStressTest (10.50s)1756=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete17572026/10/06 10:43:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17582026/10/06 10:43:01 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Y2MyZDc1MmMtNGU1Ni00NDU4LWIyMGMtZmQ5NGM0MjQ0ZmQ0LmZkODA1YTFmLTYwZTEtNDQ0Mi1hZjM3LTVmYjgyOTZhMDYxYngxNzkxMjgzMzgwODI0MTY5MDAw17592026/10/06 10:43:01 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Y2MyZDc1MmMtNGU1Ni00NDU4LWIyMGMtZmQ5NGM0MjQ0ZmQ0LmZkODA1YTFmLTYwZTEtNDQ0Mi1hZjM3LTVmYjgyOTZhMDYxYngxNzkxMjgzMzgwODI0MTY5MDAw parts=11760--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (3.27s)1761=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows17622026/10/06 10:43:01 INFO Received uploads request method=POST path=/api/pending_closures17632026/10/06 10:43:01 INFO Received uploads request method=POST path=/api/pending_closures1764--- PASS: TestReadProxyRangeRequest (3.45s)1765=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check17662026/10/06 10:43:01 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17672026/10/06 10:43:01 WARN mTLS auth: bound subjects configured but subject DN unavailable17682026/10/06 10:43:01 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1769--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (3.49s)1770=== CONT TestResolveDBConnectionString/flag_wins1771=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1772=== CONT TestResolveDBConnectionString/nothing_configured1773=== CONT TestResolveDBConnectionString/missing_file_is_an_error1774=== CONT TestResolveDBConnectionString/file_when_flag_empty1775=== CONT TestIsValidCachePath/narinfo1776=== CONT TestIsValidCachePath/index.html1777=== CONT TestIsValidCachePath/short_hash1778=== CONT TestIsValidCachePath/wrong_extension1779=== CONT TestIsValidCachePath/leading_slash1780=== CONT TestIsValidCachePath/empty1781=== CONT TestIsValidCachePath/random_path1782=== CONT TestIsValidCachePath/invalid_char_u1783=== CONT TestIsValidCachePath/invalid_char_e1784=== CONT TestIsValidCachePath/traversal_in_middle1785=== CONT TestIsValidCachePath/traversal_parent1786=== CONT TestIsValidCachePath/nar_uncompressed1787=== CONT TestIsValidCachePath/nix-cache-info1788=== CONT TestIsValidCachePath/realisation1789=== CONT TestIsValidCachePath/log1790=== CONT TestIsValidCachePath/ls1791=== CONT TestIsValidCachePath/nar_xz1792=== CONT TestIsValidCachePath/nar_bz21793=== CONT TestIsValidCachePath/nar_zst1794=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1795--- PASS: TestIsValidCachePath (0.00s)1796 --- PASS: TestIsValidCachePath/narinfo (0.00s)1797 --- PASS: TestIsValidCachePath/index.html (0.00s)1798 --- PASS: TestIsValidCachePath/short_hash (0.00s)1799 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1800 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1801 --- PASS: TestIsValidCachePath/empty (0.00s)1802 --- PASS: TestIsValidCachePath/random_path (0.00s)1803 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1804 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1805 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1806 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1807 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1808 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1809 --- PASS: TestIsValidCachePath/realisation (0.00s)1810 --- PASS: TestIsValidCachePath/log (0.00s)1811 --- PASS: TestIsValidCachePath/ls (0.00s)1812 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1813 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1814 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1815 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1816=== CONT TestParseSingleRange/none1817=== CONT TestParseSingleRange/open-ended1818=== CONT TestParseSingleRange/start_far_past_EOF1819=== CONT TestParseSingleRange/start_past_EOF1820=== CONT TestParseSingleRange/single_byte1821=== CONT TestParseSingleRange/suffix_exceeds_size1822=== CONT TestParseSingleRange/suffix1823=== CONT TestParseSingleRange/end_clamped_to_size1824=== CONT TestParseSingleRange/malformed_both_empty1825=== CONT TestParseSingleRange/closed1826=== CONT TestParseSingleRange/malformed_end_before_start1827=== CONT TestParseSingleRange/multi-range_ignored1828=== CONT TestParseSingleRange/malformed_no_dash1829=== CONT TestParseSingleRange/unknown_unit1830--- PASS: TestParseSingleRange (0.00s)1831 --- PASS: TestParseSingleRange/none (0.00s)1832 --- PASS: TestParseSingleRange/open-ended (0.00s)1833 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1834 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1835 --- PASS: TestParseSingleRange/single_byte (0.00s)1836 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1837 --- PASS: TestParseSingleRange/suffix (0.00s)1838 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1839 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1840 --- PASS: TestParseSingleRange/closed (0.00s)1841 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1842 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1843 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1844 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1845=== CONT TestClientErrorHandling/InvalidStorePath1846--- PASS: TestResolveDBConnectionString (0.03s)1847 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1848 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1849 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1850 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1851 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1852--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (3.16s)1853=== CONT TestClientErrorHandling/ServerNotAvailable18542026/10/06 10:43:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18552026/10/06 10:43:02 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=Y2MyZDc1MmMtNGU1Ni00NDU4LWIyMGMtZmQ5NGM0MjQ0ZmQ0LjNiYWE3Y2E3LTk2ZjYtNDBmZi05ZGM1LWIzZjM3N2Q4NjQ2MHgxNzkxMjgzMzgwNDgxNjQ2MDAw parts=1218562026/10/06 10:43:02 INFO Received uploads request method=POST path=/api/pending_closures1857--- PASS: TestCompletedNarNotReofferedAcrossClosures (5.13s)1858=== CONT TestClientErrorHandling/InvalidAuthToken18592026/10/06 10:43: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/present1860=== CONT TestCacheConfigHandler/full_config,_no_issuer1861=== CONT TestCacheConfigHandler/no_signing_keys1862=== CONT TestCacheConfigHandler/no_cache_url_configured1863=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1864--- PASS: TestCacheConfigHandler (0.00s)1865 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1866 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1867 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1868 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1869=== CONT TestServerTLSConfig/no_client_CA1870=== CONT TestServerTLSConfig/not_a_PEM_file1871=== CONT TestServerTLSConfig/missing_CA_file1872--- PASS: TestServerTLSConfig (0.00s)1873 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1874 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.02s)1875 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1876=== CONT TestService_RequireScope_OIDC/builder_may_write1877=== CONT TestService_RequireScope_OIDC/reader_may_read1878=== CONT TestService_RequireScope_OIDC/static_token_may_write1879=== CONT TestService_RequireScope_OIDC/static_token_may_admin1880=== CONT TestService_RequireScope_OIDC/reader_may_not_write1881=== CONT TestService_RequireScope_OIDC/ops_may_not_write1882=== CONT TestService_RequireScope_OIDC/ops_may_admin1883=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1884=== CONT TestService_RequireScope_OIDC/writer_implies_read1885=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18862026/10/06 10:43:02 WARN Authentication failed token_preview=wrong token_length=5 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1887=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1888=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1889=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1890=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1891=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1892--- PASS: TestService_RequireScope_OIDC (2.24s)1893 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1894 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1895 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1896 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1897 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1898 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1899 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1900 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1901 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1902 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1903 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1904 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1905 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1906 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1907=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19082026/10/06 10:43: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]1909=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1910=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19112026/10/06 10:43:02 WARN Authentication failed token_preview=eyJhbGciOi...p5Dc_6534g token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1912=== CONT TestPush_RejectsBadRequests/no_roots19132026/10/06 10:43:02 INFO Received push request method=POST path=/api/pushes1914=== CONT TestPush_RejectsBadRequests/root_not_in_objects19152026/10/06 10:43:02 INFO Received push request method=POST path=/api/pushes1916=== CONT TestPush_RejectsBadRequests/bad_root19172026/10/06 10:43:02 INFO Received push request method=POST path=/api/pushes1918=== CONT TestPush_RejectsBadRequests/no_objects19192026/10/06 10:43:02 INFO Received push request method=POST path=/api/pushes1920--- PASS: TestPush_RejectsBadRequests (3.07s)1921 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1922 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1923 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1924 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1925--- PASS: TestService_AuthMiddleware_OIDC (2.08s)1926 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1927 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1928 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1929 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)19302026/10/06 10:43:02 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=187.732404ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19312026/10/06 10:43:03 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=439.72144ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19322026/10/06 10:43:03 INFO Received uploads request method=POST path=/api/pending_closures19332026/10/06 10:43:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19342026/10/06 10:43:03 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=Y2MyZDc1MmMtNGU1Ni00NDU4LWIyMGMtZmQ5NGM0MjQ0ZmQ0LmJkZDA2YmIwLTdkYjYtNGU1My04NjliLTU3ZGUxNTExOTA4M3gxNzkxMjgzMzgxMjE4MTI2MDAw parts=1219352026/10/06 10:43:03 INFO Received uploads request method=POST path=/api/pending_closures19362026/10/06 10:43:03 INFO Received uploads request method=POST path=/api/pending_closures19372026/10/06 10:43:03 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=747.574816ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19382026/10/06 10:43:03 INFO Aborted multipart uploads count=0 kept=019392026/10/06 10:43:03 WARN Force mode enabled - objects will be deleted immediately without grace period19402026-10-06 10:43:03.506 UTC [19514] ERROR: canceling statement due to user request19412026-10-06 10:43:03.506 UTC [19514] STATEMENT: -- name: MarkStaleObjects :execrows1942 WITH RECURSIVE ct AS (1943 SELECT timezone('UTC', now()) AS now1944 ),1945 closure_reach AS (1946 -- Start with all closure keys1947 SELECT o.key, o.refs1948 FROM objects o1949 INNER JOIN closures c ON o.key = c.key1950 UNION1951 -- Recursively add all referenced objects1952 SELECT o.key, o.refs1953 FROM objects o1954 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1955 ),1956 reachable_objects AS (1957 SELECT DISTINCT key FROM closure_reach1958 ),1959 stale_objects AS (1960 SELECT o.key1961 FROM objects AS o, ct1962 WHERE1963 NOT EXISTS (1964 SELECT 11965 FROM reachable_objects ro1966 WHERE ro.key = o.key1967 )1968 AND NOT EXISTS (1969 SELECT 11970 FROM pending_objects AS po1971 WHERE po.key = o.key1972 )1973 AND o.deleted_at IS NULL -- Only mark fresh objects1974 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure1975 FOR UPDATE1976 )1977 UPDATE objects1978 SET1979 deleted_at = ct.now,1980 first_deleted_at = COALESCE(first_deleted_at, ct.now)1981 FROM stale_objects, ct1982 WHERE objects.key = stale_objects.key1983 1984--- PASS: TestPendingClosureWriteTimeout (0.00s)1985 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1986 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1987 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1988 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (4.23s)19892026/10/06 10:43:04 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.489284856s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19902026/10/06 10:43:04 INFO Aborted multipart uploads count=0 kept=019912026/10/06 10:43:04 WARN Force mode enabled - objects will be deleted immediately without grace period19922026/10/06 10:43:04 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:52111/bucket88/?delete=\": context canceled"1993--- PASS: TestGCEndsOnShutdown (0.00s)1994 --- PASS: TestGCEndsOnShutdown/before_the_run (3.10s)1995 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (3.37s)1996 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (3.34s)19972026/10/06 10:43:04 INFO Received uploads request method=POST path=/api/pending_closures19982026/10/06 10:43:04 INFO Aborted multipart uploads count=0 kept=019992026/10/06 10:43:04 WARN Force mode enabled - objects will be deleted immediately without grace period20002026/10/06 10:43:04 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=020012026/10/06 10:43:04 INFO Vacuumed table table=pending_closures20022026/10/06 10:43:04 INFO Vacuumed table table=pending_objects20032026/10/06 10:43:04 INFO Vacuumed table table=multipart_uploads20042026/10/06 10:43:04 INFO Vacuumed table table=closures20052026/10/06 10:43:04 INFO Vacuumed table table=objects20062026/10/06 10:43:04 INFO Received uploads request method=POST path=/api/pending_closures20072026/10/06 10:43:04 INFO Aborted multipart uploads count=0 kept=020082026/10/06 10:43:04 WARN Force mode enabled - objects will be deleted immediately without grace period20092026/10/06 10:43:04 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=020102026/10/06 10:43:04 INFO Vacuumed table table=pending_closures20112026/10/06 10:43:04 INFO Vacuumed table table=pending_objects20122026/10/06 10:43:04 INFO Vacuumed table table=multipart_uploads20132026/10/06 10:43:04 INFO Vacuumed table table=closures20142026/10/06 10:43:04 INFO Vacuumed table table=objects2015--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2016 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (3.52s)2017 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (3.39s)20182026/10/06 10:43:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20192026/10/06 10:43:05 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=Y2MyZDc1MmMtNGU1Ni00NDU4LWIyMGMtZmQ5NGM0MjQ0ZmQ0LmZiNTI2NGU2LWYzZTEtNDEwYi1hMmY2LTk0MDk0MDEwZmEzZHgxNzkxMjgzMzgzMzYwMTA2MDAw error="Get \"http://127.0.0.1:1/bucket81/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"20202026/10/06 10:43:05 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=Y2MyZDc1MmMtNGU1Ni00NDU4LWIyMGMtZmQ5NGM0MjQ0ZmQ0Ljc2NDQzNDE5LTcxNjEtNGMxMC04ZTRlLWJiNzhkZTY4ZDY5Y3gxNzkxMjgzMzgzMzA3NTY1MDAw parts=1220212026/10/06 10:43:05 INFO Received cleanup request method=DELETE path=/api/pending_closures20222026/10/06 10:43:05 INFO Aborted multipart uploads count=1 kept=02023--- PASS: TestRedundantMultipartUpload (7.08s)20242026/10/06 10:43:05 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20252026/10/06 10:43:05 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20262026/10/06 10:43: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-config20272026/10/06 10:43:05 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=216.78569ms 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:43:06 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=408.052403ms 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:43:06 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=812.767678ms 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:43:07 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.45771411s 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:43: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"20322026/10/06 10:43: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-config20332026/10/06 10:43:08 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=188.393376ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20342026/10/06 10:43:09 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=368.770273ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20352026/10/06 10:43:09 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=822.345888ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20362026/10/06 10:43:10 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.536681163s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20372026/10/06 10:43: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_closures20382026/10/06 10:43:11 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=185.623382ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20392026/10/06 10:43:12 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=400.140939ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20402026/10/06 10:43:12 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=869.489203ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20412026/10/06 10:43:13 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.619319648s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2042--- PASS: TestClientErrorHandling (0.00s)2043 --- PASS: TestClientErrorHandling/InvalidStorePath (3.22s)2044 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.90s)2045 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.73s)2046PASS20472026-10-06 10:43:15.140 UTC [19058] LOG: received smart shutdown request20482026-10-06 10:43:15.140 UTC [19058] LOG: background worker "logical replication launcher" (PID 19069) exited with exit code 120492026-10-06 10:43:15.143 UTC [19063] LOG: shutting down20502026-10-06 10:43:15.143 UTC [19063] LOG: checkpoint starting: shutdown immediate20512026-10-06 10:43:16.411 UTC [19063] LOG: checkpoint complete: wrote 12580 buffers (76.8%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 27 recycled; write=0.696 s, sync=0.532 s, total=1.268 s; sync files=31336, longest=0.001 s, average=0.001 s; distance=440410 kB, estimate=440410 kB; lsn=0/1C5A3920, redo lsn=0/1C5A392020522026-10-06 10:43:16.417 UTC [19058] LOG: database system is shut down2053Running OIDC tests...2054=== RUN TestAudienceForIssuer2055=== PAUSE TestAudienceForIssuer2056=== RUN TestGlobMatch2057=== PAUSE TestGlobMatch2058=== RUN TestValidateToken_ValidToken2059=== PAUSE TestValidateToken_ValidToken2060=== RUN TestValidateToken_WrongAudience2061=== PAUSE TestValidateToken_WrongAudience2062=== RUN TestValidateToken_Expired2063=== PAUSE TestValidateToken_Expired2064=== RUN TestValidateToken_BoundClaimsMismatch2065=== PAUSE TestValidateToken_BoundClaimsMismatch2066=== RUN TestValidateToken_BoundSubjectMismatch2067=== PAUSE TestValidateToken_BoundSubjectMismatch2068=== RUN TestValidateToken_MultipleProviders2069=== PAUSE TestValidateToken_MultipleProviders2070=== RUN TestValidateToken_NoMatchingProvider2071=== PAUSE TestValidateToken_NoMatchingProvider2072=== RUN TestValidateToken_KubernetesServiceAccount2073=== PAUSE TestValidateToken_KubernetesServiceAccount2074=== RUN TestNewValidator_KubernetesRequiresCA2075=== PAUSE TestNewValidator_KubernetesRequiresCA2076=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2077=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2078=== RUN TestPins_ReservedForMatchingRule2079=== PAUSE TestPins_ReservedForMatchingRule2080=== RUN TestPins_TopLevelShorthand2081=== PAUSE TestPins_TopLevelShorthand2082=== RUN TestPins_ConfigValidation2083=== PAUSE TestPins_ConfigValidation2084=== RUN TestScopes_LegacyProviderDefaultsToWrite2085=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2086=== RUN TestScopes_Rules2087=== PAUSE TestScopes_Rules2088=== RUN TestScopes_ConfigValidation2089=== PAUSE TestScopes_ConfigValidation2090=== CONT TestAudienceForIssuer2091--- PASS: TestAudienceForIssuer (0.00s)2092=== CONT TestScopes_ConfigValidation2093=== CONT TestValidateToken_BoundClaimsMismatch2094=== CONT TestValidateToken_KubernetesServiceAccount2095=== CONT TestValidateToken_WrongAudience2096=== CONT TestValidateToken_ValidToken2097=== CONT TestGlobMatch2098=== RUN TestGlobMatch/foo_foo2099=== CONT TestValidateToken_BoundSubjectMismatch2100=== CONT TestValidateToken_Expired2101--- PASS: TestScopes_ConfigValidation (0.00s)2102=== CONT TestScopes_Rules2103=== CONT TestValidateToken_NoMatchingProvider2104=== CONT TestPins_TopLevelShorthand2105=== PAUSE TestGlobMatch/foo_foo2106=== RUN TestGlobMatch/foo_bar2107=== PAUSE TestGlobMatch/foo_bar2108=== RUN TestGlobMatch/*_2109=== PAUSE TestGlobMatch/*_2110=== RUN TestGlobMatch/*_anything2111=== PAUSE TestGlobMatch/*_anything2112=== RUN TestGlobMatch/foo*_foo2113=== PAUSE TestGlobMatch/foo*_foo2114=== RUN TestGlobMatch/foo*_foobar2115=== PAUSE TestGlobMatch/foo*_foobar2116=== RUN TestGlobMatch/foo*_bar2117=== PAUSE TestGlobMatch/foo*_bar2118=== RUN TestGlobMatch/*bar_bar2119=== PAUSE TestGlobMatch/*bar_bar2120=== RUN TestGlobMatch/*bar_foobar2121=== PAUSE TestGlobMatch/*bar_foobar2122=== RUN TestGlobMatch/*bar_foo2123=== PAUSE TestGlobMatch/*bar_foo2124=== RUN TestGlobMatch/foo*bar_foobar2125=== PAUSE TestGlobMatch/foo*bar_foobar2126=== RUN TestGlobMatch/foo*bar_foo123bar2127=== PAUSE TestGlobMatch/foo*bar_foo123bar2128=== RUN TestGlobMatch/foo*bar_foobarbaz2129=== PAUSE TestGlobMatch/foo*bar_foobarbaz2130=== RUN TestGlobMatch/*/*_foo/bar2131=== PAUSE TestGlobMatch/*/*_foo/bar2132=== RUN TestGlobMatch/*/*_foo2133=== PAUSE TestGlobMatch/*/*_foo2134=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2135=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2136=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02137=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02138=== RUN TestGlobMatch/refs/*/main_refs/heads/main2139=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2140=== RUN TestGlobMatch/fo?_foo2141=== PAUSE TestGlobMatch/fo?_foo2142=== RUN TestGlobMatch/fo?_fo2143=== PAUSE TestGlobMatch/fo?_fo2144=== RUN TestGlobMatch/fo?_fooo2145=== PAUSE TestGlobMatch/fo?_fooo2146=== RUN TestGlobMatch/?oo_foo2147=== PAUSE TestGlobMatch/?oo_foo2148=== RUN TestGlobMatch/?oo_boo2149=== PAUSE TestGlobMatch/?oo_boo2150=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2151=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2152=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2153=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2154=== CONT TestScopes_LegacyProviderDefaultsToWrite21552026/10/06 10:43:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52570/oidc2156--- PASS: TestValidateToken_Expired (0.02s)2157=== CONT TestPins_ConfigValidation2158--- PASS: TestPins_ConfigValidation (0.00s)2159=== CONT TestValidateToken_KubernetesIssuerFromOwnToken21602026/10/06 10:43:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52573/oidc2161--- PASS: TestPins_TopLevelShorthand (0.03s)2162=== CONT TestPins_ReservedForMatchingRule21632026/10/06 10:43:17 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232164--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.03s)2165=== CONT TestNewValidator_KubernetesRequiresCA21662026/10/06 10:43:17 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:5257721672026/10/06 10:43:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52579/oidc2168--- PASS: TestValidateToken_KubernetesServiceAccount (0.07s)2169=== CONT TestValidateToken_MultipleProviders21702026/10/06 10:43:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52582/oidc2171--- PASS: TestScopes_Rules (0.07s)2172=== CONT TestGlobMatch/foo_foo2173=== CONT TestGlobMatch/*/*_foo/bar2174=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2175=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2176=== CONT TestGlobMatch/?oo_boo2177=== CONT TestGlobMatch/?oo_foo2178=== CONT TestGlobMatch/fo?_fooo2179=== CONT TestGlobMatch/fo?_fo2180=== CONT TestGlobMatch/fo?_foo2181=== CONT TestGlobMatch/refs/*/main_refs/heads/main2182=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02183=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2184=== CONT TestGlobMatch/*/*_foo2185=== CONT TestGlobMatch/*bar_bar2186=== CONT TestGlobMatch/foo*bar_foobarbaz2187=== CONT TestGlobMatch/foo*bar_foo123bar2188=== CONT TestGlobMatch/foo*bar_foobar2189=== CONT TestGlobMatch/*bar_foo2190=== CONT TestGlobMatch/*bar_foobar2191=== CONT TestGlobMatch/foo*_foo2192=== CONT TestGlobMatch/foo*_bar2193=== CONT TestGlobMatch/foo*_foobar2194=== CONT TestGlobMatch/*_2195=== CONT TestGlobMatch/*_anything2196=== CONT TestGlobMatch/foo_bar2197--- PASS: TestGlobMatch (0.01s)2198 --- PASS: TestGlobMatch/foo_foo (0.00s)2199 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2200 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2201 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2202 --- PASS: TestGlobMatch/?oo_boo (0.00s)2203 --- PASS: TestGlobMatch/?oo_foo (0.00s)2204 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2205 --- PASS: TestGlobMatch/fo?_fo (0.00s)2206 --- PASS: TestGlobMatch/fo?_foo (0.00s)2207 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2208 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2209 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2210 --- PASS: TestGlobMatch/*/*_foo (0.00s)2211 --- PASS: TestGlobMatch/*bar_bar (0.00s)2212 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2213 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2214 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2215 --- PASS: TestGlobMatch/*bar_foo (0.00s)2216 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2217 --- PASS: TestGlobMatch/foo*_foo (0.00s)2218 --- PASS: TestGlobMatch/foo*_bar (0.00s)2219 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2220 --- PASS: TestGlobMatch/*_ (0.00s)2221 --- PASS: TestGlobMatch/*_anything (0.00s)2222 --- PASS: TestGlobMatch/foo_bar (0.00s)2223--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.07s)22242026/10/06 10:43:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52584/oidc2225--- PASS: TestValidateToken_BoundClaimsMismatch (0.09s)22262026/10/06 10:43:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52586/oidc2227--- PASS: TestValidateToken_WrongAudience (0.11s)22282026/10/06 10:43:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52588/oidc2229--- PASS: TestValidateToken_BoundSubjectMismatch (0.11s)22302026/10/06 10:43:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52590/oidc22312026/10/06 10:43:17 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:52572/oidc2232--- PASS: TestValidateToken_ValidToken (0.11s)2233--- PASS: TestValidateToken_NoMatchingProvider (0.11s)22342026/10/06 10:43:17 http: TLS handshake error from 127.0.0.1:52595: read tcp 127.0.0.1:52594->127.0.0.1:52595: use of closed network connection2235--- PASS: TestNewValidator_KubernetesRequiresCA (0.06s)22362026/10/06 10:43:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52596/oidc2237--- PASS: TestPins_ReservedForMatchingRule (0.10s)22382026/10/06 10:43:18 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:52598/oidc22392026/10/06 10:43:18 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:52599/oidc2240--- PASS: TestValidateToken_MultipleProviders (0.22s)2241PASS2242Running hook tests...2243=== RUN TestSendPathsEmpty2244=== PAUSE TestSendPathsEmpty2245=== RUN TestQueueEnqueueAndFetch2246=== PAUSE TestQueueEnqueueAndFetch2247=== RUN TestQueueDeduplication2248=== PAUSE TestQueueDeduplication2249=== RUN TestQueueRemove2250=== PAUSE TestQueueRemove2251=== RUN TestQueueFetchBatchLimit2252=== PAUSE TestQueueFetchBatchLimit2253=== RUN TestQueueRetryMovesToBack2254=== PAUSE TestQueueRetryMovesToBack2255=== RUN TestQueueFetchRemoveLifecycle2256=== PAUSE TestQueueFetchRemoveLifecycle2257=== RUN TestQueueConcurrentWriters2258=== PAUSE TestQueueConcurrentWriters2259=== RUN TestQueueRemoveLargeClosure2260=== PAUSE TestQueueRemoveLargeClosure2261=== RUN TestServerClientIntegration2262=== PAUSE TestServerClientIntegration2263=== RUN TestServerQueueError2264=== PAUSE TestServerQueueError2265=== RUN TestGetListenerSocketActivation2266 server_test.go:210: === RUN TestGetListenerSocketActivation2267 --- PASS: TestGetListenerSocketActivation (0.00s)2268 PASS2269 2270--- PASS: TestGetListenerSocketActivation (0.01s)2271=== RUN TestDrainIsolatesPoisonPath2272=== PAUSE TestDrainIsolatesPoisonPath2273=== RUN TestRunNotBlockedByPoisonHead2274=== PAUSE TestRunNotBlockedByPoisonHead2275=== RUN TestDrainGivesUpWhenServerDown2276=== PAUSE TestDrainGivesUpWhenServerDown2277=== RUN TestFailedPathPrunedByLaterClosure2278=== PAUSE TestFailedPathPrunedByLaterClosure2279=== RUN TestWorkerUploadsAndRemoves2280=== PAUSE TestWorkerUploadsAndRemoves2281=== RUN TestWorkerSkipsGCdPaths2282=== PAUSE TestWorkerSkipsGCdPaths2283=== RUN TestWorkerPrunesClosureDeps2284=== PAUSE TestWorkerPrunesClosureDeps2285=== RUN TestDrainTimeout2286=== PAUSE TestDrainTimeout2287=== CONT TestSendPathsEmpty2288--- PASS: TestSendPathsEmpty (0.00s)2289=== CONT TestServerClientIntegration2290=== CONT TestServerQueueError2291=== CONT TestWorkerUploadsAndRemoves2292=== CONT TestDrainTimeout2293=== CONT TestWorkerPrunesClosureDeps2294=== CONT TestWorkerSkipsGCdPaths2295=== CONT TestDrainGivesUpWhenServerDown2296=== CONT TestFailedPathPrunedByLaterClosure2297=== CONT TestDrainIsolatesPoisonPath2298=== CONT TestQueueRetryMovesToBack22992026/10/06 10:43:18 ERROR Failed to queue paths error="permission denied" count=12300--- PASS: TestServerQueueError (0.00s)2301=== CONT TestQueueRemoveLargeClosure2302--- PASS: TestServerClientIntegration (0.00s)2303=== CONT TestQueueConcurrentWriters23042026/10/06 10:43:18 INFO Upload queue status pending=223052026/10/06 10:43:18 INFO Upload queue status pending=223062026/10/06 10:43:18 INFO Uploading batch count=123072026/10/06 10:43:18 INFO Upload queue status pending=223082026/10/06 10:43:18 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-19021-1960143159/TestWorkerSkipsGCdPaths2820018570/002/nonexistent23092026/10/06 10:43:18 INFO Uploading batch count=223102026/10/06 10:43:18 INFO Uploading batch count=423112026/10/06 10:43:18 ERROR Upload failed error="upload failed" count=423122026/10/06 10:43:18 INFO Uploading batch count=123132026/10/06 10:43:18 INFO Uploading batch count=223142026/10/06 10:43:18 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-19021-1960143159/TestDrainIsolatesPoisonPath4159607114/002/bbb23152026/10/06 10:43:18 INFO Uploading batch count=223162026/10/06 10:43:18 ERROR Upload failed error="upload failed" count=223172026/10/06 10:43:18 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-19021-1960143159/TestDrainGivesUpWhenServerDown107553177/002/a23182026/10/06 10:43:18 INFO Uploading batch count=123192026/10/06 10:43:18 ERROR Upload failed error="upload failed" count=123202026/10/06 10:43:18 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-19021-1960143159/TestDrainGivesUpWhenServerDown107553177/002/b23212026/10/06 10:43:18 INFO Uploading batch count=123222026/10/06 10:43:18 ERROR Upload failed error="upload failed" count=123232026/10/06 10:43:18 INFO Uploading batch count=223242026/10/06 10:43:18 ERROR Upload failed error="upload failed" count=223252026/10/06 10:43:18 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-19021-1960143159/TestDrainGivesUpWhenServerDown107553177/002/c23262026/10/06 10:43:18 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-19021-1960143159/TestDrainGivesUpWhenServerDown107553177/002/d23272026/10/06 10:43:18 INFO Uploading batch count=123282026/10/06 10:43:18 ERROR Upload failed error="upload failed" count=12329--- PASS: TestQueueRetryMovesToBack (0.01s)2330=== CONT TestQueueFetchRemoveLifecycle23312026/10/06 10:43:18 ERROR Drain finished with paths left in queue remaining=123322026/10/06 10:43:18 INFO Uploading batch count=123332026/10/06 10:43:18 ERROR Upload failed error="upload failed" count=123342026/10/06 10:43:18 INFO Uploading batch count=223352026/10/06 10:43:18 ERROR Upload failed error="upload failed" count=223362026/10/06 10:43:18 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-19021-1960143159/TestDrainGivesUpWhenServerDown107553177/002/e23372026/10/06 10:43:18 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-19021-1960143159/TestDrainGivesUpWhenServerDown107553177/002/f23382026/10/06 10:43:18 INFO Uploading batch count=123392026/10/06 10:43:18 ERROR Drain finished with paths left in queue remaining=1023402026/10/06 10:43:18 INFO Uploading batch count=12341--- PASS: TestDrainIsolatesPoisonPath (0.01s)2342=== CONT TestQueueRemove2343--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2344=== CONT TestQueueFetchBatchLimit2345--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)2346=== CONT TestQueueDeduplication2347--- PASS: TestQueueFetchRemoveLifecycle (0.00s)2348=== CONT TestQueueEnqueueAndFetch2349--- PASS: TestQueueRemove (0.00s)2350=== CONT TestRunNotBlockedByPoisonHead2351--- PASS: TestQueueFetchBatchLimit (0.00s)2352--- PASS: TestQueueDeduplication (0.00s)2353--- PASS: TestQueueEnqueueAndFetch (0.00s)23542026/10/06 10:43:18 INFO Upload queue status pending=323552026/10/06 10:43:18 INFO Uploading batch count=123562026/10/06 10:43:18 ERROR Upload failed error="upload failed" count=12357--- PASS: TestWorkerUploadsAndRemoves (0.03s)2358--- PASS: TestWorkerPrunesClosureDeps (0.03s)2359--- PASS: TestWorkerSkipsGCdPaths (0.03s)2360--- PASS: TestQueueRemoveLargeClosure (0.04s)2361--- PASS: TestQueueConcurrentWriters (0.12s)23622026/10/06 10:43:18 ERROR Upload failed error="context deadline exceeded" count=223632026/10/06 10:43:18 ERROR Drain finished with paths left in queue remaining=42364--- PASS: TestDrainTimeout (0.22s)23652026/10/06 10:43:19 INFO Uploading batch count=123662026/10/06 10:43:19 INFO Uploading batch count=123672026/10/06 10:43:19 INFO Uploading batch count=123682026/10/06 10:43:19 ERROR Upload failed error="upload failed" count=123692026/10/06 10:43:19 INFO Uploading batch count=123702026/10/06 10:43:19 ERROR Upload failed error="upload failed" count=123712026/10/06 10:43:19 INFO Uploading batch count=123722026/10/06 10:43:19 ERROR Upload failed error="upload failed" count=123732026/10/06 10:43:19 INFO Uploading batch count=123742026/10/06 10:43:19 ERROR Upload failed error="upload failed" count=123752026/10/06 10:43:19 ERROR Drain finished with paths left in queue remaining=12376--- PASS: TestRunNotBlockedByPoisonHead (1.01s)2377PASS2378Running signing tests...2379=== RUN TestExternalSigner2380=== PAUSE TestExternalSigner2381=== RUN TestExternalSignerWrongPublicKey2382=== PAUSE TestExternalSignerWrongPublicKey2383=== RUN TestExternalSignerErrors2384=== PAUSE TestExternalSignerErrors2385=== RUN TestExternalSignerRestartsAfterCrash2386=== PAUSE TestExternalSignerRestartsAfterCrash2387=== RUN TestExternalSignerProgramErrorKeepsProcess2388=== PAUSE TestExternalSignerProgramErrorKeepsProcess2389=== RUN TestExternalSignerClose2390=== PAUSE TestExternalSignerClose2391=== RUN TestExternalSignerRejectsInvalidPublicKey2392=== PAUSE TestExternalSignerRejectsInvalidPublicKey2393=== RUN TestExternalSignerCancellation2394=== PAUSE TestExternalSignerCancellation2395=== RUN TestGenerateFingerprint2396=== PAUSE TestGenerateFingerprint2397=== RUN TestParseSigningKey2398=== PAUSE TestParseSigningKey2399=== RUN TestSign2400=== PAUSE TestSign2401=== RUN TestSignBatch2402=== PAUSE TestSignBatch2403=== RUN TestNilKeyPublicKey2404=== PAUSE TestNilKeyPublicKey2405=== RUN TestSignErrors2406=== PAUSE TestSignErrors2407=== CONT TestExternalSigner2408=== CONT TestExternalSignerCancellation2409=== CONT TestSignBatch2410=== CONT TestParseSigningKey2411=== RUN TestParseSigningKey/valid_32-byte_key2412=== CONT TestGenerateFingerprint2413=== PAUSE TestParseSigningKey/valid_32-byte_key2414=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2415=== RUN TestGenerateFingerprint/basic_with_references2416=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2417=== RUN TestParseSigningKey/no_colon2418=== PAUSE TestParseSigningKey/no_colon2419=== PAUSE TestGenerateFingerprint/basic_with_references2420=== RUN TestParseSigningKey/empty_name2421=== CONT TestSignErrors2422=== PAUSE TestParseSigningKey/empty_name2423=== RUN TestParseSigningKey/invalid_base642424=== RUN TestGenerateFingerprint/no_references2425=== PAUSE TestGenerateFingerprint/no_references2426=== CONT TestSign2427=== CONT TestNilKeyPublicKey2428=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2429--- PASS: TestNilKeyPublicKey (0.00s)2430=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2431=== CONT TestExternalSignerRejectsInvalidPublicKey2432=== CONT TestExternalSignerProgramErrorKeepsProcess2433=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2434=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2435=== RUN TestGenerateFingerprint/invalid_nar_hash_length2436=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2437=== RUN TestGenerateFingerprint/invalid_store_path_prefix2438=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2439=== RUN TestGenerateFingerprint/invalid_reference_prefix2440=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2441=== RUN TestExternalSignerRejectsInvalidPublicKey/#002442=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002443=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2444=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2445=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2446=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2447=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2448=== CONT TestExternalSignerRestartsAfterCrash2449=== PAUSE TestParseSigningKey/invalid_base642450=== RUN TestParseSigningKey/wrong_length2451=== PAUSE TestParseSigningKey/wrong_length2452=== CONT TestExternalSignerErrors2453=== RUN TestExternalSignerErrors/exit_on_request2454=== PAUSE TestExternalSignerErrors/exit_on_request2455=== RUN TestExternalSignerErrors/wrong_shape2456=== PAUSE TestExternalSignerErrors/wrong_shape2457=== RUN TestExternalSignerErrors/wrong_id2458=== PAUSE TestExternalSignerErrors/wrong_id2459=== RUN TestExternalSignerErrors/exit_at_startup2460=== PAUSE TestExternalSignerErrors/exit_at_startup2461=== RUN TestExternalSignerErrors/null2462=== PAUSE TestExternalSignerErrors/null2463=== RUN TestExternalSignerErrors/missing_signatures2464=== PAUSE TestExternalSignerErrors/missing_signatures2465=== RUN TestExternalSignerErrors/wrong_signatures_shape2466=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2467=== RUN TestExternalSignerErrors/invalid_signature_base642468=== PAUSE TestExternalSignerErrors/invalid_signature_base642469=== RUN TestExternalSignerErrors/wrong_signature_length2470=== PAUSE TestExternalSignerErrors/wrong_signature_length2471=== RUN TestExternalSignerErrors/invalid_JSON2472=== CONT TestExternalSignerClose2473=== PAUSE TestExternalSignerErrors/invalid_JSON2474=== RUN TestExternalSignerErrors/null_signatures2475=== PAUSE TestExternalSignerErrors/null_signatures2476=== RUN TestExternalSignerErrors/too_few_signatures2477=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2478=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2479=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2480=== PAUSE TestExternalSignerErrors/too_few_signatures2481=== CONT TestExternalSignerWrongPublicKey2482=== RUN TestExternalSignerErrors/unrequested_key2483=== PAUSE TestExternalSignerErrors/unrequested_key2484=== RUN TestExternalSignerErrors/wrong_signature_name2485=== PAUSE TestExternalSignerErrors/wrong_signature_name2486=== RUN TestExternalSignerErrors/program_error2487=== PAUSE TestExternalSignerErrors/program_error2488=== RUN TestExternalSignerErrors/missing_signature_name2489=== PAUSE TestExternalSignerErrors/missing_signature_name2490=== CONT TestGenerateFingerprint/basic_with_references2491=== CONT TestGenerateFingerprint/invalid_nar_hash_length2492=== CONT TestGenerateFingerprint/invalid_reference_prefix2493=== CONT TestGenerateFingerprint/invalid_store_path_prefix2494=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2495=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2496=== CONT TestGenerateFingerprint/no_references2497=== CONT TestParseSigningKey/valid_32-byte_key2498--- PASS: TestGenerateFingerprint (0.00s)2499 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2500 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2501 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2502 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2503 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2504 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2505 --- PASS: TestGenerateFingerprint/no_references (0.00s)2506=== RUN TestSignErrors/nil_key2507=== CONT TestParseSigningKey/empty_name2508=== PAUSE TestSignErrors/nil_key2509=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2510--- PASS: TestSign (0.00s)2511=== RUN TestSignErrors/nil_narinfo2512=== CONT TestParseSigningKey/invalid_base642513=== PAUSE TestSignErrors/nil_narinfo2514=== CONT TestExternalSignerRejectsInvalidPublicKey/#002515=== RUN TestSignErrors/invalid_narinfo2516=== PAUSE TestSignErrors/invalid_narinfo2517=== RUN TestSignErrors/canceled2518=== PAUSE TestSignErrors/canceled2519=== CONT TestParseSigningKey/wrong_length2520=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2521=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2522=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2523=== CONT TestParseSigningKey/no_colon2524=== CONT TestExternalSignerErrors/exit_on_request2525--- PASS: TestParseSigningKey (0.00s)2526 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2527 --- PASS: TestParseSigningKey/empty_name (0.00s)2528 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2529 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2530 --- PASS: TestParseSigningKey/wrong_length (0.00s)2531 --- PASS: TestParseSigningKey/no_colon (0.00s)2532=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2533=== CONT TestExternalSignerErrors/wrong_signature_length2534=== CONT TestExternalSignerErrors/program_error2535--- PASS: TestSignBatch (0.01s)2536--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2537 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2538 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2539 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2540 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2541 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2542=== CONT TestExternalSignerErrors/missing_signature_name2543--- PASS: TestExternalSigner (0.23s)2544=== CONT TestExternalSignerErrors/wrong_signature_name2545--- PASS: TestExternalSignerCancellation (0.41s)2546=== CONT TestExternalSignerErrors/unrequested_key2547--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.58s)2548=== CONT TestExternalSignerErrors/too_few_signatures2549--- PASS: TestExternalSignerWrongPublicKey (0.77s)2550=== CONT TestExternalSignerErrors/null_signatures2551--- PASS: TestExternalSignerRestartsAfterCrash (0.98s)2552=== CONT TestExternalSignerErrors/invalid_JSON2553/nix/var/nix/builds/nix-19021-1960143159/TestExternalSignerRestartsAfterCrash2396640280/001/sign program: line 7: /nix/var/nix/builds/nix-19021-1960143159/TestExternalSignerRestartsAfterCrash2396640280/001/sign program.starts: No such file or directory2554--- PASS: TestExternalSignerClose (1.14s)2555=== CONT TestExternalSignerErrors/null2556=== CONT TestExternalSignerErrors/invalid_signature_base642557=== CONT TestExternalSignerErrors/wrong_signatures_shape2558=== CONT TestExternalSignerErrors/missing_signatures2559=== CONT TestExternalSignerErrors/wrong_id2560=== CONT TestExternalSignerErrors/exit_at_startup2561=== CONT TestExternalSignerErrors/wrong_shape2562=== CONT TestSignErrors/nil_key2563=== CONT TestSignErrors/canceled2564=== CONT TestSignErrors/invalid_narinfo2565=== CONT TestSignErrors/nil_narinfo2566--- PASS: TestSignErrors (0.01s)2567 --- PASS: TestSignErrors/nil_key (0.00s)2568 --- PASS: TestSignErrors/canceled (0.00s)2569 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2570 --- PASS: TestSignErrors/nil_narinfo (0.00s)2571--- PASS: TestExternalSignerErrors (0.00s)2572 --- PASS: TestExternalSignerErrors/missing_signature_name (1.33s)2573 --- PASS: TestExternalSignerErrors/exit_on_request (1.51s)2574 --- PASS: TestExternalSignerErrors/program_error (1.70s)2575 --- PASS: TestExternalSignerErrors/wrong_signature_length (1.88s)2576 --- PASS: TestExternalSignerErrors/wrong_signature_name (1.85s)2577 --- PASS: TestExternalSignerErrors/unrequested_key (1.85s)2578 --- PASS: TestExternalSignerErrors/too_few_signatures (1.87s)2579 --- PASS: TestExternalSignerErrors/null_signatures (1.87s)2580 --- PASS: TestExternalSignerErrors/invalid_JSON (1.85s)2581 --- PASS: TestExternalSignerErrors/null (1.87s)2582 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (1.87s)2583 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (1.87s)2584 --- PASS: TestExternalSignerErrors/missing_signatures (1.87s)2585 --- PASS: TestExternalSignerErrors/wrong_id (1.88s)2586 --- PASS: TestExternalSignerErrors/exit_at_startup (1.87s)2587 --- PASS: TestExternalSignerErrors/wrong_shape (1.87s)2588PASS2589Running OpenBao signer tests...2590=== RUN TestSign2591=== PAUSE TestSign2592=== RUN TestSignErrors2593=== PAUSE TestSignErrors2594=== RUN TestServe2595=== PAUSE TestServe2596=== RUN TestServeRejectsGarbage2597=== PAUSE TestServeRejectsGarbage2598=== CONT TestSign2599=== CONT TestServe2600=== CONT TestServeRejectsGarbage2601--- PASS: TestServeRejectsGarbage (0.00s)2602=== CONT TestSignErrors2603=== RUN TestSignErrors/http_error2604=== PAUSE TestSignErrors/http_error2605=== RUN TestSignErrors/invalid_json2606=== PAUSE TestSignErrors/invalid_json2607=== RUN TestSignErrors/no_prefix2608=== PAUSE TestSignErrors/no_prefix2609=== RUN TestSignErrors/invalid_base642610=== PAUSE TestSignErrors/invalid_base642611=== CONT TestSignErrors/http_error2612=== CONT TestSignErrors/no_prefix2613--- PASS: TestServe (0.00s)2614=== CONT TestSignErrors/invalid_base642615=== CONT TestSignErrors/invalid_json2616--- PASS: TestSign (0.00s)2617--- PASS: TestSignErrors (0.00s)2618 --- PASS: TestSignErrors/no_prefix (0.00s)2619 --- PASS: TestSignErrors/invalid_json (0.00s)2620 --- PASS: TestSignErrors/invalid_base64 (0.00s)2621 --- PASS: TestSignErrors/http_error (0.00s)2622PASS