niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #383
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica8=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica9=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun10=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun11=== RUN TestCaseHackSuffix12=== PAUSE TestCaseHackSuffix13=== RUN TestFilterOversizedClosures14=== PAUSE TestFilterOversizedClosures15=== RUN TestUploadMultipart_PartsInParallel16=== PAUSE TestUploadMultipart_PartsInParallel17=== RUN TestPartSizeForNAR18=== PAUSE TestPartSizeForNAR19=== RUN TestUploadMultipart_SupersededByPeer20=== PAUSE TestUploadMultipart_SupersededByPeer21=== RUN TestDumpPathCaseHackMatchesNix22--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestDumpPathMatchesNix26=== PAUSE TestDumpPathMatchesNix27=== RUN TestDumpPathSingleFile28=== PAUSE TestDumpPathSingleFile29=== RUN TestDumpPathWriterError30=== PAUSE TestDumpPathWriterError31=== RUN TestEncodeNixBase3232=== PAUSE TestEncodeNixBase3233=== RUN TestEncodeNixBase32WithRealHash34=== PAUSE TestEncodeNixBase32WithRealHash35=== RUN TestConvertHashToNix3236=== PAUSE TestConvertHashToNix3237=== RUN TestGetStorePathHash38=== PAUSE TestGetStorePathHash39=== RUN TestPathInfoHashCompatibility40=== PAUSE TestPathInfoHashCompatibility41=== RUN TestParsePathInfoJSON42=== PAUSE TestParsePathInfoJSON43=== RUN TestParsePathInfoJSONMultiplePaths44=== PAUSE TestParsePathInfoJSONMultiplePaths45=== RUN TestPathInfoCACompatibility46=== PAUSE TestPathInfoCACompatibility47=== RUN TestRateLimiterFeedback48=== PAUSE TestRateLimiterFeedback49=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess51=== RUN TestResolveStorePath52=== PAUSE TestResolveStorePath53=== RUN TestDoWithRetry_BodyReplayedViaGetBody54=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody55=== RUN TestShellSplit56=== PAUSE TestShellSplit57=== RUN TestShellSplitErrors58=== PAUSE TestShellSplitErrors59=== RUN TestStreamPushReportsEveryPath60=== PAUSE TestStreamPushReportsEveryPath61=== RUN TestStreamPushBatchesUnderLoad62=== PAUSE TestStreamPushBatchesUnderLoad63=== RUN TestStreamPushIsolatesFailures64=== PAUSE TestStreamPushIsolatesFailures65=== RUN TestStreamPushGivesUpOnDeadServer66=== PAUSE TestStreamPushGivesUpOnDeadServer67=== RUN TestStreamPushRequestLine68=== PAUSE TestStreamPushRequestLine69=== RUN TestStreamPushReportsSignatures70=== PAUSE TestStreamPushReportsSignatures71=== RUN TestClientSignaturesByStorePath72=== PAUSE TestClientSignaturesByStorePath73=== RUN TestSetClientTLS74=== PAUSE TestSetClientTLS75=== RUN TestSetClientTLSDoesNotMutateDefaultTransport76=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport77=== RUN TestSetClientTLSErrors78=== PAUSE TestSetClientTLSErrors79=== RUN TestStaticToken80=== PAUSE TestStaticToken81=== RUN TestFileTokenReadsAndCaches82=== PAUSE TestFileTokenReadsAndCaches83=== RUN TestFileTokenMissing84=== PAUSE TestFileTokenMissing85=== RUN TestFileTokenEmpty86=== PAUSE TestFileTokenEmpty87=== RUN TestScriptTokenNoExpiryRerunsEveryCall88=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall89=== RUN TestScriptTokenCachesUntilRefresh90=== PAUSE TestScriptTokenCachesUntilRefresh91=== RUN TestScriptTokenEmptyToken92=== PAUSE TestScriptTokenEmptyToken93=== RUN TestScriptTokenBadJSON94=== PAUSE TestScriptTokenBadJSON95=== RUN TestScriptTokenScriptFails96=== PAUSE TestScriptTokenScriptFails97=== RUN TestScriptTokenEmptyCommand98=== PAUSE TestScriptTokenEmptyCommand99=== CONT TestDoServerRequestAttachesToken100=== CONT TestDoWithRetry_BodyReplayedViaGetBody101=== CONT TestScriptTokenEmptyCommand102--- PASS: TestScriptTokenEmptyCommand (0.00s)103=== CONT TestParsePathInfoJSONMultiplePaths104=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths105=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths106=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths107=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths108=== CONT TestStreamPushGivesUpOnDeadServer109=== CONT TestFileTokenReadsAndCaches110=== CONT TestSetClientTLS111=== CONT TestClientSignaturesByStorePath112--- PASS: TestClientSignaturesByStorePath (0.00s)113=== CONT TestParsePathInfoJSON114--- PASS: TestFileTokenReadsAndCaches (0.00s)115=== RUN TestParsePathInfoJSON/Nix_format116=== PAUSE TestParsePathInfoJSON/Nix_format117=== RUN TestParsePathInfoJSON/Lix_format118=== PAUSE TestParsePathInfoJSON/Lix_format119=== RUN TestParsePathInfoJSON/empty_input120=== PAUSE TestParsePathInfoJSON/empty_input121=== RUN TestParsePathInfoJSON/whitespace_only122=== PAUSE TestParsePathInfoJSON/whitespace_only123=== RUN TestParsePathInfoJSON/invalid_JSON124=== PAUSE TestParsePathInfoJSON/invalid_JSON125=== CONT TestStaticToken126--- PASS: TestStaticToken (0.00s)127=== CONT TestSetClientTLSErrors128=== CONT TestStreamPushReportsEveryPath129=== CONT TestStreamPushIsolatesFailures130=== CONT TestPathInfoHashCompatibility131=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)132=== CONT TestStreamPushBatchesUnderLoad133=== CONT TestScriptTokenNoExpiryRerunsEveryCall134=== CONT TestScriptTokenScriptFails135=== CONT TestScriptTokenBadJSON136=== CONT TestScriptTokenEmptyToken137=== CONT TestScriptTokenCachesUntilRefresh138=== CONT TestEncodeNixBase32139=== CONT TestResolveStorePath140=== CONT TestSetClientTLSDoesNotMutateDefaultTransport141=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess142=== CONT TestRateLimiterFeedback143=== RUN TestRateLimiterFeedback/429_enables_limiter144=== CONT TestFileTokenEmpty145=== CONT TestPathInfoCACompatibility146=== CONT TestFileTokenMissing147=== CONT TestStreamPushReportsSignatures148=== CONT TestStreamPushRequestLine1492026/10/06 21:13:39 ERROR Upload failed error="connection refused" count=20150=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)1512026/10/06 21:13:39 ERROR Upload failed error="bad path" count=31522026/10/06 21:13:39 ERROR Server seems unavailable, giving up on batch untried=17153--- PASS: TestStreamPushIsolatesFailures (0.00s)154=== CONT TestGetStorePathHash155=== RUN TestGetStorePathHash/valid_store_path156=== PAUSE TestGetStorePathHash/valid_store_path157=== RUN TestGetStorePathHash/basename_without_hyphen_should_error158=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error1592026/10/06 21:13:39 WARN Rate limiter enabled after throttle name=server-test rate=5160=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error1612026/10/06 21:13:39 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:33577162=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error163=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error164=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error165--- PASS: TestStreamPushReportsEveryPath (0.00s)166=== CONT TestEncodeNixBase32WithRealHash167--- PASS: TestEncodeNixBase32WithRealHash (0.00s)168=== CONT TestUploadMultipart_PartsInParallel169=== CONT TestConvertHashToNix321702026/10/06 21:13:39 WARN Rate limiter backed off name=server-test rate=5171--- PASS: TestDoServerRequestAttachesToken (0.01s)1722026/10/06 21:13:39 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:33577173=== CONT TestShellSplit174=== RUN TestEncodeNixBase32/test_string_hash175=== RUN TestConvertHashToNix32/SRI_format_to_Nix32176--- PASS: TestShellSplit (0.00s)177=== PAUSE TestEncodeNixBase32/test_string_hash178=== CONT TestDumpPathMatchesNix179--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)180=== RUN TestEncodeNixBase32/empty_input181=== RUN TestSetClientTLSErrors/missing_cert_file182--- PASS: TestResolveStorePath (0.00s)183--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)184=== CONT TestDumpPathSingleFile185=== RUN TestSetClientTLS/rejects_connection_without_client_cert186=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert187=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA1882026/10/06 21:13:39 WARN Rate limiter enabled after throttle name=server-test rate=5189=== CONT TestDumpPathWriterError190=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA191=== PAUSE TestRateLimiterFeedback/429_enables_limiter1922026/10/06 21:13:39 ERROR Upload failed error=boom count=1193=== RUN TestRateLimiterFeedback/503_enables_limiter194=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun195=== PAUSE TestRateLimiterFeedback/503_enables_limiter196=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter197=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter198=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter199=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter200=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica2012026/10/06 21:13:39 ERROR Upload failed error=boom count=1202=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32203=== RUN TestConvertHashToNix32/already_Nix32_format204=== PAUSE TestConvertHashToNix32/already_Nix32_format205=== RUN TestConvertHashToNix32/invalid_format206=== CONT TestCaseHackSuffix207=== CONT TestUploadMultipart_SupersededByPeer208=== RUN TestUploadMultipart_SupersededByPeer/exists209=== PAUSE TestConvertHashToNix32/invalid_format210=== PAUSE TestEncodeNixBase32/empty_input211=== PAUSE TestSetClientTLSErrors/missing_cert_file212--- PASS: TestScriptTokenScriptFails (0.03s)213=== CONT TestPartSizeForNAR214=== RUN TestPathInfoCACompatibility/null_ca_field215=== PAUSE TestPathInfoCACompatibility/null_ca_field216=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths217=== RUN TestPartSizeForNAR/zero_stays_at_minimum218=== CONT TestParsePathInfoJSON/Nix_format219=== RUN TestPathInfoCACompatibility/old_string_format_-_text220=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text221=== CONT TestParsePathInfoJSON/whitespace_only222=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive223=== CONT TestParsePathInfoJSON/Lix_format2242026/10/06 21:13:39 INFO Garbage collection started225=== CONT TestParsePathInfoJSON/empty_input2262026/10/06 21:13:39 INFO Garbage collection started227=== RUN TestSetClientTLSErrors/missing_key_file228=== PAUSE TestSetClientTLSErrors/missing_key_file229=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum230=== RUN TestSetClientTLS/preserves_debug_logging_transport231=== RUN TestPartSizeForNAR/small_stays_at_minimum232=== PAUSE TestSetClientTLS/preserves_debug_logging_transport233=== CONT TestRegisterUploadedObjectReusesConnections234=== PAUSE TestUploadMultipart_SupersededByPeer/exists235=== RUN TestUploadMultipart_SupersededByPeer/missing236=== PAUSE TestUploadMultipart_SupersededByPeer/missing237=== CONT TestShellSplitErrors238=== CONT TestGetStorePathHash/basename_without_hyphen_should_error239=== CONT TestRateLimiterFeedback/429_enables_limiter240=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths241=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter242--- PASS: TestStreamPushReportsSignatures (0.00s)243--- PASS: TestScriptTokenEmptyToken (0.03s)244--- PASS: TestScriptTokenBadJSON (0.03s)245--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)246--- PASS: TestFileTokenEmpty (0.00s)247--- PASS: TestFileTokenMissing (0.00s)248=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon249=== CONT TestParsePathInfoJSON/invalid_JSON250=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive251=== CONT TestGetStorePathHash/valid_store_path252=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter253=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon254=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI255=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI256=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512257=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512258=== RUN TestPathInfoCACompatibility/new_structured_format_-_text259=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text260=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method261=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method262=== CONT TestRateLimiterFeedback/503_enables_limiter263=== CONT TestConvertHashToNix32/already_Nix32_format264=== CONT TestEncodeNixBase32/test_string_hash265=== CONT TestEncodeNixBase32/empty_input266=== CONT TestSetClientTLS/rejects_connection_without_client_cert2672026/10/06 21:13:39 WARN Rate limiter enabled after throttle name=server-test rate=5268=== CONT TestConvertHashToNix32/invalid_format2692026/10/06 21:13:39 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:42297270=== CONT TestSetClientTLS/preserves_debug_logging_transport2712026/10/06 21:13:39 WARN Rate limiter backed off name=server-test rate=5272=== CONT TestFilterOversizedClosures273=== RUN TestFilterOversizedClosures/no_limit_keeps_everything274=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything275=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA2762026/10/06 21:13:39 WARN Rate limiter enabled after throttle name=server-test rate=52772026/10/06 21:13:39 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:39123278=== PAUSE TestPartSizeForNAR/small_stays_at_minimum279=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum280=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum281=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts282=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts283=== RUN TestPartSizeForNAR/1_TiB284=== PAUSE TestPartSizeForNAR/1_TiB285=== RUN TestPartSizeForNAR/5_TiB_S3_max_object286=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error287=== RUN TestSetClientTLSErrors/missing_ca_file288--- PASS: TestShellSplitErrors (0.00s)289=== CONT TestConvertHashToNix32/SRI_format_to_Nix32290=== CONT TestUploadMultipart_SupersededByPeer/exists2912026/10/06 21:13:39 WARN Rate limiter backed off name=server-test rate=5292=== CONT TestUploadMultipart_SupersededByPeer/missing293=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error294--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)295 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)296 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)297--- PASS: TestParsePathInfoJSON (0.00s)298 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)299 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)300 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)301 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)302 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)303=== PAUSE TestSetClientTLSErrors/missing_ca_file304=== RUN TestSetClientTLSErrors/invalid_ca_file305=== PAUSE TestSetClientTLSErrors/invalid_ca_file306=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object307=== RUN TestPartSizeForNAR/capped_at_5_GiB308=== PAUSE TestPartSizeForNAR/capped_at_5_GiB309=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon310=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method311=== CONT TestPathInfoCACompatibility/new_structured_format_-_text312=== CONT TestPathInfoCACompatibility/old_string_format_-_text313=== CONT TestSetClientTLSErrors/missing_cert_file314=== CONT TestSetClientTLSErrors/invalid_ca_file315=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)316=== CONT TestSetClientTLSErrors/missing_ca_file317=== CONT TestSetClientTLSErrors/missing_key_file318=== CONT TestPartSizeForNAR/capped_at_5_GiB319=== CONT TestPartSizeForNAR/5_TiB_S3_max_object320=== CONT TestPartSizeForNAR/1_TiB321=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts322=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum323=== CONT TestPartSizeForNAR/small_stays_at_minimum324=== CONT TestPartSizeForNAR/zero_stays_at_minimum325=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512326=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive327=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped328=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped329=== RUN TestFilterOversizedClosures/all_closures_skipped330=== PAUSE TestFilterOversizedClosures/all_closures_skipped331=== CONT TestFilterOversizedClosures/no_limit_keeps_everything332--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)333=== CONT TestFilterOversizedClosures/all_closures_skipped3342026/10/06 21:13:39 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=50335=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3362026/10/06 21:13:39 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=2000337=== CONT TestPathInfoCACompatibility/null_ca_field338=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI339--- PASS: TestEncodeNixBase32 (0.02s)340 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)341 --- PASS: TestEncodeNixBase32/empty_input (0.00s)342--- PASS: TestConvertHashToNix32 (0.02s)343 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)344 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)345 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)346--- PASS: TestGetStorePathHash (0.00s)347 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)348 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)349 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)350 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)351--- PASS: TestRateLimiterFeedback (0.03s)352 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)353 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)354 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)355 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)356--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)357--- PASS: TestPartSizeForNAR (0.00s)358 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)359 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)360 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)361 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)362 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)363 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)364 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)365--- PASS: TestPathInfoCACompatibility (0.00s)366 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)367 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)368 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)369 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)370 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)371--- PASS: TestPathInfoHashCompatibility (0.03s)372 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)373 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)374 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)375 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)376--- PASS: TestFilterOversizedClosures (0.00s)377 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)378 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)379 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)380--- PASS: TestSetClientTLSErrors (0.04s)381 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)382 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)383 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)384 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)385--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)386--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)387 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)388 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)3892026/10/06 21:13:39 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=03902026/10/06 21:13:39 WARN Garbage collection finished on another replica. Its statistics are not available here391--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)3922026/10/06 21:13:39 http: TLS handshake error from 127.0.0.1:55764: remote error: tls: bad certificate393--- PASS: TestSetClientTLS (0.03s)394 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)395 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)396 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)397--- PASS: TestStreamPushRequestLine (0.02s)398--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)399--- PASS: TestDumpPathSingleFile (0.05s)400--- PASS: TestCaseHackSuffix (0.03s)401--- PASS: TestDumpPathWriterError (0.03s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestDumpPathMatchesNix (0.10s)404--- PASS: TestUploadMultipart_PartsInParallel (0.65s)405--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.02s)406PASS407Running server tests...408The files belonging to this database system will be owned by user "nixbld".409This user must also own the server process.410411The database cluster will be initialized with locale "C".412The default database encoding has accordingly been set to "SQL_ASCII".413The default text search configuration will be set to "english".414415Data page checksums are enabled.416417creating directory /build/postgres404748785/data ... ok418creating subdirectories ... ok419selecting dynamic shared memory implementation ... posix420selecting default "max_connections" ... 100421selecting default "shared_buffers" ... 128MB422selecting default time zone ... UTC423creating configuration files ... ok424running bootstrap script ... ok425performing post-bootstrap initialization ... ok426syncing data to disk ... ok427428initdb: warning: enabling "trust" authentication for local connections429initdb: 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.430431Success. You can now start the database server using:432433 pg_ctl -D /build/postgres404748785/data -l logfile start434435/build/postgres404748785:5432 - no response4362026-10-06 21:13:41.851 UTC [129] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-06 21:13:41.852 UTC [129] LOG: listening on Unix socket "/build/postgres404748785/.s.PGSQL.5432"4382026-10-06 21:13:41.856 UTC [136] LOG: database system was shut down at 2026-10-06 21:13:41 UTC4392026-10-06 21:13:41.860 UTC [129] LOG: database system is ready to accept connections440/build/postgres404748785:5432 - accepting connections441=== RUN TestService_AuthMiddleware442=== PAUSE TestService_AuthMiddleware443=== RUN TestService_AuthMiddleware_MTLSProxyHeader444=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader445=== RUN TestService_AuthMiddleware_MTLSBoundSubjects446=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects447=== RUN TestService_ReadAuthMiddleware448=== PAUSE TestService_ReadAuthMiddleware449=== RUN TestService_AuthMiddleware_OIDC450=== PAUSE TestService_AuthMiddleware_OIDC451=== RUN TestService_RequireScope_OIDC452=== PAUSE TestService_RequireScope_OIDC453=== RUN TestService_ReadScope_PublicByDefault454=== PAUSE TestService_ReadScope_PublicByDefault455=== RUN TestCacheConfigHandler456=== PAUSE TestCacheConfigHandler457=== RUN TestCacheStatsHandler458=== PAUSE TestCacheStatsHandler459=== RUN TestClientCADerivations460=== PAUSE TestClientCADerivations461=== RUN TestClientErrorHandling462=== PAUSE TestClientErrorHandling463=== RUN TestClientIntegration464=== PAUSE TestClientIntegration465=== RUN TestClientMultipleUploads466=== PAUSE TestClientMultipleUploads467=== RUN TestClientWithDependencies468=== PAUSE TestClientWithDependencies469=== RUN TestClientSharedPathCommittedMidPush470=== PAUSE TestClientSharedPathCommittedMidPush471=== RUN TestPinProtectsFromGC472=== PAUSE TestPinProtectsFromGC473=== RUN TestClientPushesUseOnePush474=== PAUSE TestClientPushesUseOnePush475=== RUN TestClientFallsBackToClosures476=== PAUSE TestClientFallsBackToClosures477=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock478=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock479=== RUN TestResolveDBConnectionString480=== PAUSE TestResolveDBConnectionString481=== RUN TestConnectWaitsForAPeerMigration482=== PAUSE TestConnectWaitsForAPeerMigration483=== RUN TestLeadElectsOneAndHandsOver484=== PAUSE TestLeadElectsOneAndHandsOver485=== RUN TestLeadIncumbentWinsAfterRestart4862026/10/06 21:13:42 INFO lead: acquired remote=192.0.2.1:12344872026/10/06 21:13:42 INFO lead: released remote=192.0.2.1:12344882026/10/06 21:13:42 INFO lead: acquired remote=192.0.2.1:12344892026/10/06 21:13:44 INFO lead: released remote=192.0.2.1:1234490--- PASS: TestLeadIncumbentWinsAfterRestart (1.85s)491=== RUN TestLeadIncumbentAnnouncesAtOnce492=== PAUSE TestLeadIncumbentAnnouncesAtOnce493=== RUN TestLeadEndsOnShutdown494=== PAUSE TestLeadEndsOnShutdown495=== RUN TestLeadEndsWhenItsConnectionHangs4962026/10/06 21:13:44 INFO lead: acquired remote=192.0.2.1:12344972026-10-06 21:13:45.535 UTC [385] FATAL: terminating connection due to administrator command4982026/10/06 21:13:45 INFO lead: acquired remote=192.0.2.1:12344992026/10/06 21:13:46 WARN lead: lock connection lost error="timeout: context deadline exceeded"5002026/10/06 21:13:46 INFO lead: released remote=192.0.2.1:12345012026/10/06 21:13:46 INFO lead: released remote=192.0.2.1:1234502--- PASS: TestLeadEndsWhenItsConnectionHangs (2.93s)503=== RUN TestGCAdvisoryLockBlocksConcurrentRun504=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun505=== RUN TestGCBugBareHashReferences506=== PAUSE TestGCBugBareHashReferences507=== RUN TestGCMetrics508=== PAUSE TestGCMetrics509=== RUN TestPushDedupSurvivesConcurrentGC510=== PAUSE TestPushDedupSurvivesConcurrentGC511=== RUN TestDeduplicatedObjectsRecordedAsPending512=== PAUSE TestDeduplicatedObjectsRecordedAsPending513=== RUN TestGCSweepSkipsPendingObjects514=== PAUSE TestGCSweepSkipsPendingObjects515=== RUN TestTombstonedObjectOfferedWithoutWaiting516=== PAUSE TestTombstonedObjectOfferedWithoutWaiting517=== RUN TestGCSweepDeliversEachKeyOnce518=== PAUSE TestGCSweepDeliversEachKeyOnce519=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection520=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection521=== RUN TestForceGCDuringPushOffersSweptObject522=== PAUSE TestForceGCDuringPushOffersSweptObject523=== RUN TestFailedS3DeleteKeepsTombstone524=== PAUSE TestFailedS3DeleteKeepsTombstone525=== RUN TestSweepSkipsRowsLockedByPush526=== PAUSE TestSweepSkipsRowsLockedByPush527=== RUN TestRegisterCompletedObjectNeedsPendingRow528=== PAUSE TestRegisterCompletedObjectNeedsPendingRow529=== RUN TestGetExistingObjectsLocksRows530=== PAUSE TestGetExistingObjectsLocksRows531=== RUN TestSweepRechecksPendingAfterLocking532=== PAUSE TestSweepRechecksPendingAfterLocking533=== RUN TestPushWaitsForSweepHoldingRow534=== PAUSE TestPushWaitsForSweepHoldingRow535=== RUN TestCommitRacingPendingCleanupKeepsObjects536=== PAUSE TestCommitRacingPendingCleanupKeepsObjects537=== RUN TestGCEndsOnShutdown538=== PAUSE TestGCEndsOnShutdown539=== RUN TestGCTaskStore_StartNew540=== PAUSE TestGCTaskStore_StartNew541=== RUN TestGCTaskStore_DeduplicateSameParams542=== PAUSE TestGCTaskStore_DeduplicateSameParams543=== RUN TestGCTaskStore_ConflictDifferentParams544=== PAUSE TestGCTaskStore_ConflictDifferentParams545=== RUN TestGCTaskStore_GetEmpty546=== PAUSE TestGCTaskStore_GetEmpty547=== RUN TestGCTaskStore_GetReturnsLatest548=== PAUSE TestGCTaskStore_GetReturnsLatest549=== RUN TestGCTaskStore_CompletedAllowsNewTask550=== PAUSE TestGCTaskStore_CompletedAllowsNewTask551=== RUN TestGCTaskStore_PhaseUpdates552=== PAUSE TestGCTaskStore_PhaseUpdates553=== RUN TestGCTaskStore_Fail554=== PAUSE TestGCTaskStore_Fail555=== RUN TestGracefulShutdownDrainsInflight556=== PAUSE TestGracefulShutdownDrainsInflight557=== RUN TestService_healthCheckHandler558=== PAUSE TestService_healthCheckHandler559=== RUN TestService_readinessHandler560=== PAUSE TestService_readinessHandler561=== RUN TestGenerateLandingPage562=== PAUSE TestGenerateLandingPage563=== RUN TestCacheConfigHandlerMaxNarSize564=== PAUSE TestCacheConfigHandlerMaxNarSize565=== RUN TestCreatePendingClosureRejectsOversizedNAR566=== PAUSE TestCreatePendingClosureRejectsOversizedNAR567=== RUN TestNARDeduplicationMetadataUploadBug568=== PAUSE TestNARDeduplicationMetadataUploadBug569=== RUN TestMetricsInventory570=== PAUSE TestMetricsInventory571=== RUN TestService_NativeMTLS572=== PAUSE TestService_NativeMTLS573=== RUN TestServerTLSConfig574=== PAUSE TestServerTLSConfig575=== RUN TestMultipartCleanup576=== PAUSE TestMultipartCleanup577=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded578=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded579=== RUN TestPendingCleanupUsesOneCutoff580=== PAUSE TestPendingCleanupUsesOneCutoff581=== RUN TestObjectStatsTrigger582=== PAUSE TestObjectStatsTrigger583=== RUN TestOrphanedObjectsGC584=== PAUSE TestOrphanedObjectsGC585=== RUN TestOrphanedObjectsGCStressTest586=== PAUSE TestOrphanedObjectsGCStressTest587=== RUN TestCreatePin_ReservedPins588=== PAUSE TestCreatePin_ReservedPins589=== RUN TestPresentReportsOnlyClosureRoots590=== PAUSE TestPresentReportsOnlyClosureRoots591=== RUN TestPresentRefreshesOnlyStaleClosures592=== PAUSE TestPresentRefreshesOnlyStaleClosures593=== RUN TestPresentNotReportedWhileGCDeletesClosure594=== PAUSE TestPresentNotReportedWhileGCDeletesClosure595=== RUN TestParseSingleRange596=== PAUSE TestParseSingleRange597=== RUN TestProxyHeadersOnlyTrustedOnSocket598=== PAUSE TestProxyHeadersOnlyTrustedOnSocket599=== RUN TestIsValidCachePath600=== PAUSE TestIsValidCachePath601=== RUN TestReadProxyNarinfo602=== PAUSE TestReadProxyNarinfo603=== RUN TestReadProxyNarinfoAlreadyDecompressed604=== PAUSE TestReadProxyNarinfoAlreadyDecompressed605=== RUN TestReadProxyContentNegotiation606=== PAUSE TestReadProxyContentNegotiation607=== RUN TestReadProxyNarStreaming608=== PAUSE TestReadProxyNarStreaming609=== RUN TestReadProxy404610=== PAUSE TestReadProxy404611=== RUN TestReadProxyInvalidPath612=== PAUSE TestReadProxyInvalidPath613=== RUN TestReadProxyHead614=== PAUSE TestReadProxyHead615=== RUN TestReadProxyOutlastsServerWriteTimeout616=== PAUSE TestReadProxyOutlastsServerWriteTimeout617=== RUN TestReadProxyConditionalGet618=== PAUSE TestReadProxyConditionalGet619=== RUN TestReadProxyRootRedirectsToIndexHTML620=== PAUSE TestReadProxyRootRedirectsToIndexHTML621=== RUN TestReadProxyDisabled622=== PAUSE TestReadProxyDisabled623=== RUN TestReadRedirectNar624=== PAUSE TestReadRedirectNar625=== RUN TestReadRedirectKeepsNarinfoProxied626=== PAUSE TestReadRedirectKeepsNarinfoProxied627=== RUN TestReadProxyRangeRequest628=== PAUSE TestReadProxyRangeRequest629=== RUN TestReadRedirectUsesPublicS3URL630=== PAUSE TestReadRedirectUsesPublicS3URL631=== RUN TestPush_OverlappingRootsStoreOneRowPerKey632=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey633=== RUN TestPush_CompleteCommitsEveryRoot634=== PAUSE TestPush_CompleteCommitsEveryRoot635=== RUN TestPush_RepeatedRootCommitsOnce636=== PAUSE TestPush_RepeatedRootCommitsOnce637=== RUN TestPush_CompleteWaitsForCleanupOfThePush638=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush639=== RUN TestPush_RootsAreLockedInByteOrder640=== PAUSE TestPush_RootsAreLockedInByteOrder641=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit642=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit643=== RUN TestPush_RejectsBadRequests644=== PAUSE TestPush_RejectsBadRequests645=== RUN TestPush_SignsNarinfosOfItsPendingObjects646=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects647=== RUN TestRedundantMultipartUpload648=== PAUSE TestRedundantMultipartUpload649=== RUN TestCompleteMultipartUpload_ErrorButObjectExists650=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists651=== RUN TestCompletedNarNotReofferedAcrossClosures652=== PAUSE TestCompletedNarNotReofferedAcrossClosures653=== RUN TestPresignedUploadRegisteredBeforeCommit654=== PAUSE TestPresignedUploadRegisteredBeforeCommit655=== RUN TestService_Rustfstest656=== PAUSE TestService_Rustfstest657=== RUN TestParseSize658=== PAUSE TestParseSize659=== RUN TestSkippedUploadsHandler660=== PAUSE TestSkippedUploadsHandler661=== RUN TestSystemdListenerNotActivated662--- PASS: TestSystemdListenerNotActivated (0.00s)663=== RUN TestWatchdogBeatsWhenHealthy664--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)665=== RUN TestWatchdogSkipsWhenUnhealthy6662026/10/06 21:13:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/06 21:13:47 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6682026/10/06 21:13:47 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6692026/10/06 21:13:47 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6702026/10/06 21:13:47 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6712026/10/06 21:13:47 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6722026/10/06 21:13:47 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6732026/10/06 21:13:47 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6742026/10/06 21:13:47 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6752026/10/06 21:13:47 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"676--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)677=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle678=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle679=== RUN TestProxyWriteTimeout680=== PAUSE TestProxyWriteTimeout681=== RUN TestPendingClosureWriteTimeout682=== PAUSE TestPendingClosureWriteTimeout683=== RUN TestIsValidUploadKey684=== PAUSE TestIsValidUploadKey685=== RUN TestUploadHandlersRejectInvalidKeys686=== PAUSE TestUploadHandlersRejectInvalidKeys687=== RUN TestUploadHandlersRejectOversizedBody688=== PAUSE TestUploadHandlersRejectOversizedBody689=== RUN TestService_cleanupPendingClosuresHandler690=== PAUSE TestService_cleanupPendingClosuresHandler691=== RUN TestService_createPendingClosureHandler692=== PAUSE TestService_createPendingClosureHandler693=== RUN TestService_verifyS3Integrity694=== PAUSE TestService_verifyS3Integrity695=== RUN TestCompleteMultipartUnregistered696=== PAUSE TestCompleteMultipartUnregistered697=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT698=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT699=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle700=== CONT TestService_AuthMiddleware701=== CONT TestSkippedUploadsHandler702=== CONT TestParseSize703--- PASS: TestParseSize (0.00s)704=== CONT TestReadRedirectNar705=== CONT TestService_Rustfstest706=== CONT TestPresignedUploadRegisteredBeforeCommit7072026/10/06 21:13:47 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000708=== CONT TestCompletedNarNotReofferedAcrossClosures709=== CONT TestCompleteMultipartUpload_ErrorButObjectExists710=== CONT TestRedundantMultipartUpload711=== CONT TestPush_SignsNarinfosOfItsPendingObjects712=== CONT TestPush_RejectsBadRequests713=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit714=== CONT TestPush_RootsAreLockedInByteOrder715=== CONT TestPush_CompleteWaitsForCleanupOfThePush716=== CONT TestService_cleanupPendingClosuresHandler717=== CONT TestPush_RepeatedRootCommitsOnce718=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT719--- PASS: TestSkippedUploadsHandler (0.01s)720=== CONT TestPush_CompleteCommitsEveryRoot721=== CONT TestCompleteMultipartUnregistered722=== CONT TestPush_OverlappingRootsStoreOneRowPerKey723=== CONT TestReadRedirectUsesPublicS3URL724=== CONT TestReadProxyRangeRequest725=== CONT TestReadRedirectKeepsNarinfoProxied726=== CONT TestService_verifyS3Integrity727=== CONT TestService_createPendingClosureHandler7282026/10/06 21:13:47 INFO Received uploads request method=POST path=/api/pending_closures7292026/10/06 21:13:47 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst7302026/10/06 21:13:47 INFO Received uploads request method=POST path=/api/pending_closures7312026/10/06 21:13:47 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"732--- PASS: TestService_AuthMiddleware (0.30s)733=== CONT TestReadProxyDisabled734--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.30s)735=== CONT TestGCTaskStore_StartNew736--- PASS: TestGCTaskStore_StartNew (0.00s)737=== CONT TestIsValidUploadKey738=== RUN TestIsValidUploadKey/narinfo739=== PAUSE TestIsValidUploadKey/narinfo740=== RUN TestIsValidUploadKey/nar_zst741=== PAUSE TestIsValidUploadKey/nar_zst742=== RUN TestIsValidUploadKey/nar_xz743=== PAUSE TestIsValidUploadKey/nar_xz744=== RUN TestIsValidUploadKey/nar_plain745=== PAUSE TestIsValidUploadKey/nar_plain746=== RUN TestIsValidUploadKey/listing747=== PAUSE TestIsValidUploadKey/listing748=== RUN TestIsValidUploadKey/build_log749=== PAUSE TestIsValidUploadKey/build_log750=== RUN TestIsValidUploadKey/build_log_home-manager_file751=== PAUSE TestIsValidUploadKey/build_log_home-manager_file752=== RUN TestIsValidUploadKey/build_log_plus_in_name753=== PAUSE TestIsValidUploadKey/build_log_plus_in_name754=== RUN TestIsValidUploadKey/build_log_question_mark755=== PAUSE TestIsValidUploadKey/build_log_question_mark756=== RUN TestIsValidUploadKey/build_log_equals757=== PAUSE TestIsValidUploadKey/build_log_equals758=== RUN TestIsValidUploadKey/realisation759=== PAUSE TestIsValidUploadKey/realisation760=== RUN TestIsValidUploadKey/realisation_plus_in_output761=== PAUSE TestIsValidUploadKey/realisation_plus_in_output762=== RUN TestIsValidUploadKey/nix-cache-info763=== PAUSE TestIsValidUploadKey/nix-cache-info764=== RUN TestIsValidUploadKey/index.html765=== PAUSE TestIsValidUploadKey/index.html766=== RUN TestIsValidUploadKey/narinfo_key,_nar_type767=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type768=== RUN TestIsValidUploadKey/nar_key,_narinfo_type769=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type770=== RUN TestIsValidUploadKey/listing_key,_narinfo_type771=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type772=== RUN TestIsValidUploadKey/traversal773=== PAUSE TestIsValidUploadKey/traversal774=== RUN TestIsValidUploadKey/traversal_nar775=== PAUSE TestIsValidUploadKey/traversal_nar776=== RUN TestIsValidUploadKey/absolute777=== PAUSE TestIsValidUploadKey/absolute778=== RUN TestIsValidUploadKey/empty_key779=== PAUSE TestIsValidUploadKey/empty_key780=== RUN TestIsValidUploadKey/unknown_type781=== PAUSE TestIsValidUploadKey/unknown_type782=== CONT TestGCEndsOnShutdown783=== RUN TestGCEndsOnShutdown/before_the_run784=== PAUSE TestGCEndsOnShutdown/before_the_run785=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete786=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete787=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark788=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark789=== CONT TestReadProxyRootRedirectsToIndexHTML7902026/10/06 21:13:47 INFO Received uploads request method=POST path=/api/pending_closures791--- PASS: TestReadRedirectNar (0.35s)792=== CONT TestUploadHandlersRejectOversizedBody7932026/10/06 21:13:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7942026/10/06 21:13:47 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NzFhYzdiODctMzQ2ZC00Y2U0LWI4YTUtMjkxYTRjZTMxNWYwLjliODA2ZjRjLTUyYWYtNGY4OC05NjhjLTM2NDdmZTNkMWY5YXgxNzkxMzIxMjI3NDkzMzE4MzYz795=== RUN TestPush_RejectsBadRequests/no_roots796=== PAUSE TestPush_RejectsBadRequests/no_roots797=== RUN TestPush_RejectsBadRequests/no_objects798=== PAUSE TestPush_RejectsBadRequests/no_objects799=== RUN TestPush_RejectsBadRequests/bad_root800=== PAUSE TestPush_RejectsBadRequests/bad_root801=== RUN TestPush_RejectsBadRequests/root_not_in_objects802=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects803=== CONT TestCommitRacingPendingCleanupKeepsObjects8042026/10/06 21:13:47 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NzFhYzdiODctMzQ2ZC00Y2U0LWI4YTUtMjkxYTRjZTMxNWYwLjliODA2ZjRjLTUyYWYtNGY4OC05NjhjLTM2NDdmZTNkMWY5YXgxNzkxMzIxMjI3NDkzMzE4MzYz parts=1805--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.37s)806=== CONT TestReadProxyConditionalGet8072026/10/06 21:13:47 INFO Received push request method=POST path=/api/pushes8082026/10/06 21:13:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8092026/10/06 21:13:47 INFO Signed narinfos id=1 count=18102026/10/06 21:13:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8112026/10/06 21:13:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8122026/10/06 21:13:47 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"8132026/10/06 21:13:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8142026/10/06 21:13:47 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"8152026/10/06 21:13:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8162026/10/06 21:13:47 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=18172026/10/06 21:13:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8182026/10/06 21:13:47 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo819--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.39s)820=== CONT TestPushWaitsForSweepHoldingRow8212026/10/06 21:13:47 INFO Received uploads request method=POST path=/api/pending_closures8222026/10/06 21:13:47 INFO Received uploads request method=POST path=/api/pending_closures8232026/10/06 21:13:47 INFO Received uploads request method=POST path=/api/pending_closures824--- PASS: TestService_Rustfstest (0.45s)825=== CONT TestReadProxyOutlastsServerWriteTimeout8262026/10/06 21:13:47 INFO Received uploads request method=POST path=/api/pending_closures8272026/10/06 21:13:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8282026/10/06 21:13:47 INFO Received push request method=POST path=/api/pushes8292026/10/06 21:13:47 INFO Received uploads request method=POST path=/api/pending_closures830=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure831=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure832=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart833=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart834=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts835=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts836=== CONT TestUploadHandlersRejectInvalidKeys837=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info838=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info839=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal840=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal841=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key842=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key843=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key844=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key845=== CONT TestReadProxyHead846--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.52s)847=== CONT TestSweepRechecksPendingAfterLocking8482026/10/06 21:13:47 INFO Received push request method=POST path=/api/pushes8492026/10/06 21:13:47 INFO Received push request method=POST path=/api/pushes8502026/10/06 21:13:47 INFO Received complete push request method=POST path=/api/pushes/1/complete8512026-10-06 21:13:47.738 UTC [512] ERROR: could not obtain lock on row in relation "closures"8522026-10-06 21:13:47.738 UTC [512] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8532026-10-06 21:13:47.739 UTC [512] ERROR: could not obtain lock on row in relation "closures"8542026-10-06 21:13:47.739 UTC [512] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8552026-10-06 21:13:47.739 UTC [512] ERROR: could not obtain lock on row in relation "closures"8562026-10-06 21:13:47.739 UTC [512] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8572026-10-06 21:13:47.739 UTC [512] ERROR: could not obtain lock on row in relation "closures"8582026-10-06 21:13:47.739 UTC [512] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8592026-10-06 21:13:47.739 UTC [512] ERROR: could not obtain lock on row in relation "closures"8602026-10-06 21:13:47.739 UTC [512] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8612026/10/06 21:13:47 INFO Received push request method=POST path=/api/pushes862--- PASS: TestPush_RootsAreLockedInByteOrder (0.58s)863=== CONT TestReadProxyInvalidPath864--- PASS: TestPush_RepeatedRootCommitsOnce (0.58s)865=== CONT TestPendingClosureWriteTimeout866=== RUN TestPendingClosureWriteTimeout/empty867=== PAUSE TestPendingClosureWriteTimeout/empty868=== RUN TestPendingClosureWriteTimeout/400_objects869=== PAUSE TestPendingClosureWriteTimeout/400_objects870=== RUN TestPendingClosureWriteTimeout/670k_objects871=== PAUSE TestPendingClosureWriteTimeout/670k_objects872=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline873=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline874=== CONT TestGetExistingObjectsLocksRows8752026/10/06 21:13:47 INFO Received complete push request method=POST path=/api/pushes/1/complete8762026/10/06 21:13:47 INFO Received cleanup request method=DELETE path=/api/pending_closures8772026/10/06 21:13:47 INFO Aborted multipart uploads count=0 kept=08782026/10/06 21:13:47 INFO Received uploads request method=POST path=/api/pending_closures8792026/10/06 21:13:47 INFO Received push request method=POST path=/api/pushes8802026/10/06 21:13:47 INFO Received cleanup request method=DELETE path=/api/pending_closures8812026/10/06 21:13:47 INFO Aborted multipart uploads count=1 kept=08822026/10/06 21:13:47 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8832026-10-06 21:13:47.784 UTC [478] ERROR: Closure does not exist: id=18842026-10-06 21:13:47.784 UTC [478] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE8852026-10-06 21:13:47.784 UTC [478] STATEMENT: -- name: CommitPendingClosure :exec886 SELECT commit_pending_closure($1::bigint)887 888--- PASS: TestService_cleanupPendingClosuresHandler (0.62s)889=== CONT TestReadProxy404890--- PASS: TestReadRedirectKeepsNarinfoProxied (0.63s)891=== CONT TestRegisterCompletedObjectNeedsPendingRow8922026/10/06 21:13:47 INFO Received push request method=POST path=/api/pushes8932026/10/06 21:13:47 INFO Received complete push request method=POST path=/api/pushes/1/complete8942026/10/06 21:13:47 INFO Aborted multipart uploads count=0 kept=08952026/10/06 21:13:47 WARN Force mode enabled - objects will be deleted immediately without grace period896--- PASS: TestPush_CompleteCommitsEveryRoot (0.67s)897=== CONT TestMultipartCleanup898--- PASS: TestReadProxyRangeRequest (0.68s)899=== CONT TestServerTLSConfig900=== RUN TestServerTLSConfig/no_client_CA901=== PAUSE TestServerTLSConfig/no_client_CA902=== RUN TestServerTLSConfig/missing_CA_file903=== PAUSE TestServerTLSConfig/missing_CA_file904=== RUN TestServerTLSConfig/not_a_PEM_file905=== PAUSE TestServerTLSConfig/not_a_PEM_file906=== CONT TestService_NativeMTLS9072026/10/06 21:13:47 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=09082026/10/06 21:13:47 INFO Vacuumed table table=pending_closures9092026/10/06 21:13:47 INFO Vacuumed table table=pending_objects9102026/10/06 21:13:47 INFO Vacuumed table table=multipart_uploads9112026/10/06 21:13:47 INFO Vacuumed table table=closures9122026/10/06 21:13:47 INFO Vacuumed table table=objects9132026/10/06 21:13:47 INFO Received complete push request method=POST path=/api/pushes/2/complete914--- PASS: TestReadRedirectUsesPublicS3URL (0.71s)915=== CONT TestFailedS3DeleteKeepsTombstone916--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.71s)917=== CONT TestReadProxyNarStreaming9182026/10/06 21:13:47 INFO Received uploads request method=POST path=/api/pending_closures9192026/10/06 21:13:47 INFO Received uploads request method=POST path=/api/pending_closures9202026/10/06 21:13:47 INFO Received uploads request method=POST path=/api/pending_closures9212026/10/06 21:13:47 INFO Received push request method=POST path=/api/pushes922--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.76s)923=== CONT TestMetricsInventory9242026/10/06 21:13:47 INFO Received uploads request method=POST path=/api/pending_closures9252026/10/06 21:13:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9262026/10/06 21:13:47 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst927--- PASS: TestCompleteMultipartUnregistered (0.80s)928=== CONT TestForceGCDuringPushOffersSweptObject929=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows930=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows931=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check932=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check933=== CONT TestNARDeduplicationMetadataUploadBug9342026-10-06 21:13:47.970 UTC [502] ERROR: Push does not exist: id=19352026-10-06 21:13:47.970 UTC [502] CONTEXT: PL/pgSQL function commit_push(bigint) line 10 at RAISE9362026-10-06 21:13:47.970 UTC [502] STATEMENT: SELECT commit_push($1)937--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.80s)938=== CONT TestSweepSkipsRowsLockedByPush9392026/10/06 21:13:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete940--- PASS: TestReadProxyDisabled (0.53s)941=== CONT TestCreatePendingClosureRejectsOversizedNAR9422026/10/06 21:13:47 INFO Received uploads request method=POST path=/api/pending_closures943--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)944=== CONT TestPresentReportsOnlyClosureRoots9452026/10/06 21:13:48 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NzFhYzdiODctMzQ2ZC00Y2U0LWI4YTUtMjkxYTRjZTMxNWYwLmRhYjBjMDI4LTFmYjItNDVjYi1iMGQyLWI3MDEzZmIxMzQ5Y3gxNzkxMzIxMjI3NTk0OTI5MTcw parts=129462026/10/06 21:13:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9472026/10/06 21:13:48 INFO Received uploads request method=POST path=/api/pending_closures948--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.64s)949=== CONT TestCacheConfigHandlerMaxNarSize950--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)951=== CONT TestGenerateLandingPage952--- PASS: TestGenerateLandingPage (0.00s)953=== CONT TestCreatePin_ReservedPins9542026/10/06 21:13:48 INFO Received uploads request method=POST path=/api/pending_closures9552026/10/06 21:13:48 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NzFhYzdiODctMzQ2ZC00Y2U0LWI4YTUtMjkxYTRjZTMxNWYwLmEwMmJkMGU2LWE5YWQtNGIyMi1hNDMyLTkyMmM5ZGEwZDY4NHgxNzkxMzIxMjI3NjM5NTQ2Nzc5 parts=129562026/10/06 21:13:48 INFO Received uploads request method=POST path=/api/pending_closures957--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.96s)958=== CONT TestService_readinessHandler959--- PASS: TestReadProxyConditionalGet (0.60s)960=== CONT TestOrphanedObjectsGCStressTest9612026/10/06 21:13:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44839/oidc9622026/10/06 21:13:48 INFO Received uploads request method=POST path=/api/pending_closures9632026/10/06 21:13:48 INFO Aborted multipart uploads count=0 kept=09642026/10/06 21:13:48 WARN Force mode enabled - objects will be deleted immediately without grace period9652026/10/06 21:13:48 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09662026/10/06 21:13:48 INFO Vacuumed table table=pending_closures9672026/10/06 21:13:48 INFO Vacuumed table table=pending_objects9682026/10/06 21:13:48 INFO Vacuumed table table=multipart_uploads9692026/10/06 21:13:48 INFO Vacuumed table table=closures9702026/10/06 21:13:48 INFO Vacuumed table table=objects971--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.71s)972=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection973--- PASS: TestReadProxyHead (0.56s)974=== CONT TestOrphanedObjectsGC9752026/10/06 21:13:48 INFO Aborted multipart uploads count=0 kept=09762026/10/06 21:13:48 WARN Force mode enabled - objects will be deleted immediately without grace period9772026/10/06 21:13:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete978--- PASS: TestReadProxyInvalidPath (0.54s)979=== CONT TestService_healthCheckHandler9802026/10/06 21:13:48 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09812026/10/06 21:13:48 INFO Vacuumed table table=pending_closures9822026/10/06 21:13:48 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NzFhYzdiODctMzQ2ZC00Y2U0LWI4YTUtMjkxYTRjZTMxNWYwLjkxZDIzZGI1LTliYmMtNGQ1Ny05ZTY2LWQwNzlmYTI4NzI2ZHgxNzkxMzIxMjI3ODg4MzM4ODg5 parts=109832026/10/06 21:13:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9842026/10/06 21:13:48 INFO Vacuumed table table=pending_objects9852026/10/06 21:13:48 INFO Vacuumed table table=multipart_uploads9862026/10/06 21:13:48 INFO Vacuumed table table=closures9872026/10/06 21:13:48 INFO Vacuumed table table=objects9882026/10/06 21:13:48 INFO Completed upload id=19892026/10/06 21:13:48 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000990--- PASS: TestSweepRechecksPendingAfterLocking (0.62s)991=== CONT TestGCSweepDeliversEachKeyOnce9922026/10/06 21:13:48 INFO Received uploads request method=POST path=/api/pending_closures9932026/10/06 21:13:48 INFO Starting cleanup of old closures method=DELETE path=/api/closures9942026/10/06 21:13:48 INFO Aborted multipart uploads count=0 kept=0995--- PASS: TestGetExistingObjectsLocksRows (0.58s)996=== CONT TestObjectStatsTrigger9972026/10/06 21:13:48 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=09982026/10/06 21:13:48 INFO Vacuumed table table=pending_closures9992026/10/06 21:13:48 INFO Vacuumed table table=pending_objects10002026/10/06 21:13:48 INFO Vacuumed table table=multipart_uploads10012026/10/06 21:13:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10022026/10/06 21:13:48 INFO Vacuumed table table=closures10032026/10/06 21:13:48 INFO Vacuumed table table=objects1004--- PASS: TestReadProxy404 (0.57s)1005=== CONT TestGracefulShutdownDrainsInflight10062026/10/06 21:13:48 INFO Starting HTTP server address=127.0.0.1:4169310072026/10/06 21:13:48 INFO Shutdown signal received, draining in-flight requests timeout=10s10082026/10/06 21:13:48 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001009--- PASS: TestService_createPendingClosureHandler (1.19s)1010=== CONT TestTombstonedObjectOfferedWithoutWaiting1011--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.56s)1012=== CONT TestPendingCleanupUsesOneCutoff10132026/10/06 21:13:48 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NzFhYzdiODctMzQ2ZC00Y2U0LWI4YTUtMjkxYTRjZTMxNWYwLjA1YTQxOWYwLTMwNWYtNDFjNC05MDRjLWNjZjRjMDZmZmU2M3gxNzkxMzIxMjI3OTM4MjIzODg0 parts=1010142026/10/06 21:13:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10152026/10/06 21:13:48 INFO Completed upload id=110162026/10/06 21:13:48 INFO Received uploads request method=POST path=/api/pending_closures10172026/10/06 21:13:48 INFO Received uploads request method=POST path=/api/pending_closures10182026/10/06 21:13:48 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10192026/10/06 21:13:48 WARN Found objects in DB but missing from S3, will re-upload count=11020--- PASS: TestService_verifyS3Integrity (1.21s)1021=== CONT TestGCTaskStore_Fail1022--- PASS: TestGCTaskStore_Fail (0.00s)1023=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded10242026/10/06 21:13:48 INFO Received uploads request method=POST path=/api/pending_closures10252026/10/06 21:13:48 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10262026/10/06 21:13:48 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1027--- PASS: TestService_NativeMTLS (0.56s)1028=== CONT TestGCTaskStore_PhaseUpdates1029--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1030=== CONT TestDeduplicatedObjectsRecordedAsPending1031--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1032=== CONT TestGCTaskStore_CompletedAllowsNewTask1033--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1034=== CONT TestClientSharedPathCommittedMidPush10352026/10/06 21:13:48 INFO Received uploads request method=POST path=/api/pending_closures1036--- PASS: TestReadProxyNarStreaming (0.58s)1037=== CONT TestClientWithDependencies1038--- PASS: TestMetricsInventory (0.57s)1039=== CONT TestGCTaskStore_GetReturnsLatest1040--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1041=== CONT TestPushDedupSurvivesConcurrentGC10422026/10/06 21:13:48 INFO Received cleanup request method=DELETE path=/api/pending_closures10432026/10/06 21:13:48 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket39/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""10442026/10/06 21:13:48 INFO Aborted multipart uploads count=0 kept=110452026/10/06 21:13:48 INFO Received cleanup request method=DELETE path=/api/pending_closures10462026/10/06 21:13:48 INFO Aborted multipart uploads count=1 kept=010472026/10/06 21:13:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1048--- PASS: TestMultipartCleanup (0.66s)1049=== CONT TestClientMultipleUploads10502026/10/06 21:13:48 INFO Aborted multipart uploads count=0 kept=010512026/10/06 21:13:48 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NzFhYzdiODctMzQ2ZC00Y2U0LWI4YTUtMjkxYTRjZTMxNWYwLjM3ZTBiNWE3LTU1ZTktNGQ1ZC05OTc1LTBhY2IzYjAyYmM5OHgxNzkxMzIxMjI4MTIyNDM4NTMw error="Get \"http://127.0.0.1:1/bucket10/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"10522026/10/06 21:13:48 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NzFhYzdiODctMzQ2ZC00Y2U0LWI4YTUtMjkxYTRjZTMxNWYwLjFlZDc4NjNlLTEzNzItNDE3MS05YTUyLTExOWFmZWQyNjBlMXgxNzkxMzIxMjI4MTA3MTM3MDc3 parts=1210532026/10/06 21:13:48 WARN Force mode enabled - objects will be deleted immediately without grace period10542026/10/06 21:13:48 INFO Received cleanup request method=DELETE path=/api/pending_closures10552026/10/06 21:13:48 INFO Aborted multipart uploads count=1 kept=010562026/10/06 21:13:48 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."10572026/10/06 21:13:48 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1058--- PASS: TestRedundantMultipartUpload (1.36s)1059=== CONT TestGCTaskStore_GetEmpty1060--- PASS: TestGCTaskStore_GetEmpty (0.00s)1061=== CONT TestPresentRefreshesOnlyStaleClosures1062--- PASS: TestFailedS3DeleteKeepsTombstone (0.65s)1063=== CONT TestGCTaskStore_ConflictDifferentParams1064--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1065=== CONT TestGCSweepSkipsPendingObjects1066=== NAME TestNARDeduplicationMetadataUploadBug1067 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2156185783/001/store/kh6d5dvb7lqyjr33ydgas0b0ck8ckbvf-file1.txt10682026/10/06 21:13:48 INFO Aborted multipart uploads count=0 kept=010692026/10/06 21:13:48 WARN Force mode enabled - objects will be deleted immediately without grace period10702026/10/06 21:13:48 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010712026/10/06 21:13:48 INFO Vacuumed table table=pending_closures10722026/10/06 21:13:48 INFO Vacuumed table table=pending_objects10732026/10/06 21:13:48 INFO Vacuumed table table=multipart_uploads10742026/10/06 21:13:48 INFO Vacuumed table table=closures1075--- PASS: TestPresentReportsOnlyClosureRoots (0.57s)1076=== CONT TestGCMetrics10772026/10/06 21:13:48 INFO Vacuumed table table=objects10782026/10/06 21:13:48 INFO Aborted multipart uploads count=0 kept=010792026/10/06 21:13:48 WARN Force mode enabled - objects will be deleted immediately without grace period10802026/10/06 21:13:48 WARN readiness check failed error="closed pool"1081--- PASS: TestService_readinessHandler (0.45s)1082=== CONT TestReadProxyContentNegotiation10832026/10/06 21:13:48 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=010842026/10/06 21:13:48 INFO Vacuumed table table=pending_closures10852026/10/06 21:13:48 INFO Vacuumed table table=pending_objects10862026/10/06 21:13:48 INFO Vacuumed table table=multipart_uploads10872026/10/06 21:13:48 INFO Vacuumed table table=closures10882026/10/06 21:13:48 INFO Vacuumed table table=objects1089--- PASS: TestSweepSkipsRowsLockedByPush (0.62s)1090=== CONT TestGCBugBareHashReferences10912026/10/06 21:13:48 INFO Received push request method=POST path=/api/pushes10922026/10/06 21:13:48 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10932026/10/06 21:13:48 INFO Uploading kh6d5dvb7lqyjr33ydgas0b0ck8ckbvf-file1.txt (160B)10942026/10/06 21:13:48 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10952026/10/06 21:13:48 WARN Refused reserved pin name=worker-x86_64-linux10962026/10/06 21:13:48 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10972026/10/06 21:13:48 INFO Received create pin request method=POST path=/api/pins/my-app10982026/10/06 21:13:48 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1099--- PASS: TestCreatePin_ReservedPins (0.52s)1100=== CONT TestReadProxyNarinfoAlreadyDecompressed11012026/10/06 21:13:48 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11022026/10/06 21:13:48 WARN Failed to register uploaded object key=kh6d5dvb7lqyjr33ydgas0b0ck8ckbvf.ls error="server returned 404: 404 page not found\n"11032026/10/06 21:13:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11042026/10/06 21:13:48 INFO Signed narinfos id=1 count=111052026/10/06 21:13:48 INFO Uploading 1 narinfos11062026/10/06 21:13:48 INFO Received complete push request method=POST path=/api/pushes/1/complete11072026/10/06 21:13:48 WARN Failed to register uploaded object key=kh6d5dvb7lqyjr33ydgas0b0ck8ckbvf.narinfo error="server returned 404: 404 page not found\n"11082026/10/06 21:13:48 INFO Received uploads request method=POST path=/api/pending_closures11092026/10/06 21:13:48 INFO Upload complete. (66ms)1110=== NAME TestNARDeduplicationMetadataUploadBug1111 metadata_upload_test.go:54: Retrieved narinfo from S3:1112 StorePath: /build/TestNARDeduplicationMetadataUploadBug2156185783/001/store/kh6d5dvb7lqyjr33ydgas0b0ck8ckbvf-file1.txt1113 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1114 Compression: zstd1115 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1116 NarSize: 1601117 References: 1118 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1119 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1120 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1121 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1122--- PASS: TestPushWaitsForSweepHoldingRow (1.13s)1123=== CONT TestGCAdvisoryLockBlocksConcurrentRun1124=== NAME TestNARDeduplicationMetadataUploadBug1125 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2156185783/001/store/h0ipc0jlvlr1bam5ams4brz5qk5qxbfj-file2.txt1126--- PASS: TestService_healthCheckHandler (0.43s)1127=== CONT TestReadProxyNarinfo11282026/10/06 21:13:48 INFO Received push request method=POST path=/api/pushes11292026/10/06 21:13:48 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11302026/10/06 21:13:48 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11312026/10/06 21:13:48 INFO Signed narinfos id=2 count=111322026/10/06 21:13:48 INFO Aborted multipart uploads count=0 kept=011332026/10/06 21:13:48 WARN Failed to register uploaded object key=h0ipc0jlvlr1bam5ams4brz5qk5qxbfj.ls error="server returned 404: 404 page not found\n"11342026/10/06 21:13:48 INFO Uploading 1 narinfos11352026/10/06 21:13:48 WARN Force mode enabled - objects will be deleted immediately without grace period11362026/10/06 21:13:48 INFO Received complete push request method=POST path=/api/pushes/2/complete11372026/10/06 21:13:48 WARN Failed to register uploaded object key=h0ipc0jlvlr1bam5ams4brz5qk5qxbfj.narinfo error="server returned 404: 404 page not found\n"11382026/10/06 21:13:48 INFO Upload complete. (49ms)1139=== NAME TestNARDeduplicationMetadataUploadBug1140 metadata_upload_test.go:76: Retrieved narinfo from S3:1141 StorePath: /build/TestNARDeduplicationMetadataUploadBug2156185783/001/store/h0ipc0jlvlr1bam5ams4brz5qk5qxbfj-file2.txt1142 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1143 Compression: zstd1144 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1145 NarSize: 1601146 References: 1147 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1148--- PASS: TestObjectStatsTrigger (0.46s)1149=== CONT TestLeadEndsOnShutdown1150=== NAME TestNARDeduplicationMetadataUploadBug1151 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1152 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1153 {"version":1,"root":{"type":"regular","size":44}}1154--- PASS: TestNARDeduplicationMetadataUploadBug (0.82s)1155=== CONT TestLeadIncumbentAnnouncesAtOnce11562026/10/06 21:13:48 INFO Received uploads request method=POST path=/api/pending_closures11572026/10/06 21:13:48 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=011582026/10/06 21:13:48 INFO Vacuumed table table=pending_closures11592026/10/06 21:13:48 INFO Vacuumed table table=pending_objects11602026/10/06 21:13:48 INFO Vacuumed table table=multipart_uploads11612026/10/06 21:13:48 INFO Vacuumed table table=closures11622026/10/06 21:13:48 INFO Vacuumed table table=objects11632026/10/06 21:13:48 INFO Received uploads request method=POST path=/api/pending_closures1164--- PASS: TestGCSweepDeliversEachKeyOnce (0.50s)1165=== CONT TestIsValidCachePath1166=== RUN TestIsValidCachePath/narinfo1167=== PAUSE TestIsValidCachePath/narinfo1168=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1169=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1170=== RUN TestIsValidCachePath/nar_zst1171=== PAUSE TestIsValidCachePath/nar_zst1172=== RUN TestIsValidCachePath/nar_xz1173=== PAUSE TestIsValidCachePath/nar_xz1174=== RUN TestIsValidCachePath/nar_bz21175=== PAUSE TestIsValidCachePath/nar_bz21176=== RUN TestIsValidCachePath/nar_uncompressed1177=== PAUSE TestIsValidCachePath/nar_uncompressed1178=== RUN TestIsValidCachePath/ls1179=== PAUSE TestIsValidCachePath/ls1180=== RUN TestIsValidCachePath/log1181=== PAUSE TestIsValidCachePath/log1182=== RUN TestIsValidCachePath/realisation1183=== PAUSE TestIsValidCachePath/realisation1184=== RUN TestIsValidCachePath/nix-cache-info1185=== PAUSE TestIsValidCachePath/nix-cache-info1186=== RUN TestIsValidCachePath/index.html1187=== PAUSE TestIsValidCachePath/index.html1188=== RUN TestIsValidCachePath/traversal_parent1189=== PAUSE TestIsValidCachePath/traversal_parent1190=== RUN TestIsValidCachePath/traversal_in_middle1191=== PAUSE TestIsValidCachePath/traversal_in_middle1192=== RUN TestIsValidCachePath/invalid_char_e1193=== PAUSE TestIsValidCachePath/invalid_char_e1194=== RUN TestIsValidCachePath/invalid_char_u1195=== PAUSE TestIsValidCachePath/invalid_char_u1196=== RUN TestIsValidCachePath/random_path1197=== PAUSE TestIsValidCachePath/random_path1198=== RUN TestIsValidCachePath/empty1199=== PAUSE TestIsValidCachePath/empty1200=== RUN TestIsValidCachePath/leading_slash1201=== PAUSE TestIsValidCachePath/leading_slash1202=== RUN TestIsValidCachePath/wrong_extension1203=== PAUSE TestIsValidCachePath/wrong_extension1204=== RUN TestIsValidCachePath/short_hash1205=== PAUSE TestIsValidCachePath/short_hash1206=== CONT TestLeadElectsOneAndHandsOver12072026/10/06 21:13:48 INFO Received cleanup request method=DELETE path=/api/pending_closures12082026/10/06 21:13:48 INFO Received uploads request method=POST path=/api/pending_closures1209--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.47s)1210=== CONT TestProxyHeadersOnlyTrustedOnSocket12112026/10/06 21:13:48 INFO Received uploads request method=POST path=/api/pending_closures1212--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.48s)1213=== CONT TestConnectWaitsForAPeerMigration12142026/10/06 21:13:48 INFO Received uploads request method=POST path=/api/pending_closures1215--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.64s)1216=== CONT TestGCTaskStore_DeduplicateSameParams1217--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1218=== CONT TestParseSingleRange1219=== RUN TestParseSingleRange/none1220=== PAUSE TestParseSingleRange/none1221=== RUN TestParseSingleRange/unknown_unit1222=== PAUSE TestParseSingleRange/unknown_unit1223=== RUN TestParseSingleRange/multi-range_ignored1224=== PAUSE TestParseSingleRange/multi-range_ignored1225=== RUN TestParseSingleRange/malformed_no_dash1226=== PAUSE TestParseSingleRange/malformed_no_dash1227=== RUN TestParseSingleRange/malformed_both_empty1228=== PAUSE TestParseSingleRange/malformed_both_empty1229=== RUN TestParseSingleRange/malformed_end_before_start1230=== PAUSE TestParseSingleRange/malformed_end_before_start1231=== RUN TestParseSingleRange/closed1232=== PAUSE TestParseSingleRange/closed1233=== RUN TestParseSingleRange/open-ended1234=== PAUSE TestParseSingleRange/open-ended1235=== RUN TestParseSingleRange/end_clamped_to_size1236=== PAUSE TestParseSingleRange/end_clamped_to_size1237=== RUN TestParseSingleRange/suffix1238=== PAUSE TestParseSingleRange/suffix1239=== RUN TestParseSingleRange/suffix_exceeds_size1240=== PAUSE TestParseSingleRange/suffix_exceeds_size1241=== RUN TestParseSingleRange/single_byte1242=== PAUSE TestParseSingleRange/single_byte1243=== RUN TestParseSingleRange/start_past_EOF1244=== PAUSE TestParseSingleRange/start_past_EOF1245=== RUN TestParseSingleRange/start_far_past_EOF1246=== PAUSE TestParseSingleRange/start_far_past_EOF1247=== CONT TestResolveDBConnectionString1248=== RUN TestResolveDBConnectionString/flag_wins1249=== PAUSE TestResolveDBConnectionString/flag_wins1250=== RUN TestResolveDBConnectionString/file_when_flag_empty1251=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1252=== RUN TestResolveDBConnectionString/missing_file_is_an_error1253=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1254=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1255=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1256=== RUN TestResolveDBConnectionString/nothing_configured1257=== PAUSE TestResolveDBConnectionString/nothing_configured1258=== CONT TestPresentNotReportedWhileGCDeletesClosure1259=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1260=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1261=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1262=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1263=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1264--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.47s)1265=== CONT TestProxyWriteTimeout1266=== RUN TestProxyWriteTimeout/narinfo1267=== PAUSE TestProxyWriteTimeout/narinfo1268=== RUN TestProxyWriteTimeout/1_GiB_nar1269=== PAUSE TestProxyWriteTimeout/1_GiB_nar1270=== RUN TestProxyWriteTimeout/10_GiB_nar1271=== PAUSE TestProxyWriteTimeout/10_GiB_nar1272=== RUN TestProxyWriteTimeout/unknown_size1273=== PAUSE TestProxyWriteTimeout/unknown_size1274=== CONT TestClientFallsBackToClosures12752026/10/06 21:13:48 INFO Received uploads request method=POST path=/api/pending_closures12762026/10/06 21:13:48 INFO Received uploads request method=POST path=/api/pending_closures1277=== NAME TestClientMultipleUploads1278 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads3199308100/001/store/6zc8gb7h4vhhjxqdixmsdcxhvqsq9niv-test-file-0.txt1279=== NAME TestClientWithDependencies1280 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2372532699/001/store/j4q204r98fcv77d0pb00wxrl78hzix1i-test-script12812026/10/06 21:13:49 INFO Aborted multipart uploads count=0 kept=01282=== NAME TestOrphanedObjectsGC1283 orphaned_objects_gc_test.go:290: GC Test Summary:1284 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1285 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1286 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1287 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1288 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1289--- PASS: TestOrphanedObjectsGC (0.77s)1290=== CONT TestClientCADerivations12912026/10/06 21:13:49 WARN Force mode enabled - objects will be deleted immediately without grace period1292--- PASS: TestPresentRefreshesOnlyStaleClosures (0.48s)1293=== CONT TestPinProtectsFromGC12942026/10/06 21:13: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=012952026/10/06 21:13:49 INFO Vacuumed table table=pending_closures12962026/10/06 21:13:49 INFO Vacuumed table table=pending_objects12972026/10/06 21:13:49 INFO Vacuumed table table=multipart_uploads12982026/10/06 21:13:49 INFO Vacuumed table table=closures12992026/10/06 21:13:49 INFO Vacuumed table table=objects13002026/10/06 21:13:49 INFO Aborted multipart uploads count=0 kept=013012026/10/06 21:13:49 INFO Aborted multipart uploads count=0 kept=013022026/10/06 21:13:49 INFO Received push request method=POST path=/api/pushes1303--- PASS: TestGCSweepSkipsPendingObjects (0.50s)1304=== CONT TestClientPushesUseOnePush13052026/10/06 21:13:49 WARN Force mode enabled - objects will be deleted immediately without grace period13062026/10/06 21:13:49 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)13072026/10/06 21:13:49 INFO Uploading a3657009cwvl7jxcabjnpas85apqsfpm-top (224B)13082026/10/06 21:13:49 INFO Uploading 2mp5y7vnrd0abyydv1mbj3cirbwb7h7h-shared-dep (136B)13092026/10/06 21:13:49 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=01310=== NAME TestClientWithDependencies13112026/10/06 21:13: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=01312 client_integration_test.go:615: Found 1 dependencies (including self)13132026/10/06 21:13:49 INFO Vacuumed table table=pending_closures13142026/10/06 21:13:49 INFO Vacuumed table table=pending_closures13152026/10/06 21:13:49 INFO Vacuumed table table=pending_objects13162026/10/06 21:13:49 INFO Vacuumed table table=multipart_uploads13172026/10/06 21:13:49 INFO Vacuumed table table=closures13182026/10/06 21:13:49 WARN Failed to register uploaded object key=a3657009cwvl7jxcabjnpas85apqsfpm.ls error="server returned 404: 404 page not found\n"13192026/10/06 21:13:49 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13202026/10/06 21:13:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13212026/10/06 21:13:49 INFO Vacuumed table table=objects13222026/10/06 21:13:49 WARN Failed to register uploaded object key=nar/1hj5mz5mnw5ck28dm1p4b87n9ykghcmg13zaxy4yir6m3kf1bx3s.nar.zst error="server returned 404: 404 page not found\n"13232026/10/06 21:13:49 INFO Vacuumed table table=pending_objects13242026/10/06 21:13:49 WARN Failed to register uploaded object key=2mp5y7vnrd0abyydv1mbj3cirbwb7h7h.ls error="server returned 404: 404 page not found\n"1325=== NAME TestClientMultipleUploads13262026/10/06 21:13:49 INFO Signed narinfos id=1 count=21327 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads3199308100/001/store/3kvwirry8xfirzry32kxhgpibkzhzq4s-test-file-1.txt13282026/10/06 21:13:49 INFO Uploading 2 narinfos13292026/10/06 21:13:49 INFO Vacuumed table table=multipart_uploads13302026/10/06 21:13:49 INFO Vacuumed table table=closures1331--- PASS: TestGCMetrics (0.48s)1332=== CONT TestClientErrorHandling1333=== RUN TestClientErrorHandling/InvalidStorePath1334=== PAUSE TestClientErrorHandling/InvalidStorePath1335=== RUN TestClientErrorHandling/InvalidAuthToken1336=== PAUSE TestClientErrorHandling/InvalidAuthToken1337=== RUN TestClientErrorHandling/ServerNotAvailable1338=== PAUSE TestClientErrorHandling/ServerNotAvailable1339=== CONT TestCacheStatsHandler13402026/10/06 21:13:49 WARN Failed to register uploaded object key=2mp5y7vnrd0abyydv1mbj3cirbwb7h7h.narinfo error="server returned 404: 404 page not found\n"13412026/10/06 21:13:49 INFO Received complete push request method=POST path=/api/pushes/1/complete13422026/10/06 21:13:49 WARN Failed to register uploaded object key=a3657009cwvl7jxcabjnpas85apqsfpm.narinfo error="server returned 404: 404 page not found\n"13432026/10/06 21:13:49 INFO Vacuumed table table=objects13442026/10/06 21:13:49 INFO Aborted multipart uploads count=0 kept=013452026/10/06 21:13:49 WARN Force mode enabled - objects will be deleted immediately without grace period13462026/10/06 21:13:49 INFO Upload complete. (65ms)13472026/10/06 21:13: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=01348=== NAME TestClientSharedPathCommittedMidPush1349 client_integration_test.go:680: Retrieved narinfo from S3:1350 StorePath: /build/TestClientSharedPathCommittedMidPush3913165650/001/store/2mp5y7vnrd0abyydv1mbj3cirbwb7h7h-shared-dep1351 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1352 Compression: zstd1353 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821354 NarSize: 1361355 References: 1356 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n13572026/10/06 21:13:49 INFO Vacuumed table table=pending_closures1358 client_integration_test.go:680: Retrieved narinfo from S3:1359 StorePath: /build/TestClientSharedPathCommittedMidPush3913165650/001/store/a3657009cwvl7jxcabjnpas85apqsfpm-top1360 URL: nar/1hj5mz5mnw5ck28dm1p4b87n9ykghcmg13zaxy4yir6m3kf1bx3s.nar.zst1361 Compression: zstd1362 NarHash: sha256:1hj5mz5mnw5ck28dm1p4b87n9ykghcmg13zaxy4yir6m3kf1bx3s1363 NarSize: 2241364 References: /build/TestClientSharedPathCommittedMidPush3913165650/001/store/2mp5y7vnrd0abyydv1mbj3cirbwb7h7h-shared-dep1365 CA: text:sha256:0hmm9738zwql3fn4pxkymmg5zkxghhh7237rz6i87vpf1irnb81c13662026/10/06 21:13:49 INFO Vacuumed table table=pending_objects13672026/10/06 21:13:49 INFO Vacuumed table table=multipart_uploads13682026/10/06 21:13:49 INFO Vacuumed table table=closures13692026/10/06 21:13:49 INFO Vacuumed table table=objects1370--- PASS: TestClientSharedPathCommittedMidPush (0.64s)1371=== CONT TestService_ReadAuthMiddleware1372--- PASS: TestPushDedupSurvivesConcurrentGC (0.57s)1373=== CONT TestCacheConfigHandler1374=== RUN TestCacheConfigHandler/full_config,_no_issuer1375=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1376=== RUN TestCacheConfigHandler/no_cache_url_configured1377=== PAUSE TestCacheConfigHandler/no_cache_url_configured1378=== RUN TestCacheConfigHandler/no_signing_keys1379=== PAUSE TestCacheConfigHandler/no_signing_keys1380=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1381=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1382=== CONT TestService_ReadScope_PublicByDefault1383=== NAME TestClientMultipleUploads1384 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads3199308100/001/store/wxvhsy7b6dcyapv7cj6npk8ac8fx5gdi-test-file-2.txt1385--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.47s)1386=== CONT TestService_RequireScope_OIDC1387--- PASS: TestReadProxyContentNegotiation (0.54s)1388=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13892026/10/06 21:13:49 INFO Received push request method=POST path=/api/pushes13902026/10/06 21:13:49 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13912026/10/06 21:13:49 INFO Uploading j4q204r98fcv77d0pb00wxrl78hzix1i-test-script (136B)13922026/10/06 21:13:49 WARN Failed to register uploaded object key=j4q204r98fcv77d0pb00wxrl78hzix1i.ls error="server returned 404: 404 page not found\n"13932026/10/06 21:13:49 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"13942026/10/06 21:13:49 WARN Failed to register uploaded object key=log/gsjq3nviqsai74882j1wjwywl78w3ak0-test-script.drv error="server returned 404: 404 page not found\n"13952026/10/06 21:13:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13962026/10/06 21:13:49 INFO Signed narinfos id=1 count=113972026/10/06 21:13:49 INFO Uploading 1 narinfos13982026/10/06 21:13:49 INFO Received complete push request method=POST path=/api/pushes/1/complete13992026/10/06 21:13:49 WARN Failed to register uploaded object key=j4q204r98fcv77d0pb00wxrl78hzix1i.narinfo error="server returned 404: 404 page not found\n"14002026/10/06 21:13:49 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=nixbld database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1401--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.45s)1402=== CONT TestService_AuthMiddleware_OIDC14032026/10/06 21:13:49 INFO Upload complete. (67ms)1404=== NAME TestClientWithDependencies1405 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2372532699/001/store) requires matching store prefix1406--- PASS: TestClientWithDependencies (0.69s)1407=== CONT TestClientIntegration14082026/10/06 21:13:49 INFO Received push request method=POST path=/api/pushes14092026/10/06 21:13:49 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)14102026/10/06 21:13:49 INFO Uploading 6zc8gb7h4vhhjxqdixmsdcxhvqsq9niv-test-file-0.txt (160B)14112026/10/06 21:13:49 INFO Uploading 3kvwirry8xfirzry32kxhgpibkzhzq4s-test-file-1.txt (160B)14122026/10/06 21:13:49 INFO Uploading wxvhsy7b6dcyapv7cj6npk8ac8fx5gdi-test-file-2.txt (160B)14132026/10/06 21:13:49 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"14142026/10/06 21:13:49 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"14152026/10/06 21:13:49 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"14162026/10/06 21:13:49 WARN Failed to register uploaded object key=3kvwirry8xfirzry32kxhgpibkzhzq4s.ls error="server returned 404: 404 page not found\n"14172026/10/06 21:13:49 WARN Failed to register uploaded object key=wxvhsy7b6dcyapv7cj6npk8ac8fx5gdi.ls error="server returned 404: 404 page not found\n"14182026/10/06 21:13:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14192026/10/06 21:13:49 WARN Failed to register uploaded object key=6zc8gb7h4vhhjxqdixmsdcxhvqsq9niv.ls error="server returned 404: 404 page not found\n"14202026/10/06 21:13:49 INFO Signed narinfos id=1 count=314212026/10/06 21:13:49 INFO Uploading 3 narinfos14222026/10/06 21:13:49 WARN Failed to register uploaded object key=3kvwirry8xfirzry32kxhgpibkzhzq4s.narinfo error="server returned 404: 404 page not found\n"14232026/10/06 21:13:49 WARN Failed to register uploaded object key=wxvhsy7b6dcyapv7cj6npk8ac8fx5gdi.narinfo error="server returned 404: 404 page not found\n"14242026/10/06 21:13:49 INFO Received complete push request method=POST path=/api/pushes/1/complete14252026/10/06 21:13:49 WARN Failed to register uploaded object key=6zc8gb7h4vhhjxqdixmsdcxhvqsq9niv.narinfo error="server returned 404: 404 page not found\n"14262026/10/06 21:13:49 INFO lead: acquired remote=192.0.2.1:123414272026/10/06 21:13:49 INFO Upload complete. (67ms)1428=== NAME TestClientMultipleUploads1429 client_integration_test.go:369: Uploaded 3 paths in 104.626693ms1430--- PASS: TestClientMultipleUploads (0.69s)1431=== CONT TestService_AuthMiddleware_MTLSProxyHeader14322026/10/06 21:13:49 INFO lead: acquired remote=192.0.2.1:123414332026/10/06 21:13:49 INFO lead: released remote=192.0.2.1:12341434--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.42s)1435=== CONT TestIsValidUploadKey/narinfo1436=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1437=== CONT TestIsValidUploadKey/index.html1438=== CONT TestIsValidUploadKey/nix-cache-info1439=== CONT TestIsValidUploadKey/realisation_plus_in_output1440=== CONT TestIsValidUploadKey/realisation1441=== CONT TestIsValidUploadKey/build_log_equals1442=== CONT TestIsValidUploadKey/build_log_question_mark1443=== CONT TestIsValidUploadKey/build_log_plus_in_name1444=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1445=== CONT TestIsValidUploadKey/build_log_home-manager_file1446=== CONT TestIsValidUploadKey/build_log1447=== CONT TestIsValidUploadKey/listing1448=== CONT TestIsValidUploadKey/nar_zst1449=== CONT TestIsValidUploadKey/absolute1450=== CONT TestIsValidUploadKey/unknown_type1451=== CONT TestIsValidUploadKey/empty_key1452=== CONT TestIsValidUploadKey/nar_xz1453=== CONT TestIsValidUploadKey/traversal1454=== CONT TestIsValidUploadKey/nar_plain1455=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1456=== CONT TestIsValidUploadKey/traversal_nar1457--- PASS: TestIsValidUploadKey (0.00s)1458 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1459 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1460 --- PASS: TestIsValidUploadKey/index.html (0.00s)1461 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1462 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1463 --- PASS: TestIsValidUploadKey/realisation (0.00s)1464 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1465 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1466 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1467 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1468 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1469 --- PASS: TestIsValidUploadKey/build_log (0.00s)1470 --- PASS: TestIsValidUploadKey/listing (0.00s)1471 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1472 --- PASS: TestIsValidUploadKey/absolute (0.00s)1473 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1474 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1475 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1476 --- PASS: TestIsValidUploadKey/traversal (0.00s)1477 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1478 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1479 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1480=== CONT TestGCEndsOnShutdown/before_the_run14812026/10/06 21:13:49 INFO lead: acquired remote=192.0.2.1:123414822026/10/06 21:13:49 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket2666029425/001/proxy.sock14832026/10/06 21:13:49 INFO Starting HTTP server address=127.0.0.1:3961514842026/10/06 21:13:49 WARN mTLS auth: subject not in bound subjects subject="CN=someone"14852026/10/06 21:13:49 INFO Shutdown signal received, draining in-flight requests timeout=10s1486--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.43s)1487=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark14882026/10/06 21:13:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36601/oidc14892026/10/06 21:13:49 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1490--- PASS: TestReadProxyNarinfo (0.55s)1491=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete14922026/10/06 21:13:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41591/oidc1493--- PASS: TestGCBugBareHashReferences (0.71s)1494=== CONT TestPush_RejectsBadRequests/no_roots14952026/10/06 21:13:49 INFO Received push request method=POST path=/api/pushes1496=== CONT TestPush_RejectsBadRequests/bad_root14972026/10/06 21:13:49 INFO Received push request method=POST path=/api/pushes1498=== CONT TestPush_RejectsBadRequests/root_not_in_objects14992026/10/06 21:13:49 INFO Received push request method=POST path=/api/pushes1500=== CONT TestPush_RejectsBadRequests/no_objects15012026/10/06 21:13:49 INFO Received push request method=POST path=/api/pushes1502=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure1503--- PASS: TestPush_RejectsBadRequests (0.36s)1504 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1505 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1506 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1507 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)15082026/10/06 21:13:49 INFO Received uploads request method=POST path=/1509--- PASS: TestCacheStatsHandler (0.36s)1510=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts15112026/10/06 21:13:49 INFO Received request for more parts method=POST path=/1512--- PASS: TestService_ReadScope_PublicByDefault (0.34s)1513=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart15142026/10/06 21:13:49 INFO Received complete multipart upload request method=POST path=/1515=== NAME TestClientCADerivations1516 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3906251387/001/store/gsiqnmhhdq39n3g6cqr4cx1jwilgwzrl-ca-test1517=== NAME TestPinProtectsFromGC1518 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC2263004625/001/store/bxdk2m5d0iqyvf7bwnv4k0q7vxamnd54-pinned-file.txt1519 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC2263004625/001/store/l8xchhghb9rj64c0vnxzyg06gf2yvzd3-unpinned-file.txt1520--- PASS: TestService_ReadAuthMiddleware (0.37s)1521=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info15222026/10/06 21:13:49 INFO Received uploads request method=POST path=/1523=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15242026/10/06 21:13:49 INFO Received complete multipart upload request method=POST path=/1525=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key15262026/10/06 21:13:49 INFO Received request for more parts method=POST path=/1527=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal15282026/10/06 21:13:49 INFO Received uploads request method=POST path=/1529--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1530 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1531 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1532 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1533 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1534=== CONT TestPendingClosureWriteTimeout/empty1535=== CONT TestPendingClosureWriteTimeout/670k_objects1536=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline15372026/10/06 21:13:49 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15382026/10/06 21:13:49 WARN mTLS auth: bound subjects configured but subject DN unavailable15392026/10/06 21:13:49 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1540--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.34s)1541=== CONT TestPendingClosureWriteTimeout/400_objects1542=== CONT TestServerTLSConfig/no_client_CA1543=== NAME TestClientCADerivations1544 client_ca_test.go:139: Found 1 dependencies (including self)1545=== CONT TestServerTLSConfig/not_a_PEM_file1546=== CONT TestServerTLSConfig/missing_CA_file1547=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1548--- PASS: TestServerTLSConfig (0.00s)1549 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1550 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1551 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1552=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1553=== CONT TestIsValidCachePath/narinfo1554=== CONT TestIsValidCachePath/wrong_extension1555=== CONT TestIsValidCachePath/leading_slash1556=== CONT TestIsValidCachePath/empty1557=== CONT TestIsValidCachePath/random_path1558=== CONT TestIsValidCachePath/invalid_char_u1559=== CONT TestIsValidCachePath/short_hash1560=== CONT TestIsValidCachePath/invalid_char_e1561=== CONT TestIsValidCachePath/ls1562=== CONT TestIsValidCachePath/nar_uncompressed1563=== CONT TestIsValidCachePath/nar_bz21564=== CONT TestIsValidCachePath/nar_xz1565=== CONT TestIsValidCachePath/nar_zst1566=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1567=== CONT TestIsValidCachePath/index.html1568=== CONT TestIsValidCachePath/traversal_in_middle1569=== CONT TestIsValidCachePath/traversal_parent1570=== CONT TestIsValidCachePath/nix-cache-info1571=== CONT TestIsValidCachePath/realisation1572=== CONT TestIsValidCachePath/log1573--- PASS: TestIsValidCachePath (0.00s)1574 --- PASS: TestIsValidCachePath/narinfo (0.00s)1575 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1576 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1577 --- PASS: TestIsValidCachePath/empty (0.00s)1578 --- PASS: TestIsValidCachePath/random_path (0.00s)1579 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1580 --- PASS: TestIsValidCachePath/short_hash (0.00s)1581 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1582 --- PASS: TestIsValidCachePath/ls (0.00s)1583 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1584 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1585 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1586 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1587 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1588 --- PASS: TestIsValidCachePath/index.html (0.00s)1589 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1590 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1591 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1592 --- PASS: TestIsValidCachePath/realisation (0.00s)1593 --- PASS: TestIsValidCachePath/log (0.00s)1594=== CONT TestParseSingleRange/none1595=== CONT TestParseSingleRange/start_past_EOF1596=== CONT TestParseSingleRange/single_byte1597=== CONT TestParseSingleRange/suffix_exceeds_size1598=== CONT TestParseSingleRange/suffix1599=== CONT TestParseSingleRange/end_clamped_to_size1600=== CONT TestParseSingleRange/open-ended1601=== CONT TestParseSingleRange/closed1602=== CONT TestParseSingleRange/malformed_end_before_start1603=== CONT TestParseSingleRange/malformed_both_empty1604=== CONT TestParseSingleRange/malformed_no_dash1605=== CONT TestParseSingleRange/multi-range_ignored1606=== CONT TestParseSingleRange/unknown_unit1607=== CONT TestParseSingleRange/start_far_past_EOF1608--- PASS: TestParseSingleRange (0.00s)1609 --- PASS: TestParseSingleRange/none (0.00s)1610 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1611 --- PASS: TestParseSingleRange/single_byte (0.00s)1612 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1613 --- PASS: TestParseSingleRange/suffix (0.00s)1614 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1615 --- PASS: TestParseSingleRange/open-ended (0.00s)1616 --- PASS: TestParseSingleRange/closed (0.00s)1617 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1618 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1619 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1620 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1621 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1622 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1623=== CONT TestResolveDBConnectionString/flag_wins1624=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1625=== CONT TestResolveDBConnectionString/nothing_configured1626=== CONT TestResolveDBConnectionString/missing_file_is_an_error1627=== CONT TestResolveDBConnectionString/file_when_flag_empty1628=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1629--- PASS: TestResolveDBConnectionString (0.00s)1630 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1631 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1632 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1633 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1634 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)16352026/10/06 21:13:49 INFO Received uploads request method=POST path=/api/pending_closures1636--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.31s)1637=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh16382026/10/06 21:13:49 INFO Received uploads request method=POST path=/api/pending_closures16392026/10/06 21:13:49 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16402026/10/06 21:13:49 INFO Uploading z2rlhk57ycx37vbrr1zj60nwdb529scy-b (216B)16412026/10/06 21:13:49 INFO Uploading 15fwm5yirsk46fb938vzcjnz87zyqxyi-shared-dep (136B)16422026/10/06 21:13:49 INFO Received push request method=POST path=/api/pushes16432026/10/06 21:13:49 WARN Failed to register uploaded object key=y59si4r2mxmq367dws0ibp3cfldh5q2l.ls error="server returned 404: 404 page not found\n"16442026/10/06 21:13:49 WARN Failed to register uploaded object key=nar/0gi847m1mjj63pcrjf27hyxbabn3i558m9iamrnnh6m6pfyps0m8.nar.zst error="server returned 404: 404 page not found\n"16452026/10/06 21:13:49 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16462026/10/06 21:13:49 WARN Failed to register uploaded object key=z2rlhk57ycx37vbrr1zj60nwdb529scy.ls error="server returned 404: 404 page not found\n"16472026/10/06 21:13:49 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16482026/10/06 21:13:49 WARN Failed to register uploaded object key=15fwm5yirsk46fb938vzcjnz87zyqxyi.ls error="server returned 404: 404 page not found\n"16492026/10/06 21:13:49 INFO Signed narinfos id=2 count=216502026/10/06 21:13:49 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16512026/10/06 21:13:49 INFO Signed narinfos id=1 count=216522026/10/06 21:13:49 INFO Uploading 4 narinfos16532026/10/06 21:13:49 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16542026/10/06 21:13:49 INFO Uploading bxdk2m5d0iqyvf7bwnv4k0q7vxamnd54-pinned-file.txt (128B)16552026/10/06 21:13:49 WARN Failed to register uploaded object key=15fwm5yirsk46fb938vzcjnz87zyqxyi.narinfo error="server returned 404: 404 page not found\n"1656=== NAME TestClientIntegration16572026/10/06 21:13:49 WARN Failed to register uploaded object key=y59si4r2mxmq367dws0ibp3cfldh5q2l.narinfo error="server returned 404: 404 page not found\n"1658 client_integration_test.go:286: Created store path: /build/TestClientIntegration4172905790/002/store/f3w1h29l5g3k814pkdpdsw82spbspvy4-test-file.txt16592026/10/06 21:13:49 WARN Failed to register uploaded object key=z2rlhk57ycx37vbrr1zj60nwdb529scy.narinfo error="server returned 404: 404 page not found\n"16602026/10/06 21:13:49 WARN Failed to register uploaded object key=15fwm5yirsk46fb938vzcjnz87zyqxyi.narinfo error="server returned 404: 404 page not found\n"16612026/10/06 21:13:49 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16622026/10/06 21:13:49 WARN Failed to register uploaded object key=bxdk2m5d0iqyvf7bwnv4k0q7vxamnd54.ls error="server returned 404: 404 page not found\n"16632026/10/06 21:13:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16642026/10/06 21:13:49 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"16652026/10/06 21:13:49 INFO Signed narinfos id=1 count=116662026/10/06 21:13:49 INFO Uploading 1 narinfos16672026/10/06 21:13:49 INFO Received complete push request method=POST path=/api/pushes/1/complete16682026/10/06 21:13:49 WARN Failed to register uploaded object key=bxdk2m5d0iqyvf7bwnv4k0q7vxamnd54.narinfo error="server returned 404: 404 page not found\n"16692026/10/06 21:13:49 INFO Completed upload id=116702026/10/06 21:13:49 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16712026/10/06 21:13:49 INFO Completed upload id=216722026/10/06 21:13:49 INFO Upload complete. (79ms)16732026/10/06 21:13:49 INFO Upload complete. (63ms)1674=== NAME TestClientFallsBackToClosures1675 client_pushes_test.go:112: Retrieved narinfo from S3:1676 StorePath: /build/TestClientFallsBackToClosures3027430412/001/store/15fwm5yirsk46fb938vzcjnz87zyqxyi-shared-dep1677 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1678 Compression: zstd1679 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821680 NarSize: 1361681 References: 1682 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1683=== CONT TestProxyWriteTimeout/narinfo1684=== CONT TestProxyWriteTimeout/10_GiB_nar1685=== CONT TestProxyWriteTimeout/unknown_size1686=== CONT TestProxyWriteTimeout/1_GiB_nar1687--- PASS: TestProxyWriteTimeout (0.00s)1688 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1689 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1690 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1691 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1692=== CONT TestClientErrorHandling/InvalidStorePath1693=== NAME TestClientFallsBackToClosures1694 client_pushes_test.go:112: Retrieved narinfo from S3:1695 StorePath: /build/TestClientFallsBackToClosures3027430412/001/store/y59si4r2mxmq367dws0ibp3cfldh5q2l-a1696 URL: nar/0gi847m1mjj63pcrjf27hyxbabn3i558m9iamrnnh6m6pfyps0m8.nar.zst1697 Compression: zstd1698 NarHash: sha256:0gi847m1mjj63pcrjf27hyxbabn3i558m9iamrnnh6m6pfyps0m81699 NarSize: 2161700 References: /build/TestClientFallsBackToClosures3027430412/001/store/15fwm5yirsk46fb938vzcjnz87zyqxyi-shared-dep1701 CA: text:sha256:148h0ssa8aq8jd7paykz1dsaik1hg53f23b1n6kk128fsq82fspk1702 client_pushes_test.go:112: Retrieved narinfo from S3:1703 StorePath: /build/TestClientFallsBackToClosures3027430412/001/store/z2rlhk57ycx37vbrr1zj60nwdb529scy-b1704 URL: nar/0gi847m1mjj63pcrjf27hyxbabn3i558m9iamrnnh6m6pfyps0m8.nar.zst1705 Compression: zstd1706 NarHash: sha256:0gi847m1mjj63pcrjf27hyxbabn3i558m9iamrnnh6m6pfyps0m81707 NarSize: 2161708 References: /build/TestClientFallsBackToClosures3027430412/001/store/15fwm5yirsk46fb938vzcjnz87zyqxyi-shared-dep1709 CA: text:sha256:148h0ssa8aq8jd7paykz1dsaik1hg53f23b1n6kk128fsq82fspk1710--- PASS: TestClientFallsBackToClosures (0.67s)1711=== CONT TestClientErrorHandling/ServerNotAvailable17122026/10/06 21:13:49 INFO Received push request method=POST path=/api/pushes1713=== RUN TestService_RequireScope_OIDC/builder_may_write1714=== PAUSE TestService_RequireScope_OIDC/builder_may_write1715=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1716=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1717=== RUN TestService_RequireScope_OIDC/ops_may_admin1718=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1719=== RUN TestService_RequireScope_OIDC/ops_may_not_write1720=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1721=== RUN TestService_RequireScope_OIDC/reader_may_not_write1722=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1723=== RUN TestService_RequireScope_OIDC/static_token_may_admin1724=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1725=== RUN TestService_RequireScope_OIDC/static_token_may_write1726=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1727=== RUN TestService_RequireScope_OIDC/reader_may_read1728=== PAUSE TestService_RequireScope_OIDC/reader_may_read1729=== RUN TestService_RequireScope_OIDC/writer_implies_read1730=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1731=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1732=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1733=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1734=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1735=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1736=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1737=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1738=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1739=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1740=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1741=== CONT TestClientErrorHandling/InvalidAuthToken17422026/10/06 21:13:49 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17432026/10/06 21:13:49 INFO Uploading gsiqnmhhdq39n3g6cqr4cx1jwilgwzrl-ca-test (144B)17442026/10/06 21:13:49 INFO Received push request method=POST path=/api/pushes17452026/10/06 21:13:49 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"17462026/10/06 21:13:49 WARN Failed to register uploaded object key=gsiqnmhhdq39n3g6cqr4cx1jwilgwzrl.ls error="server returned 404: 404 page not found\n"17472026/10/06 21:13:49 WARN Failed to register uploaded object key=log/ac0jqylidh2586n8n39l9k1w1gha4ax2-ca-test.drv error="server returned 404: 404 page not found\n"17482026/10/06 21:13:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17492026/10/06 21:13:49 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17502026/10/06 21:13:49 INFO Uploading 4slz9y0gwgclfdagzxc4f17mx4nf8czm-a (216B)17512026/10/06 21:13:49 INFO Uploading a91f6b98k9vmh914v5a3lbqx1bldsic1-shared-dep (136B)17522026/10/06 21:13:49 INFO Signed narinfos id=1 count=117532026/10/06 21:13:49 INFO Uploading 1 narinfos17542026/10/06 21:13:49 INFO Received complete push request method=POST path=/api/pushes/1/complete17552026/10/06 21:13:49 WARN Failed to register uploaded object key=gsiqnmhhdq39n3g6cqr4cx1jwilgwzrl.narinfo error="server returned 404: 404 page not found\n"17562026/10/06 21:13:49 WARN Failed to register uploaded object key=3fghg1p86f2hw6rmnk3qa7abhpc2mkhs.ls error="server returned 404: 404 page not found\n"17572026/10/06 21:13:49 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17582026/10/06 21:13:49 WARN Failed to register uploaded object key=4slz9y0gwgclfdagzxc4f17mx4nf8czm.ls error="server returned 404: 404 page not found\n"17592026/10/06 21:13:49 WARN Failed to register uploaded object key=a91f6b98k9vmh914v5a3lbqx1bldsic1.ls error="server returned 404: 404 page not found\n"17602026/10/06 21:13:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17612026/10/06 21:13:49 WARN Failed to register uploaded object key=nar/10wxsi6qqw1iy3kzlyp3ycrl7y0r1blkqclr4rwcg8pi2l2aakwf.nar.zst error="server returned 404: 404 page not found\n"17622026/10/06 21:13:49 INFO Signed narinfos id=1 count=317632026/10/06 21:13:49 INFO Uploading 3 narinfos17642026/10/06 21:13:49 INFO Received complete push request method=POST path=/api/pushes/1/complete17652026/10/06 21:13:49 WARN Failed to register uploaded object key=4slz9y0gwgclfdagzxc4f17mx4nf8czm.narinfo error="server returned 404: 404 page not found\n"17662026/10/06 21:13:49 WARN Failed to register uploaded object key=3fghg1p86f2hw6rmnk3qa7abhpc2mkhs.narinfo error="server returned 404: 404 page not found\n"17672026/10/06 21:13:49 WARN Failed to register uploaded object key=a91f6b98k9vmh914v5a3lbqx1bldsic1.narinfo error="server returned 404: 404 page not found\n"17682026/10/06 21:13:49 INFO Upload complete. (97ms)1769=== NAME TestClientCADerivations1770 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3906251387/001/store/gsiqnmhhdq39n3g6cqr4cx1jwilgwzrl-ca-test1771 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1772 Compression: zstd1773 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1774 NarSize: 1441775 References: 1776 Deriver: /build/TestClientCADerivations3906251387/001/store/ac0jqylidh2586n8n39l9k1w1gha4ax2-ca-test.drv1777 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1778 client_ca_test.go:185: Checking for realisation files in S3...1779 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1780 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache17812026/10/06 21:13:49 INFO Aborted multipart uploads count=0 kept=017822026/10/06 21:13:49 INFO Upload complete. (67ms)1783=== NAME TestClientPushesUseOnePush1784 client_pushes_test.go:97: Retrieved narinfo from S3:1785 StorePath: /build/TestClientPushesUseOnePush2950219926/001/store/a91f6b98k9vmh914v5a3lbqx1bldsic1-shared-dep1786 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1787 Compression: zstd1788 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821789 NarSize: 1361790 References: 1791 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n17922026/10/06 21:13:49 WARN Force mode enabled - objects will be deleted immediately without grace period1793=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1794=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1795=== NAME TestClientPushesUseOnePush1796 client_pushes_test.go:97: Retrieved narinfo from S3:1797 StorePath: /build/TestClientPushesUseOnePush2950219926/001/store/4slz9y0gwgclfdagzxc4f17mx4nf8czm-a1798 URL: nar/10wxsi6qqw1iy3kzlyp3ycrl7y0r1blkqclr4rwcg8pi2l2aakwf.nar.zst1799 Compression: zstd1800 NarHash: sha256:10wxsi6qqw1iy3kzlyp3ycrl7y0r1blkqclr4rwcg8pi2l2aakwf1801 NarSize: 2161802 References: /build/TestClientPushesUseOnePush2950219926/001/store/a91f6b98k9vmh914v5a3lbqx1bldsic1-shared-dep1803 CA: text:sha256:0md62d47ndj04753xjjzmzaj8jakrk3zrqsw36rg7c0v9056dwqw1804=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1805=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1806=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1807=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1808=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1809=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1810=== CONT TestCacheConfigHandler/full_config,_no_issuer1811=== CONT TestCacheConfigHandler/no_signing_keys1812=== CONT TestCacheConfigHandler/no_cache_url_configured1813=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1814--- PASS: TestCacheConfigHandler (0.00s)1815 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1816 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1817 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1818 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1819=== CONT TestService_RequireScope_OIDC/builder_may_write18202026/10/06 21:13:49 INFO Received push request method=POST path=/api/pushes18212026/10/06 21:13:49 INFO Received push request method=POST path=/api/pushes1822=== CONT TestService_RequireScope_OIDC/reader_may_read1823=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1824=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18252026/10/06 21:13:49 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]1826=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1827=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1828=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1829=== CONT TestService_RequireScope_OIDC/writer_implies_read1830=== NAME TestClientPushesUseOnePush1831 client_pushes_test.go:97: Retrieved narinfo from S3:1832 StorePath: /build/TestClientPushesUseOnePush2950219926/001/store/3fghg1p86f2hw6rmnk3qa7abhpc2mkhs-b1833 URL: nar/10wxsi6qqw1iy3kzlyp3ycrl7y0r1blkqclr4rwcg8pi2l2aakwf.nar.zst1834 Compression: zstd1835 NarHash: sha256:10wxsi6qqw1iy3kzlyp3ycrl7y0r1blkqclr4rwcg8pi2l2aakwf1836 NarSize: 2161837 References: /build/TestClientPushesUseOnePush2950219926/001/store/a91f6b98k9vmh914v5a3lbqx1bldsic1-shared-dep1838 CA: text:sha256:0md62d47ndj04753xjjzmzaj8jakrk3zrqsw36rg7c0v9056dwqw1839=== CONT TestService_RequireScope_OIDC/static_token_may_write1840=== CONT TestService_RequireScope_OIDC/reader_may_not_write18412026-10-06 21:13:49.601 UTC [1541] ERROR: canceling statement due to user request18422026-10-06 21:13:49.601 UTC [1541] CONTEXT: PL/pgSQL function object_stats_apply() line 5 at statement block18432026-10-06 21:13:49.601 UTC [1541] STATEMENT: -- name: MarkStaleObjects :execrows1844 WITH RECURSIVE ct AS (1845 SELECT timezone('UTC', now()) AS now1846 ),1847 closure_reach AS (1848 -- Start with all closure keys1849 SELECT o.key, o.refs1850 FROM objects o1851 INNER JOIN closures c ON o.key = c.key1852 UNION1853 -- Recursively add all referenced objects1854 SELECT o.key, o.refs1855 FROM objects o1856 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1857 ),1858 reachable_objects AS (1859 SELECT DISTINCT key FROM closure_reach1860 ),1861 stale_objects AS (1862 SELECT o.key1863 FROM objects AS o, ct1864 WHERE1865 NOT EXISTS (1866 SELECT 11867 FROM reachable_objects ro1868 WHERE ro.key = o.key1869 )1870 AND NOT EXISTS (1871 SELECT 11872 FROM pending_objects AS po1873 WHERE po.key = o.key1874 )1875 AND o.deleted_at IS NULL -- Only mark fresh objects1876 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure1877 FOR UPDATE1878 )1879 UPDATE objects1880 SET1881 deleted_at = ct.now,1882 first_deleted_at = COALESCE(first_deleted_at, ct.now)1883 FROM stale_objects, ct1884 WHERE objects.key = stale_objects.key1885 1886=== CONT TestService_RequireScope_OIDC/static_token_may_admin1887=== CONT TestService_RequireScope_OIDC/ops_may_admin1888=== CONT TestService_RequireScope_OIDC/ops_may_not_write1889=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1890=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1891--- PASS: TestService_RequireScope_OIDC (0.46s)1892 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1893 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1894 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1895 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1896 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1897 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1898 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1899 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1900 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1901 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1902 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1903 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1904 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1905 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)19062026/10/06 21:13:49 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19072026/10/06 21:13:49 INFO Uploading l8xchhghb9rj64c0vnxzyg06gf2yvzd3-unpinned-file.txt (128B)19082026/10/06 21:13:49 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19092026/10/06 21:13:49 INFO Uploading f3w1h29l5g3k814pkdpdsw82spbspvy4-test-file.txt (152B)1910=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19112026/10/06 21:13:49 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]1912=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1913=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1914--- PASS: TestClientPushesUseOnePush (0.57s)19152026/10/06 21:13:49 WARN Authentication failed token_preview=eyJhbGciOi...bSVYjqk9Jg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1916--- PASS: TestService_AuthMiddleware_OIDC (0.46s)1917 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1918 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1919 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1920 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)19212026/10/06 21:13:49 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"19222026/10/06 21:13:49 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign19232026/10/06 21:13:49 WARN Failed to register uploaded object key=l8xchhghb9rj64c0vnxzyg06gf2yvzd3.ls error="server returned 404: 404 page not found\n"19242026/10/06 21:13:49 INFO Signed narinfos id=2 count=119252026/10/06 21:13:49 INFO Uploading 1 narinfos19262026/10/06 21:13:49 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"19272026/10/06 21:13:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19282026/10/06 21:13:49 WARN Failed to register uploaded object key=f3w1h29l5g3k814pkdpdsw82spbspvy4.ls error="server returned 404: 404 page not found\n"19292026/10/06 21:13:49 INFO Signed narinfos id=1 count=119302026/10/06 21:13:49 INFO Uploading 1 narinfos19312026/10/06 21:13:49 INFO Received complete push request method=POST path=/api/pushes/2/complete19322026/10/06 21:13:49 WARN Failed to register uploaded object key=l8xchhghb9rj64c0vnxzyg06gf2yvzd3.narinfo error="server returned 404: 404 page not found\n"19332026/10/06 21:13:49 INFO Upload complete. (49ms)19342026/10/06 21:13:49 INFO Received complete push request method=POST path=/api/pushes/1/complete19352026/10/06 21:13:49 WARN Failed to register uploaded object key=f3w1h29l5g3k814pkdpdsw82spbspvy4.narinfo error="server returned 404: 404 page not found\n"19362026/10/06 21:13:49 INFO Upload complete. (69ms)19372026/10/06 21:13:49 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/present19382026/10/06 21:13:49 INFO Aborted multipart uploads count=0 kept=019392026/10/06 21:13:49 WARN Force mode enabled - objects will be deleted immediately without grace period19402026/10/06 21:13:49 INFO Received uploads request method=POST path=/api/pending_closures19412026/10/06 21:13:49 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:38187/bucket90/?delete=\": context canceled"1942--- PASS: TestGCEndsOnShutdown (0.00s)1943 --- PASS: TestGCEndsOnShutdown/before_the_run (0.33s)1944 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.35s)1945 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.38s)19462026/10/06 21:13:49 INFO Starting cleanup of old closures method=DELETE path=/api/closures19472026/10/06 21:13:49 INFO Garbage collection started19482026/10/06 21:13:49 INFO Aborted multipart uploads count=0 kept=019492026/10/06 21:13:49 INFO All 1 paths already cached1950=== NAME TestClientIntegration1951 client_integration_test.go:312: Retrieved narinfo from S3:1952 StorePath: /build/TestClientIntegration4172905790/002/store/f3w1h29l5g3k814pkdpdsw82spbspvy4-test-file.txt1953 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1954 Compression: zstd1955 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11956 NarSize: 1521957 References: 1958 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11959 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)19602026/10/06 21:13:49 WARN Force mode enabled - objects will be deleted immediately without grace period1961 client_integration_test.go:313: Decompressed .ls content (64 bytes):1962 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1963 client_integration_test.go:316: Testing garbage collection...19642026/10/06 21:13:49 INFO Received uploads request method=POST path=/api/pending_closures19652026/10/06 21:13:49 INFO Aborted multipart uploads count=0 kept=019662026/10/06 21:13:49 WARN Force mode enabled - objects will be deleted immediately without grace period19672026/10/06 21:13:49 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=01968=== NAME TestClientCADerivations1969 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1970 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1971 error: binary cache 's3://bucket77?endpoint=http://localhost:38187®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3906251387/001/store'1972 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11973--- PASS: TestClientCADerivations (0.70s)19742026/10/06 21:13:49 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=212.388133ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19752026/10/06 21:13:49 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=388.25391ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19762026/10/06 21:13:50 INFO Vacuumed table table=pending_closures1977--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.19s)19782026/10/06 21:13:50 INFO Vacuumed table table=pending_objects19792026/10/06 21:13:50 INFO Vacuumed table table=multipart_uploads19802026/10/06 21:13:50 INFO Vacuumed table table=closures19812026/10/06 21:13:50 INFO Starting cleanup of old closures method=DELETE path=/api/closures19822026/10/06 21:13:50 INFO Garbage collection started19832026/10/06 21:13:50 INFO Vacuumed table table=objects19842026/10/06 21:13:50 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=019852026/10/06 21:13:50 INFO Vacuumed table table=pending_closures19862026/10/06 21:13:50 INFO Vacuumed table table=pending_objects19872026/10/06 21:13:50 INFO Vacuumed table table=multipart_uploads19882026/10/06 21:13:50 INFO Vacuumed table table=closures19892026/10/06 21:13:50 INFO Received uploads request method=POST path=/api/pending_closures19902026/10/06 21:13:50 INFO Vacuumed table table=objects19912026/10/06 21:13:50 INFO Aborted multipart uploads count=0 kept=019922026/10/06 21:13:50 WARN Force mode enabled - objects will be deleted immediately without grace period19932026/10/06 21:13:50 INFO Aborted multipart uploads count=0 kept=019942026/10/06 21:13:50 WARN Force mode enabled - objects will be deleted immediately without grace period19952026/10/06 21:13:50 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=019962026/10/06 21:13:50 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=019972026/10/06 21:13:50 INFO Vacuumed table table=pending_closures19982026/10/06 21:13:50 INFO Vacuumed table table=pending_closures19992026/10/06 21:13:50 INFO Vacuumed table table=pending_objects20002026/10/06 21:13:50 INFO Vacuumed table table=multipart_uploads20012026/10/06 21:13:50 INFO Vacuumed table table=closures20022026/10/06 21:13:50 INFO Vacuumed table table=pending_objects20032026/10/06 21:13:50 INFO Vacuumed table table=objects20042026/10/06 21:13:50 INFO Vacuumed table table=multipart_uploads20052026/10/06 21:13:50 INFO Vacuumed table table=closures20062026/10/06 21:13:50 INFO Vacuumed table table=objects2007--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2008 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.63s)2009 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.65s)20102026/10/06 21:13:50 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20112026/10/06 21:13:50 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20122026/10/06 21:13:50 INFO lead: released remote=192.0.2.1:12342013--- PASS: TestLeadEndsOnShutdown (1.49s)20142026/10/06 21:13:50 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=752.402913ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2015--- PASS: TestUploadHandlersRejectOversizedBody (0.17s)2016 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)2017 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)2018 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.05s)2019--- PASS: TestPendingClosureWriteTimeout (0.00s)2020 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2021 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2022 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2023 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.02s)2024=== NAME TestOrphanedObjectsGCStressTest2025 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains20262026/10/06 21:13:50 INFO lead: released remote=192.0.2.1:12342027 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion20282026/10/06 21:13:50 INFO lead: acquired remote=192.0.2.1:12342029--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2030 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (1.12s)2031 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (1.11s)2032=== NAME TestOrphanedObjectsGCStressTest2033 orphaned_objects_gc_test.go:509: Stress test completed successfully:2034 orphaned_objects_gc_test.go:510: - Active objects preserved: 202035 orphaned_objects_gc_test.go:511: - Objects deleted: 2102036 orphaned_objects_gc_test.go:512: - Total GC'd: 2102037--- PASS: TestOrphanedObjectsGCStressTest (2.62s)20382026/10/06 21:13:51 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.44464822s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20392026/10/06 21:13:51 INFO lead: released remote=192.0.2.1:12342040--- PASS: TestLeadElectsOneAndHandsOver (2.83s)20412026/10/06 21:13:51 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020422026/10/06 21:13:51 INFO Received create pin request method=POST path=/api/pins/myapp20432026/10/06 21:13:51 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2263004625/001/store/bxdk2m5d0iqyvf7bwnv4k0q7vxamnd54-pinned-file.txt narinfo_key=bxdk2m5d0iqyvf7bwnv4k0q7vxamnd54.narinfo20442026/10/06 21:13:51 INFO Starting cleanup of old closures method=DELETE path=/api/closures20452026/10/06 21:13:51 INFO Garbage collection started20462026/10/06 21:13:51 INFO Aborted multipart uploads count=0 kept=020472026/10/06 21:13:51 WARN Force mode enabled - objects will be deleted immediately without grace period20482026/10/06 21:13:51 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=020492026/10/06 21:13:51 INFO Vacuumed table table=pending_closures20502026/10/06 21:13:51 INFO Vacuumed table table=pending_objects20512026/10/06 21:13:51 INFO Vacuumed table table=multipart_uploads20522026/10/06 21:13:51 INFO Vacuumed table table=closures20532026/10/06 21:13:51 INFO Vacuumed table table=objects20542026/10/06 21:13:52 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02055=== NAME TestClientIntegration2056 client_integration_test.go:323: Objects in database after GC:2057 client_integration_test.go:323: Successfully deleted all objects with GC --force2058--- PASS: TestClientIntegration (2.92s)2059--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.81s)20602026/10/06 21:13:52 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-config20612026/10/06 21:13:52 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=183.34316ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20622026/10/06 21:13:52 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=382.916424ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20632026/10/06 21:13:53 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=781.843061ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2064=== NAME TestPinProtectsFromGC2065 client_integration_test.go:840: Pin successfully protected closure from garbage collection2066--- PASS: TestPinProtectsFromGC (4.66s)20672026/10/06 21:13:53 WARN Rate limiter enabled after throttle name=s3-test rate=520682026/10/06 21:13:53 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2069=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2070 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102071 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002072--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.66s)2073--- PASS: TestConnectWaitsForAPeerMigration (5.14s)20742026/10/06 21:13:54 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.602826226s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20752026/10/06 21:13:54 INFO Aborted multipart uploads count=1 kept=020762026/10/06 21:13:54 INFO Received cleanup request method=DELETE path=/api/pending_closures20772026/10/06 21:13:54 INFO Aborted multipart uploads count=1 kept=02078--- PASS: TestPendingCleanupUsesOneCutoff (6.47s)20792026/10/06 21:13:55 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"20802026/10/06 21:13:55 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-config20812026/10/06 21:13:55 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=215.881928ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20822026/10/06 21:13:55 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=436.157758ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20832026/10/06 21:13:56 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=833.37142ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20842026/10/06 21:13:57 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.600668437s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20852026/10/06 21:13:58 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_closures20862026/10/06 21:13:58 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=208.957866ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20872026/10/06 21:13:59 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=409.98675ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20882026/10/06 21:13:59 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=839.372665ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20892026/10/06 21:14:00 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.694019947s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2090--- PASS: TestClientErrorHandling (0.00s)2091 --- PASS: TestClientErrorHandling/InvalidStorePath (0.62s)2092 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.69s)2093 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.54s)2094PASS20952026-10-06 21:14:02.347 UTC [129] LOG: received smart shutdown request20962026-10-06 21:14:02.352 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 120972026-10-06 21:14:02.365 UTC [134] LOG: shutting down20982026-10-06 21:14:02.365 UTC [134] LOG: checkpoint starting: shutdown immediate20992026-10-06 21:14:03.083 UTC [134] LOG: checkpoint complete: wrote 11007 buffers (67.2%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 28 recycled; write=0.196 s, sync=0.497 s, total=0.718 s; sync files=33016, longest=0.062 s, average=0.001 s; distance=455947 kB, estimate=455947 kB; lsn=0/1D4A8AF0, redo lsn=0/1D4A8AF021002026-10-06 21:14:03.161 UTC [129] LOG: database system is shut down2101Running OIDC tests...2102=== RUN TestAudienceForIssuer2103=== PAUSE TestAudienceForIssuer2104=== RUN TestGlobMatch2105=== PAUSE TestGlobMatch2106=== RUN TestValidateToken_ValidToken2107=== PAUSE TestValidateToken_ValidToken2108=== RUN TestValidateToken_WrongAudience2109=== PAUSE TestValidateToken_WrongAudience2110=== RUN TestValidateToken_Expired2111=== PAUSE TestValidateToken_Expired2112=== RUN TestValidateToken_BoundClaimsMismatch2113=== PAUSE TestValidateToken_BoundClaimsMismatch2114=== RUN TestValidateToken_BoundSubjectMismatch2115=== PAUSE TestValidateToken_BoundSubjectMismatch2116=== RUN TestValidateToken_MultipleProviders2117=== PAUSE TestValidateToken_MultipleProviders2118=== RUN TestValidateToken_NoMatchingProvider2119=== PAUSE TestValidateToken_NoMatchingProvider2120=== RUN TestValidateToken_KubernetesServiceAccount2121=== PAUSE TestValidateToken_KubernetesServiceAccount2122=== RUN TestNewValidator_KubernetesRequiresCA2123=== PAUSE TestNewValidator_KubernetesRequiresCA2124=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2125=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2126=== RUN TestPins_ReservedForMatchingRule2127=== PAUSE TestPins_ReservedForMatchingRule2128=== RUN TestPins_TopLevelShorthand2129=== PAUSE TestPins_TopLevelShorthand2130=== RUN TestPins_ConfigValidation2131=== PAUSE TestPins_ConfigValidation2132=== RUN TestScopes_LegacyProviderDefaultsToWrite2133=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2134=== RUN TestScopes_Rules2135=== PAUSE TestScopes_Rules2136=== RUN TestScopes_ConfigValidation2137=== PAUSE TestScopes_ConfigValidation2138=== CONT TestAudienceForIssuer2139=== CONT TestPins_ConfigValidation2140=== CONT TestValidateToken_KubernetesServiceAccount2141=== CONT TestPins_ReservedForMatchingRule2142--- PASS: TestAudienceForIssuer (0.00s)2143=== CONT TestValidateToken_NoMatchingProvider2144=== CONT TestValidateToken_MultipleProviders2145=== CONT TestValidateToken_BoundSubjectMismatch2146=== CONT TestValidateToken_BoundClaimsMismatch2147--- PASS: TestPins_ConfigValidation (0.00s)2148=== CONT TestValidateToken_Expired2149=== CONT TestValidateToken_WrongAudience2150=== CONT TestValidateToken_ValidToken2151=== CONT TestGlobMatch2152=== RUN TestGlobMatch/foo_foo2153=== PAUSE TestGlobMatch/foo_foo2154=== RUN TestGlobMatch/foo_bar2155=== PAUSE TestGlobMatch/foo_bar2156=== RUN TestGlobMatch/*_2157=== PAUSE TestGlobMatch/*_2158=== RUN TestGlobMatch/*_anything2159=== PAUSE TestGlobMatch/*_anything2160=== RUN TestGlobMatch/foo*_foo2161=== PAUSE TestGlobMatch/foo*_foo2162=== CONT TestPins_TopLevelShorthand2163=== CONT TestScopes_Rules2164=== CONT TestScopes_ConfigValidation2165=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2166=== CONT TestNewValidator_KubernetesRequiresCA2167=== CONT TestScopes_LegacyProviderDefaultsToWrite2168=== RUN TestGlobMatch/foo*_foobar2169=== PAUSE TestGlobMatch/foo*_foobar2170=== RUN TestGlobMatch/foo*_bar2171=== PAUSE TestGlobMatch/foo*_bar2172=== RUN TestGlobMatch/*bar_bar2173=== PAUSE TestGlobMatch/*bar_bar2174=== RUN TestGlobMatch/*bar_foobar2175=== PAUSE TestGlobMatch/*bar_foobar2176=== RUN TestGlobMatch/*bar_foo2177=== PAUSE TestGlobMatch/*bar_foo2178=== RUN TestGlobMatch/foo*bar_foobar2179=== PAUSE TestGlobMatch/foo*bar_foobar2180=== RUN TestGlobMatch/foo*bar_foo123bar2181=== PAUSE TestGlobMatch/foo*bar_foo123bar2182=== RUN TestGlobMatch/foo*bar_foobarbaz2183=== PAUSE TestGlobMatch/foo*bar_foobarbaz2184=== RUN TestGlobMatch/*/*_foo/bar2185=== PAUSE TestGlobMatch/*/*_foo/bar2186=== RUN TestGlobMatch/*/*_foo2187=== PAUSE TestGlobMatch/*/*_foo2188=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2189=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2190=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02191=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02192=== RUN TestGlobMatch/refs/*/main_refs/heads/main2193=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2194=== RUN TestGlobMatch/fo?_foo2195=== PAUSE TestGlobMatch/fo?_foo2196=== RUN TestGlobMatch/fo?_fo2197=== PAUSE TestGlobMatch/fo?_fo2198=== RUN TestGlobMatch/fo?_fooo2199=== PAUSE TestGlobMatch/fo?_fooo2200=== RUN TestGlobMatch/?oo_foo2201=== PAUSE TestGlobMatch/?oo_foo2202=== RUN TestGlobMatch/?oo_boo2203=== PAUSE TestGlobMatch/?oo_boo2204=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2205=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2206=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2207=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2208=== CONT TestGlobMatch/foo_foo2209=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2210=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2211=== CONT TestGlobMatch/?oo_boo2212=== CONT TestGlobMatch/?oo_foo2213=== CONT TestGlobMatch/fo?_fooo2214=== CONT TestGlobMatch/fo?_fo2215=== CONT TestGlobMatch/fo?_foo2216=== CONT TestGlobMatch/refs/*/main_refs/heads/main2217=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02218=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2219=== CONT TestGlobMatch/*/*_foo2220=== CONT TestGlobMatch/*/*_foo/bar2221=== CONT TestGlobMatch/foo*bar_foobarbaz2222=== CONT TestGlobMatch/foo*bar_foo123bar2223=== CONT TestGlobMatch/foo*bar_foobar2224=== CONT TestGlobMatch/foo*_foo2225=== CONT TestGlobMatch/*_anything2226=== CONT TestGlobMatch/*_2227=== CONT TestGlobMatch/foo_bar2228=== CONT TestGlobMatch/*bar_foobar2229=== CONT TestGlobMatch/*bar_foo2230=== CONT TestGlobMatch/*bar_bar2231=== CONT TestGlobMatch/foo*_bar2232=== CONT TestGlobMatch/foo*_foobar2233--- PASS: TestGlobMatch (0.00s)2234 --- PASS: TestGlobMatch/foo_foo (0.00s)2235 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2236 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2237 --- PASS: TestGlobMatch/?oo_boo (0.00s)2238 --- PASS: TestGlobMatch/?oo_foo (0.00s)2239 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2240 --- PASS: TestGlobMatch/fo?_fo (0.00s)2241 --- PASS: TestGlobMatch/fo?_foo (0.00s)2242 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2243 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2244 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2245 --- PASS: TestGlobMatch/*/*_foo (0.00s)2246 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2247 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2248 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2249 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2250 --- PASS: TestGlobMatch/foo*_foo (0.00s)2251 --- PASS: TestGlobMatch/*_anything (0.00s)2252 --- PASS: TestGlobMatch/*_ (0.00s)2253 --- PASS: TestGlobMatch/foo_bar (0.00s)2254 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2255 --- PASS: TestGlobMatch/*bar_foo (0.00s)2256 --- PASS: TestGlobMatch/*bar_bar (0.00s)2257 --- PASS: TestGlobMatch/foo*_bar (0.00s)2258 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2259--- PASS: TestScopes_ConfigValidation (0.00s)22602026/10/06 21:14:05 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12322612026/10/06 21:14:05 http: TLS handshake error from 127.0.0.1:46910: remote error: tls: bad certificate2262--- PASS: TestNewValidator_KubernetesRequiresCA (0.07s)22632026/10/06 21:14:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46395/oidc2264--- PASS: TestValidateToken_Expired (0.08s)2265--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.07s)22662026/10/06 21:14:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39501/oidc22672026/10/06 21:14:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40163/oidc2268--- PASS: TestValidateToken_BoundClaimsMismatch (0.09s)2269--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.09s)22702026/10/06 21:14:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38923/oidc2271--- PASS: TestPins_TopLevelShorthand (0.10s)22722026/10/06 21:14:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46431/oidc2273--- PASS: TestPins_ReservedForMatchingRule (0.13s)22742026/10/06 21:14:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33207/oidc2275--- PASS: TestValidateToken_BoundSubjectMismatch (0.14s)22762026/10/06 21:14:05 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:345632277--- PASS: TestValidateToken_KubernetesServiceAccount (0.16s)22782026/10/06 21:14:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38089/oidc2279--- PASS: TestScopes_Rules (0.19s)22802026/10/06 21:14:05 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:42523/oidc22812026/10/06 21:14:05 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:38133/oidc2282--- PASS: TestValidateToken_MultipleProviders (0.22s)22832026/10/06 21:14:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43509/oidc22842026/10/06 21:14:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43017/oidc2285--- PASS: TestValidateToken_WrongAudience (0.27s)2286--- PASS: TestValidateToken_ValidToken (0.28s)22872026/10/06 21:14:05 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:45347/oidc2288--- PASS: TestValidateToken_NoMatchingProvider (0.40s)2289PASS2290Running hook tests...2291=== RUN TestSendPathsEmpty2292=== PAUSE TestSendPathsEmpty2293=== RUN TestQueueEnqueueAndFetch2294=== PAUSE TestQueueEnqueueAndFetch2295=== RUN TestQueueDeduplication2296=== PAUSE TestQueueDeduplication2297=== RUN TestQueueRemove2298=== PAUSE TestQueueRemove2299=== RUN TestQueueFetchBatchLimit2300=== PAUSE TestQueueFetchBatchLimit2301=== RUN TestQueueRetryMovesToBack2302=== PAUSE TestQueueRetryMovesToBack2303=== RUN TestQueueFetchRemoveLifecycle2304=== PAUSE TestQueueFetchRemoveLifecycle2305=== RUN TestQueueConcurrentWriters2306=== PAUSE TestQueueConcurrentWriters2307=== RUN TestQueueRemoveLargeClosure2308=== PAUSE TestQueueRemoveLargeClosure2309=== RUN TestServerClientIntegration2310=== PAUSE TestServerClientIntegration2311=== RUN TestServerQueueError2312=== PAUSE TestServerQueueError2313=== RUN TestGetListenerSocketActivation2314 server_test.go:210: === RUN TestGetListenerSocketActivation2315 --- PASS: TestGetListenerSocketActivation (0.00s)2316 PASS2317 2318--- PASS: TestGetListenerSocketActivation (0.01s)2319=== RUN TestDrainIsolatesPoisonPath2320=== PAUSE TestDrainIsolatesPoisonPath2321=== RUN TestRunNotBlockedByPoisonHead2322=== PAUSE TestRunNotBlockedByPoisonHead2323=== RUN TestDrainGivesUpWhenServerDown2324=== PAUSE TestDrainGivesUpWhenServerDown2325=== RUN TestFailedPathPrunedByLaterClosure2326=== PAUSE TestFailedPathPrunedByLaterClosure2327=== RUN TestWorkerUploadsAndRemoves2328=== PAUSE TestWorkerUploadsAndRemoves2329=== RUN TestWorkerSkipsGCdPaths2330=== PAUSE TestWorkerSkipsGCdPaths2331=== RUN TestWorkerPrunesClosureDeps2332=== PAUSE TestWorkerPrunesClosureDeps2333=== RUN TestDrainTimeout2334=== PAUSE TestDrainTimeout2335=== CONT TestSendPathsEmpty2336=== CONT TestWorkerPrunesClosureDeps2337=== CONT TestDrainGivesUpWhenServerDown2338--- PASS: TestSendPathsEmpty (0.00s)2339=== CONT TestQueueRemoveLargeClosure2340=== CONT TestQueueConcurrentWriters2341=== CONT TestQueueFetchRemoveLifecycle2342=== CONT TestQueueRetryMovesToBack2343=== CONT TestQueueFetchBatchLimit2344=== CONT TestServerClientIntegration2345=== CONT TestQueueRemove2346=== CONT TestQueueDeduplication2347=== CONT TestQueueEnqueueAndFetch2348=== CONT TestRunNotBlockedByPoisonHead2349=== CONT TestDrainIsolatesPoisonPath2350=== CONT TestWorkerUploadsAndRemoves2351=== CONT TestServerQueueError2352--- PASS: TestServerClientIntegration (0.00s)2353=== CONT TestWorkerSkipsGCdPaths2354=== CONT TestDrainTimeout23552026/10/06 21:14:05 ERROR Failed to queue paths error="permission denied" count=12356=== CONT TestFailedPathPrunedByLaterClosure2357--- PASS: TestServerQueueError (0.00s)23582026/10/06 21:14:05 INFO Uploading batch count=423592026/10/06 21:14:05 ERROR Upload failed error="upload failed" count=423602026/10/06 21:14:05 INFO Uploading batch count=123612026/10/06 21:14:05 ERROR Upload failed error="upload failed" count=123622026/10/06 21:14:05 INFO Upload queue status pending=223632026/10/06 21:14:05 INFO Upload queue status pending=323642026/10/06 21:14:05 INFO Uploading batch count=223652026/10/06 21:14:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath823759246/002/bbb23662026/10/06 21:14:05 INFO Uploading batch count=123672026/10/06 21:14:05 INFO Upload queue status pending=223682026/10/06 21:14:05 INFO Uploading batch count=223692026/10/06 21:14:05 ERROR Upload failed error="upload failed" count=223702026/10/06 21:14:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3814299944/002/a23712026/10/06 21:14:05 INFO Uploading batch count=123722026/10/06 21:14:05 INFO Uploading batch count=223732026/10/06 21:14:05 INFO Uploading batch count=123742026/10/06 21:14:05 ERROR Upload failed error="upload failed" count=12375--- PASS: TestQueueEnqueueAndFetch (0.05s)2376--- PASS: TestQueueFetchBatchLimit (0.05s)23772026/10/06 21:14:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3814299944/002/b2378--- PASS: TestQueueRetryMovesToBack (0.05s)23792026/10/06 21:14:05 INFO Uploading batch count=123802026/10/06 21:14:05 INFO Upload queue status pending=223812026/10/06 21:14:05 INFO Uploading batch count=123822026/10/06 21:14:05 ERROR Upload failed error="upload failed" count=123832026/10/06 21:14:05 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths4112833526/002/nonexistent2384--- PASS: TestQueueDeduplication (0.05s)23852026/10/06 21:14:05 INFO Uploading batch count=223862026/10/06 21:14:05 ERROR Upload failed error="upload failed" count=223872026/10/06 21:14:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3814299944/002/c2388--- PASS: TestQueueFetchRemoveLifecycle (0.05s)23892026/10/06 21:14:05 INFO Uploading batch count=123902026/10/06 21:14:05 ERROR Upload failed error="upload failed" count=12391--- PASS: TestQueueRemove (0.05s)23922026/10/06 21:14:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3814299944/002/d23932026/10/06 21:14:05 INFO Uploading batch count=123942026/10/06 21:14:05 INFO Uploading batch count=123952026/10/06 21:14:05 ERROR Upload failed error="upload failed" count=123962026/10/06 21:14:05 INFO Uploading batch count=223972026/10/06 21:14:05 ERROR Upload failed error="upload failed" count=223982026/10/06 21:14:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3814299944/002/e2399--- PASS: TestFailedPathPrunedByLaterClosure (0.05s)24002026/10/06 21:14:05 ERROR Drain finished with paths left in queue remaining=124012026/10/06 21:14:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3814299944/002/f24022026/10/06 21:14:05 ERROR Drain finished with paths left in queue remaining=102403--- PASS: TestDrainIsolatesPoisonPath (0.06s)2404--- PASS: TestDrainGivesUpWhenServerDown (0.06s)2405--- PASS: TestWorkerUploadsAndRemoves (0.07s)2406--- PASS: TestWorkerSkipsGCdPaths (0.07s)2407--- PASS: TestWorkerPrunesClosureDeps (0.07s)2408--- PASS: TestQueueRemoveLargeClosure (0.15s)24092026/10/06 21:14:05 ERROR Upload failed error="context deadline exceeded" count=224102026/10/06 21:14:05 ERROR Drain finished with paths left in queue remaining=42411--- PASS: TestDrainTimeout (0.25s)2412--- PASS: TestQueueConcurrentWriters (0.26s)24132026/10/06 21:14:06 INFO Uploading batch count=124142026/10/06 21:14:06 INFO Uploading batch count=124152026/10/06 21:14:06 INFO Uploading batch count=124162026/10/06 21:14:06 ERROR Upload failed error="upload failed" count=124172026/10/06 21:14:06 INFO Uploading batch count=124182026/10/06 21:14:06 ERROR Upload failed error="upload failed" count=124192026/10/06 21:14:06 INFO Uploading batch count=124202026/10/06 21:14:06 ERROR Upload failed error="upload failed" count=124212026/10/06 21:14:06 INFO Uploading batch count=124222026/10/06 21:14:06 ERROR Upload failed error="upload failed" count=124232026/10/06 21:14:06 ERROR Drain finished with paths left in queue remaining=12424--- PASS: TestRunNotBlockedByPoisonHead (1.06s)2425PASS2426Running signing tests...2427=== RUN TestExternalSigner2428=== PAUSE TestExternalSigner2429=== RUN TestExternalSignerWrongPublicKey2430=== PAUSE TestExternalSignerWrongPublicKey2431=== RUN TestExternalSignerErrors2432=== PAUSE TestExternalSignerErrors2433=== RUN TestExternalSignerRestartsAfterCrash2434=== PAUSE TestExternalSignerRestartsAfterCrash2435=== RUN TestExternalSignerProgramErrorKeepsProcess2436=== PAUSE TestExternalSignerProgramErrorKeepsProcess2437=== RUN TestExternalSignerClose2438=== PAUSE TestExternalSignerClose2439=== RUN TestExternalSignerRejectsInvalidPublicKey2440=== PAUSE TestExternalSignerRejectsInvalidPublicKey2441=== RUN TestExternalSignerCancellation2442=== PAUSE TestExternalSignerCancellation2443=== RUN TestGenerateFingerprint2444=== PAUSE TestGenerateFingerprint2445=== RUN TestParseSigningKey2446=== PAUSE TestParseSigningKey2447=== RUN TestSign2448=== PAUSE TestSign2449=== RUN TestSignBatch2450=== PAUSE TestSignBatch2451=== RUN TestNilKeyPublicKey2452=== PAUSE TestNilKeyPublicKey2453=== RUN TestSignErrors2454=== PAUSE TestSignErrors2455=== CONT TestExternalSigner2456=== CONT TestSignBatch2457=== CONT TestSignErrors2458=== CONT TestExternalSignerCancellation2459=== CONT TestSign2460=== CONT TestParseSigningKey2461=== RUN TestParseSigningKey/valid_32-byte_key2462=== CONT TestGenerateFingerprint2463=== RUN TestGenerateFingerprint/basic_with_references2464=== CONT TestNilKeyPublicKey2465--- PASS: TestNilKeyPublicKey (0.00s)2466=== CONT TestExternalSignerProgramErrorKeepsProcess2467=== CONT TestExternalSignerRejectsInvalidPublicKey2468=== RUN TestExternalSignerRejectsInvalidPublicKey/#002469=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002470=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2471=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2472=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2473=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2474=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2475=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2476=== CONT TestExternalSignerClose2477=== CONT TestExternalSignerErrors2478=== CONT TestExternalSignerRestartsAfterCrash2479=== CONT TestExternalSignerWrongPublicKey2480=== PAUSE TestParseSigningKey/valid_32-byte_key2481=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2482=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2483=== RUN TestParseSigningKey/no_colon2484=== PAUSE TestParseSigningKey/no_colon2485=== RUN TestParseSigningKey/empty_name2486=== PAUSE TestParseSigningKey/empty_name2487=== RUN TestParseSigningKey/invalid_base642488=== PAUSE TestParseSigningKey/invalid_base642489=== RUN TestParseSigningKey/wrong_length2490=== PAUSE TestParseSigningKey/wrong_length2491=== CONT TestParseSigningKey/valid_32-byte_key2492=== RUN TestExternalSignerErrors/exit_on_request2493=== PAUSE TestExternalSignerErrors/exit_on_request2494=== RUN TestExternalSignerErrors/null2495=== PAUSE TestExternalSignerErrors/null2496=== RUN TestExternalSignerErrors/wrong_id2497=== CONT TestParseSigningKey/empty_name2498=== PAUSE TestGenerateFingerprint/basic_with_references2499=== RUN TestGenerateFingerprint/no_references2500=== PAUSE TestGenerateFingerprint/no_references2501=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2502=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2503=== PAUSE TestExternalSignerErrors/wrong_id2504=== CONT TestParseSigningKey/no_colon2505=== RUN TestExternalSignerErrors/missing_signatures2506=== PAUSE TestExternalSignerErrors/missing_signatures2507=== RUN TestExternalSignerErrors/wrong_signatures_shape2508=== CONT TestParseSigningKey/wrong_length2509=== CONT TestParseSigningKey/invalid_base642510=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2511=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2512=== CONT TestExternalSignerRejectsInvalidPublicKey/#002513=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2514=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2515=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2516=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2517--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2518 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2519 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2520 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2521 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2522 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2523=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2524=== RUN TestExternalSignerErrors/too_few_signatures2525=== PAUSE TestExternalSignerErrors/too_few_signatures2526=== RUN TestExternalSignerErrors/invalid_signature_base642527=== PAUSE TestExternalSignerErrors/invalid_signature_base642528=== RUN TestExternalSignerErrors/exit_at_startup2529=== PAUSE TestExternalSignerErrors/exit_at_startup2530=== RUN TestExternalSignerErrors/wrong_shape2531=== PAUSE TestExternalSignerErrors/wrong_shape2532=== RUN TestExternalSignerErrors/unrequested_key2533=== PAUSE TestExternalSignerErrors/unrequested_key2534=== RUN TestExternalSignerErrors/wrong_signature_length2535=== PAUSE TestExternalSignerErrors/wrong_signature_length2536=== RUN TestExternalSignerErrors/program_error2537=== PAUSE TestExternalSignerErrors/program_error2538=== RUN TestExternalSignerErrors/invalid_JSON2539=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2540=== PAUSE TestExternalSignerErrors/invalid_JSON2541=== RUN TestExternalSignerErrors/missing_signature_name2542=== PAUSE TestExternalSignerErrors/missing_signature_name2543=== RUN TestExternalSignerErrors/wrong_signature_name2544=== PAUSE TestExternalSignerErrors/wrong_signature_name2545=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2546=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2547=== RUN TestExternalSignerErrors/null_signatures2548=== PAUSE TestExternalSignerErrors/null_signatures2549=== CONT TestExternalSignerErrors/exit_on_request2550=== CONT TestExternalSignerErrors/unrequested_key2551=== CONT TestExternalSignerErrors/invalid_signature_base642552=== CONT TestExternalSignerErrors/missing_signature_name2553=== RUN TestSignErrors/nil_key2554=== PAUSE TestSignErrors/nil_key2555=== RUN TestSignErrors/nil_narinfo2556--- PASS: TestSign (0.00s)2557=== CONT TestExternalSignerErrors/missing_signatures2558--- PASS: TestParseSigningKey (0.00s)2559 --- PASS: TestParseSigningKey/empty_name (0.00s)2560 --- PASS: TestParseSigningKey/no_colon (0.00s)2561 --- PASS: TestParseSigningKey/wrong_length (0.00s)2562 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2563 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2564 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2565=== PAUSE TestSignErrors/nil_narinfo2566=== CONT TestExternalSignerErrors/program_error2567=== RUN TestSignErrors/invalid_narinfo2568=== PAUSE TestSignErrors/invalid_narinfo2569=== RUN TestSignErrors/canceled2570=== PAUSE TestSignErrors/canceled2571=== CONT TestExternalSignerErrors/wrong_signature_length2572=== CONT TestExternalSignerErrors/null2573=== CONT TestExternalSignerErrors/too_few_signatures2574--- PASS: TestSignBatch (0.00s)2575=== CONT TestSignErrors/nil_key2576=== CONT TestExternalSignerErrors/wrong_shape2577=== CONT TestExternalSignerErrors/exit_at_startup2578=== CONT TestExternalSignerErrors/invalid_JSON2579=== CONT TestExternalSignerErrors/null_signatures2580=== CONT TestExternalSignerErrors/wrong_id2581=== CONT TestExternalSignerErrors/wrong_signatures_shape2582=== CONT TestExternalSignerErrors/wrong_signature_name2583=== RUN TestGenerateFingerprint/invalid_nar_hash_length2584=== CONT TestSignErrors/invalid_narinfo2585=== CONT TestSignErrors/canceled2586--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2587=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2588=== RUN TestGenerateFingerprint/invalid_store_path_prefix2589=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2590=== RUN TestGenerateFingerprint/invalid_reference_prefix2591=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2592=== CONT TestGenerateFingerprint/basic_with_references2593=== CONT TestGenerateFingerprint/invalid_nar_hash_length2594=== CONT TestGenerateFingerprint/invalid_reference_prefix2595=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2596=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2597=== CONT TestGenerateFingerprint/invalid_store_path_prefix2598=== CONT TestSignErrors/nil_narinfo2599--- PASS: TestSignErrors (0.00s)2600 --- PASS: TestSignErrors/nil_key (0.00s)2601 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2602 --- PASS: TestSignErrors/canceled (0.00s)2603 --- PASS: TestSignErrors/nil_narinfo (0.00s)2604=== CONT TestGenerateFingerprint/no_references2605--- PASS: TestGenerateFingerprint (0.01s)2606 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2607 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2608 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2609 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2610 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2611 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2612 --- PASS: TestGenerateFingerprint/no_references (0.00s)2613--- PASS: TestExternalSignerClose (0.01s)2614--- PASS: TestExternalSignerWrongPublicKey (0.01s)2615--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2616--- PASS: TestExternalSignerErrors (0.00s)2617 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2618 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2619 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2620 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2621 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2622 --- PASS: TestExternalSignerErrors/program_error (0.01s)2623 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2624 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2625 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2626 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2627 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2628 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2629 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2630 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2631 --- PASS: TestExternalSignerErrors/null (0.01s)2632 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2633--- PASS: TestExternalSigner (0.01s)2634--- PASS: TestExternalSignerCancellation (0.02s)2635PASS2636Running OpenBao signer tests...2637=== RUN TestSign2638=== PAUSE TestSign2639=== RUN TestSignErrors2640=== PAUSE TestSignErrors2641=== RUN TestServe2642=== PAUSE TestServe2643=== RUN TestServeRejectsGarbage2644=== PAUSE TestServeRejectsGarbage2645=== CONT TestSign2646=== CONT TestServe2647=== CONT TestServeRejectsGarbage2648--- PASS: TestServeRejectsGarbage (0.00s)2649=== CONT TestSignErrors2650=== RUN TestSignErrors/http_error2651=== PAUSE TestSignErrors/http_error2652=== RUN TestSignErrors/invalid_json2653=== PAUSE TestSignErrors/invalid_json2654=== RUN TestSignErrors/no_prefix2655=== PAUSE TestSignErrors/no_prefix2656=== RUN TestSignErrors/invalid_base642657=== PAUSE TestSignErrors/invalid_base642658=== CONT TestSignErrors/http_error2659=== CONT TestSignErrors/no_prefix2660=== CONT TestSignErrors/invalid_json2661=== CONT TestSignErrors/invalid_base642662--- PASS: TestServe (0.00s)2663--- PASS: TestSign (0.01s)2664--- PASS: TestSignErrors (0.00s)2665 --- PASS: TestSignErrors/invalid_json (0.00s)2666 --- PASS: TestSignErrors/no_prefix (0.00s)2667 --- PASS: TestSignErrors/invalid_base64 (0.00s)2668 --- PASS: TestSignErrors/http_error (0.01s)2669PASS