niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #383
· raw
1tribuchet: building on jamie2Running 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.05s)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 TestSetClientTLSErrors101=== CONT TestScriptTokenCachesUntilRefresh102=== CONT TestDoWithRetry_BodyReplayedViaGetBody103=== CONT TestSetClientTLSDoesNotMutateDefaultTransport104=== CONT TestSetClientTLS105=== CONT TestClientSignaturesByStorePath106--- PASS: TestClientSignaturesByStorePath (0.00s)107=== CONT TestParsePathInfoJSON108=== CONT TestStreamPushReportsSignatures109=== RUN TestParsePathInfoJSON/Nix_format110=== PAUSE TestParsePathInfoJSON/Nix_format111=== RUN TestParsePathInfoJSON/Lix_format112=== CONT TestStreamPushRequestLine113=== CONT TestStreamPushGivesUpOnDeadServer114=== CONT TestStreamPushIsolatesFailures115=== CONT TestStreamPushBatchesUnderLoad116=== CONT TestStreamPushReportsEveryPath117=== CONT TestShellSplitErrors118=== CONT TestShellSplit119=== CONT TestScriptTokenScriptFails120=== CONT TestScriptTokenEmptyCommand121=== CONT TestScriptTokenBadJSON122=== CONT TestEncodeNixBase32123=== CONT TestResolveStorePath124=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess125=== CONT TestRateLimiterFeedback126=== CONT TestPathInfoCACompatibility127=== RUN TestPathInfoCACompatibility/null_ca_field128=== CONT TestParsePathInfoJSONMultiplePaths129=== PAUSE TestParsePathInfoJSON/Lix_format130=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths131=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1322026/10/06 21:13:43 ERROR Upload failed error="bad path" count=31332026/10/06 21:13:43 ERROR Upload failed error="connection refused" count=201342026/10/06 21:13:43 ERROR Server seems unavailable, giving up on batch untried=17135=== PAUSE TestPathInfoCACompatibility/null_ca_field136=== RUN TestParsePathInfoJSON/empty_input137--- PASS: TestShellSplitErrors (0.00s)138=== RUN TestSetClientTLSErrors/missing_cert_file139--- PASS: TestStreamPushIsolatesFailures (0.00s)140=== CONT TestPathInfoHashCompatibility141=== CONT TestGetStorePathHash142=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)143=== RUN TestEncodeNixBase32/test_string_hash144=== RUN TestPathInfoCACompatibility/old_string_format_-_text145=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text146=== CONT TestEncodeNixBase32WithRealHash147--- PASS: TestShellSplit (0.00s)148--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)149=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive1502026/10/06 21:13:43 ERROR Upload failed error=boom count=1151=== CONT TestConvertHashToNix32152=== PAUSE TestEncodeNixBase32/test_string_hash1532026/10/06 21:13:43 ERROR Upload failed error=boom count=1154=== RUN TestConvertHashToNix32/SRI_format_to_Nix321552026/10/06 21:13:43 WARN Rate limiter enabled after throttle name=server-test rate=5156=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix321572026/10/06 21:13:43 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:41315158=== PAUSE TestSetClientTLSErrors/missing_cert_file1592026/10/06 21:13:43 WARN Rate limiter enabled after throttle name=server-test rate=5160=== RUN TestEncodeNixBase32/empty_input161--- PASS: TestStreamPushReportsSignatures (0.00s)162--- PASS: TestStreamPushReportsEveryPath (0.00s)163=== CONT TestFileTokenEmpty164=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive165=== RUN TestSetClientTLSErrors/missing_key_file166=== PAUSE TestSetClientTLSErrors/missing_key_file167=== RUN TestConvertHashToNix32/already_Nix32_format168=== PAUSE TestConvertHashToNix32/already_Nix32_format169=== PAUSE TestEncodeNixBase32/empty_input170=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths171=== CONT TestFileTokenMissing172=== PAUSE TestParsePathInfoJSON/empty_input173=== CONT TestScriptTokenNoExpiryRerunsEveryCall1742026/10/06 21:13:43 WARN Rate limiter backed off name=server-test rate=51752026/10/06 21:13:43 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:41315176=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)177=== CONT TestDumpPathMatchesNix178=== RUN TestGetStorePathHash/valid_store_path179=== PAUSE TestGetStorePathHash/valid_store_path180=== CONT TestUploadMultipart_PartsInParallel181=== RUN TestGetStorePathHash/basename_without_hyphen_should_error182=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error183--- PASS: TestEncodeNixBase32WithRealHash (0.00s)184=== CONT TestDumpPathWriterError185=== RUN TestRateLimiterFeedback/429_enables_limiter186=== RUN TestPathInfoCACompatibility/new_structured_format_-_text187=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths188=== RUN TestSetClientTLSErrors/missing_ca_file189=== RUN TestConvertHashToNix32/invalid_format190=== RUN TestParsePathInfoJSON/whitespace_only191=== CONT TestScriptTokenEmptyToken192=== CONT TestDumpPathSingleFile193=== CONT TestUploadMultipart_SupersededByPeer194=== CONT TestPartSizeForNAR195=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon196--- PASS: TestScriptTokenEmptyCommand (0.00s)197--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)198=== PAUSE TestRateLimiterFeedback/429_enables_limiter199=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error200=== CONT TestFileTokenReadsAndCaches201=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text202--- PASS: TestFileTokenEmpty (0.00s)203=== RUN TestSetClientTLS/rejects_connection_without_client_cert204=== CONT TestStaticToken205=== PAUSE TestParsePathInfoJSON/whitespace_only206=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun207=== RUN TestParsePathInfoJSON/invalid_JSON208=== CONT TestFilterOversizedClosures209=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method210--- PASS: TestResolveStorePath (0.00s)211--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)212--- PASS: TestDoServerRequestAttachesToken (0.01s)213--- PASS: TestFileTokenMissing (0.00s)214--- PASS: TestScriptTokenScriptFails (0.00s)215--- PASS: TestScriptTokenBadJSON (0.00s)216=== PAUSE TestConvertHashToNix32/invalid_format217=== RUN TestPartSizeForNAR/zero_stays_at_minimum218=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica219=== RUN TestUploadMultipart_SupersededByPeer/exists220=== PAUSE TestUploadMultipart_SupersededByPeer/exists221=== RUN TestUploadMultipart_SupersededByPeer/missing222=== PAUSE TestUploadMultipart_SupersededByPeer/missing223=== PAUSE TestSetClientTLSErrors/missing_ca_file224=== RUN TestSetClientTLSErrors/invalid_ca_file225=== PAUSE TestParsePathInfoJSON/invalid_JSON226=== PAUSE TestSetClientTLSErrors/invalid_ca_file227=== CONT TestCaseHackSuffix228=== CONT TestEncodeNixBase32/test_string_hash229=== RUN TestRateLimiterFeedback/503_enables_limiter230=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert231=== PAUSE TestRateLimiterFeedback/503_enables_limiter232=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon233=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI234=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI235=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512236=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512237=== CONT TestRegisterUploadedObjectReusesConnections2382026/10/06 21:13:43 INFO Garbage collection started2392026/10/06 21:13:43 INFO Garbage collection started240=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error241=== CONT TestEncodeNixBase32/empty_input242=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error243=== CONT TestConvertHashToNix32/invalid_format244=== CONT TestConvertHashToNix32/already_Nix32_format245=== CONT TestUploadMultipart_SupersededByPeer/exists246=== CONT TestUploadMultipart_SupersededByPeer/missing247=== CONT TestConvertHashToNix32/SRI_format_to_Nix32248=== CONT TestParsePathInfoJSON/Nix_format249=== CONT TestParsePathInfoJSON/whitespace_only250=== CONT TestParsePathInfoJSON/empty_input251=== CONT TestParsePathInfoJSON/invalid_JSON252=== CONT TestParsePathInfoJSON/Lix_format253=== CONT TestSetClientTLSErrors/missing_cert_file254=== CONT TestSetClientTLSErrors/invalid_ca_file255=== CONT TestSetClientTLSErrors/missing_ca_file256=== CONT TestSetClientTLSErrors/missing_key_file257=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)258=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512259=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon260=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI261--- PASS: TestStaticToken (0.00s)262--- PASS: TestEncodeNixBase32 (0.00s)263 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)264 --- PASS: TestEncodeNixBase32/empty_input (0.00s)265=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error266=== CONT TestGetStorePathHash/valid_store_path267=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA268=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA269=== RUN TestSetClientTLS/preserves_debug_logging_transport270=== PAUSE TestSetClientTLS/preserves_debug_logging_transport271=== CONT TestSetClientTLS/rejects_connection_without_client_cert272=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths273--- PASS: TestFileTokenReadsAndCaches (0.00s)274--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)275=== CONT TestGetStorePathHash/basename_without_hyphen_should_error276=== RUN TestFilterOversizedClosures/no_limit_keeps_everything277=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything278--- PASS: TestConvertHashToNix32 (0.03s)279 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)280 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)281 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)282=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error283=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error284--- PASS: TestGetStorePathHash (0.04s)285 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)286 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)287 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)288 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)289=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2902026/10/06 21:13:43 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=0291--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)292=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum293=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped294=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped295=== RUN TestFilterOversizedClosures/all_closures_skipped296=== PAUSE TestFilterOversizedClosures/all_closures_skipped297=== CONT TestFilterOversizedClosures/no_limit_keeps_everything298--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)299 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)300 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)301=== CONT TestFilterOversizedClosures/all_closures_skipped3022026/10/06 21:13:43 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=50303=== RUN TestPartSizeForNAR/small_stays_at_minimum304=== PAUSE TestPartSizeForNAR/small_stays_at_minimum305=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter306=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter307=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter308=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter309=== CONT TestSetClientTLS/preserves_debug_logging_transport310=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA311=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3122026/10/06 21:13:43 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=2000313--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)314--- PASS: TestScriptTokenEmptyToken (0.00s)315=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method316=== CONT TestPathInfoCACompatibility/null_ca_field317--- PASS: TestPathInfoHashCompatibility (0.04s)318 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)319 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)320 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)321 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)322=== CONT TestPathInfoCACompatibility/new_structured_format_-_text323=== CONT TestRateLimiterFeedback/429_enables_limiter3242026/10/06 21:13:43 WARN Garbage collection finished on another replica. Its statistics are not available here325=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter326=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter3272026/10/06 21:13:43 WARN Rate limiter enabled after throttle name=server-test rate=5328=== CONT TestRateLimiterFeedback/503_enables_limiter3292026/10/06 21:13:43 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:39085330=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum3312026/10/06 21:13:43 WARN Rate limiter backed off name=server-test rate=5332=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum333=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method3342026/10/06 21:13:43 WARN Rate limiter enabled after throttle name=server-test rate=5335=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive3362026/10/06 21:13:43 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:44113337=== CONT TestPathInfoCACompatibility/old_string_format_-_text338--- PASS: TestParsePathInfoJSON (0.04s)339 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)340 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)341 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)342 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)343 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)344=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts3452026/10/06 21:13:43 WARN Rate limiter backed off name=server-test rate=5346--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)347 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)348 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)349=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts350=== RUN TestPartSizeForNAR/1_TiB351--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)352=== PAUSE TestPartSizeForNAR/1_TiB353=== RUN TestPartSizeForNAR/5_TiB_S3_max_object354--- PASS: TestSetClientTLSErrors (0.04s)355 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)356 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)357 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)358 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)359=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object360=== RUN TestPartSizeForNAR/capped_at_5_GiB361=== PAUSE TestPartSizeForNAR/capped_at_5_GiB362=== CONT TestPartSizeForNAR/zero_stays_at_minimum363=== CONT TestPartSizeForNAR/1_TiB364--- PASS: TestFilterOversizedClosures (0.00s)365 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)366 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)367 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)368--- PASS: TestPathInfoCACompatibility (0.05s)369 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)370 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)371 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)372 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)373 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)374=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts375=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum376=== CONT TestPartSizeForNAR/small_stays_at_minimum377=== CONT TestPartSizeForNAR/capped_at_5_GiB378=== CONT TestPartSizeForNAR/5_TiB_S3_max_object379--- PASS: TestPartSizeForNAR (0.02s)380 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)381 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)382 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)383 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)384 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)385 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)386 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)387--- PASS: TestRateLimiterFeedback (0.05s)388 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)389 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)390 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)391 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)3922026/10/06 21:13:43 http: TLS handshake error from 127.0.0.1:36930: remote error: tls: bad certificate393--- PASS: TestSetClientTLS (0.05s)394 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)395 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)396 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)397--- PASS: TestStreamPushRequestLine (0.06s)398--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)399--- PASS: TestDumpPathWriterError (0.08s)400--- PASS: TestCaseHackSuffix (0.05s)401--- PASS: TestDumpPathSingleFile (0.06s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestDumpPathMatchesNix (0.13s)404--- PASS: TestUploadMultipart_PartsInParallel (0.65s)405--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)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/postgres1976758854/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/postgres1976758854/data -l logfile start434435/build/postgres1976758854:5432 - no response4362026-10-06 21:13:45.231 UTC [130] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-06 21:13:45.232 UTC [130] LOG: listening on Unix socket "/build/postgres1976758854/.s.PGSQL.5432"4382026-10-06 21:13:45.237 UTC [137] LOG: database system was shut down at 2026-10-06 21:13:44 UTC4392026-10-06 21:13:45.241 UTC [130] LOG: database system is ready to accept connections440/build/postgres1976758854: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:45 INFO lead: acquired remote=192.0.2.1:12344872026/10/06 21:13:46 INFO lead: released remote=192.0.2.1:12344882026/10/06 21:13:46 INFO lead: acquired remote=192.0.2.1:12344892026/10/06 21:13:47 INFO lead: released remote=192.0.2.1:1234490--- PASS: TestLeadIncumbentWinsAfterRestart (1.86s)491=== RUN TestLeadIncumbentAnnouncesAtOnce492=== PAUSE TestLeadIncumbentAnnouncesAtOnce493=== RUN TestLeadEndsOnShutdown494=== PAUSE TestLeadEndsOnShutdown495=== RUN TestLeadEndsWhenItsConnectionHangs4962026/10/06 21:13:47 INFO lead: acquired remote=192.0.2.1:12344972026-10-06 21:13:49.042 UTC [581] FATAL: terminating connection due to administrator command4982026/10/06 21:13:49 INFO lead: acquired remote=192.0.2.1:12344992026/10/06 21:13:50 WARN lead: lock connection lost error="timeout: context deadline exceeded"5002026/10/06 21:13:50 INFO lead: released remote=192.0.2.1:12345012026/10/06 21:13:50 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:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/06 21:13:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6682026/10/06 21:13:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6692026/10/06 21:13:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6702026/10/06 21:13:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6712026/10/06 21:13:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6722026/10/06 21:13:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6732026/10/06 21:13:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6742026/10/06 21:13:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6752026/10/06 21:13:50 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 TestService_AuthMiddleware700=== CONT TestService_cleanupPendingClosuresHandler701=== CONT TestService_NativeMTLS702=== CONT TestGCSweepSkipsPendingObjects703=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT704=== CONT TestCompleteMultipartUnregistered705=== CONT TestService_verifyS3Integrity706=== CONT TestService_createPendingClosureHandler707=== CONT TestMetricsInventory708=== CONT TestNARDeduplicationMetadataUploadBug709=== CONT TestCreatePendingClosureRejectsOversizedNAR710=== CONT TestCacheConfigHandlerMaxNarSize711=== CONT TestGenerateLandingPage7122026/10/06 21:13:50 INFO Received uploads request method=POST path=/api/pending_closures713=== CONT TestService_readinessHandler714=== CONT TestService_healthCheckHandler715=== CONT TestGracefulShutdownDrainsInflight716=== CONT TestGCTaskStore_Fail717=== CONT TestPushWaitsForSweepHoldingRow718=== CONT TestGCTaskStore_PhaseUpdates719=== CONT TestGCTaskStore_CompletedAllowsNewTask720=== CONT TestGetExistingObjectsLocksRows721=== CONT TestGCTaskStore_GetReturnsLatest7222026/10/06 21:13:50 INFO Starting HTTP server address=127.0.0.1:43053723=== CONT TestRegisterCompletedObjectNeedsPendingRow724=== CONT TestGCTaskStore_GetEmpty725=== CONT TestGCTaskStore_ConflictDifferentParams726=== CONT TestGCTaskStore_DeduplicateSameParams727=== CONT TestGCTaskStore_StartNew728--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)729=== CONT TestGCEndsOnShutdown730=== CONT TestCommitRacingPendingCleanupKeepsObjects731=== CONT TestSweepRechecksPendingAfterLocking732=== CONT TestSweepSkipsRowsLockedByPush733--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)7342026/10/06 21:13:50 INFO Shutdown signal received, draining in-flight requests timeout=10s735--- PASS: TestGCTaskStore_Fail (0.00s)736--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)737=== CONT TestFailedS3DeleteKeepsTombstone738=== CONT TestForceGCDuringPushOffersSweptObject739=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows740=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows741=== RUN TestGCEndsOnShutdown/before_the_run742=== PAUSE TestGCEndsOnShutdown/before_the_run743=== CONT TestTombstonedObjectOfferedWithoutWaiting744--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)745--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)746--- PASS: TestGCTaskStore_GetEmpty (0.00s)747--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)748--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)749--- PASS: TestGCTaskStore_StartNew (0.00s)750=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check751=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete752=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check753=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete754=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection755--- PASS: TestGenerateLandingPage (0.01s)756=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark757=== CONT TestReadRedirectNar758=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark759=== CONT TestUploadHandlersRejectOversizedBody760--- PASS: TestGracefulShutdownDrainsInflight (0.07s)761=== CONT TestUploadHandlersRejectInvalidKeys762=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info763=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info764=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal765=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal766=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key767=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key768=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key769=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key770=== CONT TestIsValidUploadKey771=== RUN TestIsValidUploadKey/narinfo772=== PAUSE TestIsValidUploadKey/narinfo773=== RUN TestIsValidUploadKey/nar_zst774=== PAUSE TestIsValidUploadKey/nar_zst775=== RUN TestIsValidUploadKey/nar_xz776=== PAUSE TestIsValidUploadKey/nar_xz777=== RUN TestIsValidUploadKey/nar_plain778=== PAUSE TestIsValidUploadKey/nar_plain779=== RUN TestIsValidUploadKey/listing780=== PAUSE TestIsValidUploadKey/listing781=== RUN TestIsValidUploadKey/build_log782=== PAUSE TestIsValidUploadKey/build_log783=== RUN TestIsValidUploadKey/build_log_home-manager_file784=== PAUSE TestIsValidUploadKey/build_log_home-manager_file785=== RUN TestIsValidUploadKey/build_log_plus_in_name786=== PAUSE TestIsValidUploadKey/build_log_plus_in_name787=== RUN TestIsValidUploadKey/build_log_question_mark788=== PAUSE TestIsValidUploadKey/build_log_question_mark789=== RUN TestIsValidUploadKey/build_log_equals790=== PAUSE TestIsValidUploadKey/build_log_equals791=== RUN TestIsValidUploadKey/realisation792=== PAUSE TestIsValidUploadKey/realisation793=== RUN TestIsValidUploadKey/realisation_plus_in_output794=== PAUSE TestIsValidUploadKey/realisation_plus_in_output795=== RUN TestIsValidUploadKey/nix-cache-info796=== PAUSE TestIsValidUploadKey/nix-cache-info797=== RUN TestIsValidUploadKey/index.html798=== PAUSE TestIsValidUploadKey/index.html799=== RUN TestIsValidUploadKey/narinfo_key,_nar_type800=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type801=== RUN TestIsValidUploadKey/nar_key,_narinfo_type802=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type803=== RUN TestIsValidUploadKey/listing_key,_narinfo_type804=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type805=== RUN TestIsValidUploadKey/traversal806=== PAUSE TestIsValidUploadKey/traversal807=== RUN TestIsValidUploadKey/traversal_nar808=== PAUSE TestIsValidUploadKey/traversal_nar809=== RUN TestIsValidUploadKey/absolute810=== PAUSE TestIsValidUploadKey/absolute811=== RUN TestIsValidUploadKey/empty_key812=== PAUSE TestIsValidUploadKey/empty_key813=== RUN TestIsValidUploadKey/unknown_type814=== PAUSE TestIsValidUploadKey/unknown_type815=== CONT TestPendingClosureWriteTimeout816=== RUN TestPendingClosureWriteTimeout/empty817=== PAUSE TestPendingClosureWriteTimeout/empty818=== RUN TestPendingClosureWriteTimeout/400_objects819=== PAUSE TestPendingClosureWriteTimeout/400_objects820=== RUN TestPendingClosureWriteTimeout/670k_objects821=== PAUSE TestPendingClosureWriteTimeout/670k_objects822=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline823=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline824=== CONT TestGCSweepDeliversEachKeyOnce825=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure826=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure827=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart828=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart829=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts830=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts831=== CONT TestProxyWriteTimeout832=== RUN TestProxyWriteTimeout/narinfo833=== PAUSE TestProxyWriteTimeout/narinfo834=== RUN TestProxyWriteTimeout/1_GiB_nar835=== PAUSE TestProxyWriteTimeout/1_GiB_nar836=== RUN TestProxyWriteTimeout/10_GiB_nar837=== PAUSE TestProxyWriteTimeout/10_GiB_nar838=== RUN TestProxyWriteTimeout/unknown_size839=== PAUSE TestProxyWriteTimeout/unknown_size840=== CONT TestPush_RejectsBadRequests8412026/10/06 21:13:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8422026/10/06 21:13:51 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst843--- PASS: TestCompleteMultipartUnregistered (0.57s)844=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit8452026/10/06 21:13:51 INFO Received uploads request method=POST path=/api/pending_closures8462026/10/06 21:13:51 WARN mTLS auth: subject not in bound subjects subject="CN=reader"8472026/10/06 21:13:51 WARN mTLS auth: subject not in bound subjects subject="CN=reader"848--- PASS: TestService_NativeMTLS (0.61s)849=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle8502026/10/06 21:13:51 INFO Aborted multipart uploads count=0 kept=08512026/10/06 21:13:51 WARN Force mode enabled - objects will be deleted immediately without grace period8522026/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=08532026/10/06 21:13:51 INFO Vacuumed table table=pending_closures8542026/10/06 21:13:51 INFO Vacuumed table table=pending_objects8552026/10/06 21:13:51 INFO Vacuumed table table=multipart_uploads8562026/10/06 21:13:51 INFO Vacuumed table table=closures8572026/10/06 21:13:51 INFO Vacuumed table table=objects858--- PASS: TestGCSweepSkipsPendingObjects (0.66s)859=== CONT TestPush_RootsAreLockedInByteOrder860--- PASS: TestService_healthCheckHandler (0.66s)861=== CONT TestSkippedUploadsHandler8622026/10/06 21:13:51 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000863--- PASS: TestGetExistingObjectsLocksRows (0.66s)864=== CONT TestPush_CompleteWaitsForCleanupOfThePush865--- PASS: TestSkippedUploadsHandler (0.01s)866=== CONT TestParseSize867--- PASS: TestParseSize (0.00s)868=== CONT TestPush_RepeatedRootCommitsOnce8692026/10/06 21:13:51 WARN readiness check failed error="closed pool"870--- PASS: TestService_readinessHandler (0.69s)871=== CONT TestService_Rustfstest8722026/10/06 21:13:51 INFO Received cleanup request method=DELETE path=/api/pending_closures8732026/10/06 21:13:51 INFO Aborted multipart uploads count=0 kept=08742026/10/06 21:13:51 INFO Received uploads request method=POST path=/api/pending_closures8752026/10/06 21:13:51 INFO Received cleanup request method=DELETE path=/api/pending_closures8762026/10/06 21:13:51 INFO Aborted multipart uploads count=1 kept=08772026/10/06 21:13:51 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"878--- PASS: TestService_AuthMiddleware (0.74s)879=== CONT TestPush_CompleteCommitsEveryRoot8802026/10/06 21:13:51 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8812026-10-06 21:13:51.432 UTC [653] ERROR: Closure does not exist: id=18822026-10-06 21:13:51.432 UTC [653] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE8832026-10-06 21:13:51.432 UTC [653] STATEMENT: -- name: CommitPendingClosure :exec884 SELECT commit_pending_closure($1::bigint)885 886--- PASS: TestService_cleanupPendingClosuresHandler (0.75s)887=== CONT TestPresignedUploadRegisteredBeforeCommit8882026/10/06 21:13:51 INFO Received uploads request method=POST path=/api/pending_closures8892026/10/06 21:13:51 INFO Received uploads request method=POST path=/api/pending_closures890--- PASS: TestMetricsInventory (0.82s)891=== CONT TestCompletedNarNotReofferedAcrossClosures892--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.84s)893=== CONT TestPush_OverlappingRootsStoreOneRowPerKey8942026/10/06 21:13:51 INFO Received uploads request method=POST path=/api/pending_closures8952026/10/06 21:13:51 INFO Received uploads request method=POST path=/api/pending_closures8962026/10/06 21:13:51 INFO Received uploads request method=POST path=/api/pending_closures8972026/10/06 21:13:51 INFO Received uploads request method=POST path=/api/pending_closures898--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.89s)899=== CONT TestCompleteMultipartUpload_ErrorButObjectExists9002026/10/06 21:13:51 INFO Received uploads request method=POST path=/api/pending_closures9012026/10/06 21:13:51 INFO Received uploads request method=POST path=/api/pending_closures902--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.99s)903=== CONT TestReadRedirectUsesPublicS3URL9042026/10/06 21:13:51 INFO Aborted multipart uploads count=0 kept=09052026/10/06 21:13:51 WARN Force mode enabled - objects will be deleted immediately without grace period9062026/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=09072026/10/06 21:13:51 INFO Vacuumed table table=pending_closures9082026/10/06 21:13:51 INFO Vacuumed table table=pending_objects9092026/10/06 21:13:51 INFO Vacuumed table table=multipart_uploads9102026/10/06 21:13:51 INFO Vacuumed table table=closures9112026/10/06 21:13:51 INFO Vacuumed table table=objects9122026/10/06 21:13:51 INFO Received uploads request method=POST path=/api/pending_closures913--- PASS: TestCommitRacingPendingCleanupKeepsObjects (1.02s)914=== CONT TestRedundantMultipartUpload915--- PASS: TestReadRedirectNar (1.05s)916=== CONT TestReadProxyRangeRequest9172026/10/06 21:13:51 INFO Aborted multipart uploads count=0 kept=09182026/10/06 21:13:51 WARN Force mode enabled - objects will be deleted immediately without grace period9192026/10/06 21:13:51 INFO Aborted multipart uploads count=0 kept=09202026/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=09212026/10/06 21:13:51 WARN Force mode enabled - objects will be deleted immediately without grace period922--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (1.11s)923=== CONT TestPush_SignsNarinfosOfItsPendingObjects9242026/10/06 21:13:51 INFO Vacuumed table table=pending_closures9252026/10/06 21:13:51 INFO Vacuumed table table=pending_objects9262026/10/06 21:13:51 INFO Vacuumed table table=multipart_uploads9272026/10/06 21:13:51 INFO Vacuumed table table=closures9282026/10/06 21:13:51 INFO Vacuumed table table=objects929--- PASS: TestSweepRechecksPendingAfterLocking (1.12s)930=== CONT TestReadRedirectKeepsNarinfoProxied9312026/10/06 21:13:51 INFO Aborted multipart uploads count=0 kept=09322026/10/06 21:13:51 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."9332026/10/06 21:13:51 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."9342026/10/06 21:13:51 WARN Force mode enabled - objects will be deleted immediately without grace period935--- PASS: TestFailedS3DeleteKeepsTombstone (1.13s)936=== CONT TestPinProtectsFromGC9372026/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=09382026/10/06 21:13:51 INFO Vacuumed table table=pending_closures9392026/10/06 21:13:51 INFO Vacuumed table table=pending_objects9402026/10/06 21:13:51 INFO Vacuumed table table=multipart_uploads9412026/10/06 21:13:51 INFO Vacuumed table table=closures9422026/10/06 21:13:51 INFO Vacuumed table table=objects9432026/10/06 21:13:51 INFO Aborted multipart uploads count=0 kept=09442026/10/06 21:13:51 WARN Force mode enabled - objects will be deleted immediately without grace period9452026/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=1 objects-failed-to-delete=09462026/10/06 21:13:51 INFO Vacuumed table table=pending_closures9472026/10/06 21:13:51 INFO Vacuumed table table=pending_objects9482026/10/06 21:13:51 INFO Vacuumed table table=multipart_uploads9492026/10/06 21:13:51 INFO Vacuumed table table=closures9502026/10/06 21:13:51 INFO Vacuumed table table=objects951--- PASS: TestSweepSkipsRowsLockedByPush (1.16s)952=== CONT TestCacheStatsHandler953=== NAME TestNARDeduplicationMetadataUploadBug954 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug340570266/001/store/vlksjgxhp992vzsqnfk6cx0388hmhhb8-file1.txt955=== RUN TestPush_RejectsBadRequests/no_roots956=== PAUSE TestPush_RejectsBadRequests/no_roots957=== RUN TestPush_RejectsBadRequests/no_objects958=== PAUSE TestPush_RejectsBadRequests/no_objects959=== RUN TestPush_RejectsBadRequests/bad_root960=== PAUSE TestPush_RejectsBadRequests/bad_root961=== RUN TestPush_RejectsBadRequests/root_not_in_objects962=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects963=== CONT TestDeduplicatedObjectsRecordedAsPending9642026/10/06 21:13:51 INFO Aborted multipart uploads count=0 kept=09652026/10/06 21:13:51 WARN Force mode enabled - objects will be deleted immediately without grace period9662026/10/06 21:13:51 INFO Received push request method=POST path=/api/pushes9672026/10/06 21:13:51 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=09682026/10/06 21:13:51 INFO Vacuumed table table=pending_closures9692026/10/06 21:13:51 INFO Vacuumed table table=pending_objects9702026/10/06 21:13:51 INFO Vacuumed table table=multipart_uploads9712026/10/06 21:13:51 INFO Vacuumed table table=closures9722026/10/06 21:13:51 INFO Vacuumed table table=objects973--- PASS: TestGCSweepDeliversEachKeyOnce (1.01s)974=== CONT TestClientSharedPathCommittedMidPush9752026/10/06 21:13:51 INFO Received complete push request method=POST path=/api/pushes/1/complete9762026/10/06 21:13:51 INFO Received uploads request method=POST path=/api/pending_closures9772026/10/06 21:13:51 INFO Received push request method=POST path=/api/pushes9782026/10/06 21:13:51 INFO Received push request method=POST path=/api/pushes9792026/10/06 21:13:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9802026/10/06 21:13:51 INFO Received push request method=POST path=/api/pushes9812026/10/06 21:13:51 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9822026/10/06 21:13:51 INFO Uploading vlksjgxhp992vzsqnfk6cx0388hmhhb8-file1.txt (160B)9832026/10/06 21:13:51 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"9842026/10/06 21:13:51 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9852026/10/06 21:13:51 WARN Failed to register uploaded object key=vlksjgxhp992vzsqnfk6cx0388hmhhb8.ls error="server returned 404: 404 page not found\n"9862026/10/06 21:13:51 INFO Signed narinfos id=1 count=19872026/10/06 21:13:51 INFO Uploading 1 narinfos9882026/10/06 21:13:51 INFO Received complete push request method=POST path=/api/pushes/1/complete9892026/10/06 21:13:51 WARN Failed to register uploaded object key=vlksjgxhp992vzsqnfk6cx0388hmhhb8.narinfo error="server returned 404: 404 page not found\n"9902026/10/06 21:13:51 INFO Received push request method=POST path=/api/pushes9912026/10/06 21:13:51 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZDUzODNmN2YtMjlhNC00N2ViLWIyNjMtM2FmNWEzODMzNzFmLjhmMzJlODUyLTA2MWEtNDVjMC04YjI3LTRkNzQxOTVkOTI4NngxNzkxMzIxMjMxNDU5NzQ4Mjk4 parts=109922026/10/06 21:13:51 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9932026/10/06 21:13:51 INFO Completed upload id=19942026/10/06 21:13:51 INFO Received uploads request method=POST path=/api/pending_closures9952026/10/06 21:13:51 INFO Upload complete. (76ms)996=== NAME TestNARDeduplicationMetadataUploadBug997 metadata_upload_test.go:54: Retrieved narinfo from S3:998 StorePath: /build/TestNARDeduplicationMetadataUploadBug340570266/001/store/vlksjgxhp992vzsqnfk6cx0388hmhhb8-file1.txt999 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1000 Compression: zstd1001 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1002 NarSize: 1601003 References: 1004 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf10052026/10/06 21:13:51 INFO Received uploads request method=POST path=/api/pending_closures1006 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1007 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1008 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}10092026/10/06 21:13:51 INFO Aborted multipart uploads count=0 kept=010102026/10/06 21:13:51 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10112026/10/06 21:13:51 WARN Found objects in DB but missing from S3, will re-upload count=11012--- PASS: TestService_verifyS3Integrity (1.30s)1013=== CONT TestPushDedupSurvivesConcurrentGC10142026-10-06 21:13:51.985 UTC [819] ERROR: could not obtain lock on row in relation "closures"10152026-10-06 21:13:51.985 UTC [819] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10162026-10-06 21:13:51.986 UTC [819] ERROR: could not obtain lock on row in relation "closures"10172026-10-06 21:13:51.986 UTC [819] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10182026/10/06 21:13:51 WARN Force mode enabled - objects will be deleted immediately without grace period10192026-10-06 21:13:51.986 UTC [819] ERROR: could not obtain lock on row in relation "closures"10202026-10-06 21:13:51.986 UTC [819] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10212026-10-06 21:13:51.986 UTC [819] ERROR: could not obtain lock on row in relation "closures"10222026-10-06 21:13:51.986 UTC [819] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10232026-10-06 21:13:51.986 UTC [819] ERROR: could not obtain lock on row in relation "closures"10242026-10-06 21:13:51.986 UTC [819] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1025--- PASS: TestPush_RootsAreLockedInByteOrder (0.65s)1026=== CONT TestClientWithDependencies10272026/10/06 21:13:51 INFO Received push request method=POST path=/api/pushes10282026/10/06 21:13:51 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=010292026/10/06 21:13:52 INFO Vacuumed table table=pending_closures10302026/10/06 21:13:52 INFO Vacuumed table table=pending_objects10312026/10/06 21:13:52 INFO Vacuumed table table=multipart_uploads10322026/10/06 21:13:52 INFO Vacuumed table table=closures1033=== NAME TestNARDeduplicationMetadataUploadBug10342026/10/06 21:13:52 INFO Received complete push request method=POST path=/api/pushes/1/complete1035 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug340570266/001/store/df3niyibpppm6zj6bgbm014qcrhkia9k-file2.txt10362026/10/06 21:13:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10372026/10/06 21:13:52 INFO Vacuumed table table=objects10382026/10/06 21:13:52 INFO Received complete push request method=POST path=/api/pushes/2/complete10392026/10/06 21:13:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1040--- PASS: TestService_Rustfstest (0.65s)1041=== CONT TestGCMetrics1042--- PASS: TestPush_RepeatedRootCommitsOnce (0.67s)1043=== CONT TestClientMultipleUploads1044--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.77s)1045=== CONT TestClientIntegration10462026/10/06 21:13:52 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZDUzODNmN2YtMjlhNC00N2ViLWIyNjMtM2FmNWEzODMzNzFmLjgxYWJlMThhLTY3YzktNDFmMC04NThkLWJhYjk4ZDFjYmFjZXgxNzkxMzIxMjMxNTM5MzE2MjQ2 parts=1010472026/10/06 21:13:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10482026/10/06 21:13:52 INFO Received push request method=POST path=/api/pushes10492026/10/06 21:13:52 INFO Completed upload id=110502026/10/06 21:13:52 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010512026/10/06 21:13:52 INFO Received uploads request method=POST path=/api/pending_closures10522026/10/06 21:13:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures10532026/10/06 21:13:52 INFO Aborted multipart uploads count=0 kept=010542026/10/06 21:13:52 INFO Received uploads request method=POST path=/api/pending_closures10552026/10/06 21:13:52 INFO Received complete push request method=POST path=/api/pushes/1/complete10562026/10/06 21:13:52 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=010572026/10/06 21:13:52 INFO Received push request method=POST path=/api/pushes10582026/10/06 21:13:52 INFO Vacuumed table table=pending_closures10592026/10/06 21:13:52 INFO Vacuumed table table=pending_objects1060--- PASS: TestPush_CompleteCommitsEveryRoot (0.67s)10612026/10/06 21:13:52 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1062=== CONT TestGCBugBareHashReferences10632026/10/06 21:13:52 INFO Vacuumed table table=multipart_uploads10642026/10/06 21:13:52 WARN Failed to register uploaded object key=df3niyibpppm6zj6bgbm014qcrhkia9k.ls error="server returned 404: 404 page not found\n"10652026/10/06 21:13:52 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign10662026/10/06 21:13:52 INFO Signed narinfos id=2 count=110672026/10/06 21:13:52 INFO Uploading 1 narinfos10682026/10/06 21:13:52 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10692026/10/06 21:13:52 INFO Received uploads request method=POST path=/api/pending_closures10702026/10/06 21:13:52 INFO Vacuumed table table=closures10712026/10/06 21:13:52 INFO Vacuumed table table=objects10722026/10/06 21:13:52 INFO Received uploads request method=POST path=/api/pending_closures1073--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.67s)1074=== CONT TestClientErrorHandling10752026/10/06 21:13:52 INFO Received complete push request method=POST path=/api/pushes/2/complete1076=== RUN TestClientErrorHandling/InvalidStorePath1077=== PAUSE TestClientErrorHandling/InvalidStorePath10782026/10/06 21:13:52 WARN Failed to register uploaded object key=df3niyibpppm6zj6bgbm014qcrhkia9k.narinfo error="server returned 404: 404 page not found\n"1079=== RUN TestClientErrorHandling/InvalidAuthToken1080=== PAUSE TestClientErrorHandling/InvalidAuthToken1081=== RUN TestClientErrorHandling/ServerNotAvailable1082=== PAUSE TestClientErrorHandling/ServerNotAvailable1083=== CONT TestGCAdvisoryLockBlocksConcurrentRun10842026/10/06 21:13:52 INFO Upload complete. (55ms)1085=== NAME TestNARDeduplicationMetadataUploadBug1086 metadata_upload_test.go:76: Retrieved narinfo from S3:1087 StorePath: /build/TestNARDeduplicationMetadataUploadBug340570266/001/store/df3niyibpppm6zj6bgbm014qcrhkia9k-file2.txt1088 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1089 Compression: zstd1090 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1091 NarSize: 1601092 References: 1093 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf10942026/10/06 21:13:52 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001095 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1096 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1097 {"version":1,"root":{"type":"regular","size":44}}1098--- PASS: TestService_createPendingClosureHandler (1.43s)1099=== CONT TestClientCADerivations1100--- PASS: TestNARDeduplicationMetadataUploadBug (1.43s)1101=== CONT TestLeadEndsOnShutdown11022026/10/06 21:13:52 INFO Received push request method=POST path=/api/pushes1103--- PASS: TestPushWaitsForSweepHoldingRow (1.45s)1104=== CONT TestLeadIncumbentAnnouncesAtOnce11052026/10/06 21:13:52 INFO Received uploads request method=POST path=/api/pending_closures1106--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.64s)1107=== CONT TestResolveDBConnectionString1108=== RUN TestResolveDBConnectionString/flag_wins1109=== PAUSE TestResolveDBConnectionString/flag_wins1110=== RUN TestResolveDBConnectionString/file_when_flag_empty1111=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1112=== RUN TestResolveDBConnectionString/missing_file_is_an_error1113=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1114=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1115=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1116=== RUN TestResolveDBConnectionString/nothing_configured1117=== PAUSE TestResolveDBConnectionString/nothing_configured1118=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock11192026/10/06 21:13:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11202026/10/06 21:13:52 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZDUzODNmN2YtMjlhNC00N2ViLWIyNjMtM2FmNWEzODMzNzFmLmJjNTk2NDcyLTgzZDUtNDViOS1iMTc5LTY2NTk1YWIyOTc1ZHgxNzkxMzIxMjMyMTY3OTM2MjY51121--- PASS: TestReadRedirectUsesPublicS3URL (0.53s)1122=== CONT TestLeadElectsOneAndHandsOver11232026/10/06 21:13:52 INFO Received uploads request method=POST path=/api/pending_closures11242026/10/06 21:13:52 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZDUzODNmN2YtMjlhNC00N2ViLWIyNjMtM2FmNWEzODMzNzFmLmJjNTk2NDcyLTgzZDUtNDViOS1iMTc5LTY2NTk1YWIyOTc1ZHgxNzkxMzIxMjMyMTY3OTM2MjY5 parts=11125--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.65s)1126=== CONT TestClientFallsBackToClosures11272026/10/06 21:13:52 INFO Received uploads request method=POST path=/api/pending_closures1128--- PASS: TestReadProxyRangeRequest (0.53s)1129=== CONT TestConnectWaitsForAPeerMigration11302026-10-06 21:13:52.286 UTC [824] ERROR: Push does not exist: id=111312026-10-06 21:13:52.286 UTC [824] CONTEXT: PL/pgSQL function commit_push(bigint) line 10 at RAISE11322026-10-06 21:13:52.286 UTC [824] STATEMENT: SELECT commit_push($1)1133--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.94s)1134=== CONT TestClientPushesUseOnePush11352026/10/06 21:13:52 INFO Received push request method=POST path=/api/pushes11362026/10/06 21:13:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11372026/10/06 21:13:52 INFO Signed narinfos id=1 count=111382026/10/06 21:13:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11392026/10/06 21:13:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11402026/10/06 21:13:52 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"11412026/10/06 21:13:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11422026/10/06 21:13:52 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"11432026/10/06 21:13:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11442026/10/06 21:13:52 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=111452026/10/06 21:13:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11462026/10/06 21:13:52 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1147--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.51s)1148=== CONT TestService_AuthMiddleware_OIDC1149--- PASS: TestReadRedirectKeepsNarinfoProxied (0.51s)1150=== CONT TestProxyHeadersOnlyTrustedOnSocket11512026/10/06 21:13:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46205/oidc1152--- PASS: TestCacheStatsHandler (0.55s)1153=== CONT TestService_RequireScope_OIDC11542026/10/06 21:13:52 INFO Received uploads request method=POST path=/api/pending_closures1155--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.56s)1156=== CONT TestService_ReadScope_PublicByDefault1157=== NAME TestPinProtectsFromGC1158 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC3195018900/001/store/rkiwfsxql3cg5jxzwmn5r3qbcgvzhkbz-pinned-file.txt1159 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC3195018900/001/store/4r5vd810p1vhx48mf8mblhf1lg32lyk0-unpinned-file.txt11602026/10/06 21:13:52 INFO Received uploads request method=POST path=/api/pending_closures11612026/10/06 21:13:52 INFO Received push request method=POST path=/api/pushes11622026/10/06 21:13:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11632026/10/06 21:13:52 INFO Uploading rkiwfsxql3cg5jxzwmn5r3qbcgvzhkbz-pinned-file.txt (128B)11642026/10/06 21:13:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36169/oidc11652026/10/06 21:13:52 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"11662026/10/06 21:13:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11672026/10/06 21:13:52 INFO Signed narinfos id=1 count=111682026/10/06 21:13:52 WARN Failed to register uploaded object key=rkiwfsxql3cg5jxzwmn5r3qbcgvzhkbz.ls error="server returned 404: 404 page not found\n"11692026/10/06 21:13:52 INFO Uploading 1 narinfos11702026/10/06 21:13:52 INFO Received complete push request method=POST path=/api/pushes/1/complete11712026/10/06 21:13:52 WARN Failed to register uploaded object key=rkiwfsxql3cg5jxzwmn5r3qbcgvzhkbz.narinfo error="server returned 404: 404 page not found\n"11722026/10/06 21:13:52 INFO Upload complete. (68ms)11732026/10/06 21:13:52 INFO Aborted multipart uploads count=0 kept=011742026/10/06 21:13:52 INFO Aborted multipart uploads count=0 kept=011752026/10/06 21:13:52 WARN Force mode enabled - objects will be deleted immediately without grace period11762026/10/06 21:13:52 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=01177=== NAME TestClientIntegration1178 client_integration_test.go:286: Created store path: /build/TestClientIntegration395779727/002/store/haz6wc0sk7c2ay069d0pg71qrin1zdxd-test-file.txt11792026/10/06 21:13:52 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=011802026/10/06 21:13:52 INFO Vacuumed table table=pending_closures11812026/10/06 21:13:52 INFO Vacuumed table table=pending_objects11822026/10/06 21:13:52 INFO Vacuumed table table=pending_closures11832026/10/06 21:13:52 INFO Vacuumed table table=multipart_uploads11842026/10/06 21:13:52 INFO Vacuumed table table=closures11852026/10/06 21:13:52 INFO Vacuumed table table=objects11862026/10/06 21:13:52 INFO Vacuumed table table=pending_objects11872026/10/06 21:13:52 INFO Vacuumed table table=multipart_uploads11882026/10/06 21:13:52 INFO Vacuumed table table=closures11892026/10/06 21:13:52 INFO Vacuumed table table=objects1190--- PASS: TestGCMetrics (0.58s)1191=== CONT TestReadProxyDisabled11922026/10/06 21:13:52 INFO Aborted multipart uploads count=0 kept=01193=== NAME TestClientWithDependencies1194 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies555631786/001/store/swd93aj7d95101vi5982da3pwv6x345l-test-script11952026/10/06 21:13:52 WARN Force mode enabled - objects will be deleted immediately without grace period11962026/10/06 21:13:52 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=011972026/10/06 21:13:52 INFO Vacuumed table table=pending_closures11982026/10/06 21:13:52 INFO Received push request method=POST path=/api/pushes11992026/10/06 21:13:52 INFO Vacuumed table table=pending_objects12002026/10/06 21:13:52 INFO Vacuumed table table=multipart_uploads12012026/10/06 21:13:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12022026/10/06 21:13:52 INFO Uploading 4r5vd810p1vhx48mf8mblhf1lg32lyk0-unpinned-file.txt (128B)12032026/10/06 21:13:52 INFO Vacuumed table table=closures12042026/10/06 21:13:52 INFO Vacuumed table table=objects1205--- PASS: TestPushDedupSurvivesConcurrentGC (0.64s)1206=== CONT TestCacheConfigHandler1207=== RUN TestCacheConfigHandler/full_config,_no_issuer1208=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1209=== RUN TestCacheConfigHandler/no_cache_url_configured1210=== PAUSE TestCacheConfigHandler/no_cache_url_configured1211=== RUN TestCacheConfigHandler/no_signing_keys1212=== PAUSE TestCacheConfigHandler/no_signing_keys1213=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1214=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1215=== CONT TestService_AuthMiddleware_MTLSBoundSubjects12162026/10/06 21:13:52 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"12172026/10/06 21:13:52 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12182026/10/06 21:13:52 WARN Failed to register uploaded object key=4r5vd810p1vhx48mf8mblhf1lg32lyk0.ls error="server returned 404: 404 page not found\n"12192026/10/06 21:13:52 INFO Signed narinfos id=2 count=112202026/10/06 21:13:52 INFO Uploading 1 narinfos12212026/10/06 21:13:52 INFO Received complete push request method=POST path=/api/pushes/2/complete12222026/10/06 21:13:52 WARN Failed to register uploaded object key=4r5vd810p1vhx48mf8mblhf1lg32lyk0.narinfo error="server returned 404: 404 page not found\n"12232026/10/06 21:13:52 INFO Upload complete. (61ms)12242026/10/06 21:13:52 INFO Received push request method=POST path=/api/pushes1225=== NAME TestClientWithDependencies1226 client_integration_test.go:615: Found 1 dependencies (including self)12272026/10/06 21:13:52 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)12282026/10/06 21:13:52 INFO Uploading 4lxpg5n7h2d59da4l4ahm0xwiirplnrx-top (224B)12292026/10/06 21:13:52 INFO Uploading qb07ycbnhp7x956vx1bi3d1bxm5rghr7-shared-dep (136B)1230=== NAME TestClientMultipleUploads1231 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads2805185131/001/store/fjcflql4l0cfp4k6dj14zmvl0d8bx4d2-test-file-0.txt12322026/10/06 21:13:52 WARN Failed to register uploaded object key=nar/176v6wwjzh33ccy08fwm3ilqsh8jfgbqa89zgwrbxnxj7vrw7x9p.nar.zst error="server returned 404: 404 page not found\n"12332026/10/06 21:13:52 WARN Failed to register uploaded object key=4lxpg5n7h2d59da4l4ahm0xwiirplnrx.ls error="server returned 404: 404 page not found\n"12342026/10/06 21:13:52 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12352026/10/06 21:13:52 WARN Failed to register uploaded object key=qb07ycbnhp7x956vx1bi3d1bxm5rghr7.ls error="server returned 404: 404 page not found\n"12362026/10/06 21:13:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12372026/10/06 21:13:52 INFO Signed narinfos id=1 count=212382026/10/06 21:13:52 INFO Uploading 2 narinfos12392026/10/06 21:13:52 WARN Failed to register uploaded object key=4lxpg5n7h2d59da4l4ahm0xwiirplnrx.narinfo error="server returned 404: 404 page not found\n"12402026/10/06 21:13:52 INFO Received complete push request method=POST path=/api/pushes/1/complete12412026/10/06 21:13:52 WARN Failed to register uploaded object key=qb07ycbnhp7x956vx1bi3d1bxm5rghr7.narinfo error="server returned 404: 404 page not found\n"12422026/10/06 21:13:52 INFO Upload complete. (102ms)1243=== NAME TestClientSharedPathCommittedMidPush1244 client_integration_test.go:680: Retrieved narinfo from S3:1245 StorePath: /build/TestClientSharedPathCommittedMidPush1175441851/001/store/qb07ycbnhp7x956vx1bi3d1bxm5rghr7-shared-dep1246 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1247 Compression: zstd1248 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821249 NarSize: 1361250 References: 1251 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1252 client_integration_test.go:680: Retrieved narinfo from S3:1253 StorePath: /build/TestClientSharedPathCommittedMidPush1175441851/001/store/4lxpg5n7h2d59da4l4ahm0xwiirplnrx-top1254 URL: nar/176v6wwjzh33ccy08fwm3ilqsh8jfgbqa89zgwrbxnxj7vrw7x9p.nar.zst1255 Compression: zstd1256 NarHash: sha256:176v6wwjzh33ccy08fwm3ilqsh8jfgbqa89zgwrbxnxj7vrw7x9p1257 NarSize: 2241258 References: /build/TestClientSharedPathCommittedMidPush1175441851/001/store/qb07ycbnhp7x956vx1bi3d1bxm5rghr7-shared-dep1259 CA: text:sha256:1lfmmay7ggssy9hc90j7pdyjg1012ycpmyr6qjwmkk1w8v5x0w0412602026/10/06 21:13:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures12612026/10/06 21:13:52 INFO Garbage collection started1262--- PASS: TestClientSharedPathCommittedMidPush (0.78s)1263=== CONT TestReadProxyRootRedirectsToIndexHTML12642026/10/06 21:13:52 INFO Received push request method=POST path=/api/pushes12652026/10/06 21:13:52 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"1266=== NAME TestClientMultipleUploads1267 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads2805185131/001/store/phjz9nmrhlcg7l3xdbf4fmivs5khn1gj-test-file-1.txt1268--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.59s)1269=== CONT TestService_ReadAuthMiddleware12702026/10/06 21:13:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12712026/10/06 21:13:52 INFO Uploading haz6wc0sk7c2ay069d0pg71qrin1zdxd-test-file.txt (152B)12722026/10/06 21:13:52 INFO Aborted multipart uploads count=0 kept=012732026/10/06 21:13:52 WARN Force mode enabled - objects will be deleted immediately without grace period12742026/10/06 21:13:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12752026/10/06 21:13:52 INFO lead: acquired remote=192.0.2.1:123412762026/10/06 21:13:52 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12772026/10/06 21:13:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12782026/10/06 21:13:52 WARN Failed to register uploaded object key=haz6wc0sk7c2ay069d0pg71qrin1zdxd.ls error="server returned 404: 404 page not found\n"12792026/10/06 21:13:52 INFO Signed narinfos id=1 count=112802026/10/06 21:13:52 INFO Uploading 1 narinfos12812026/10/06 21:13:52 INFO Received complete push request method=POST path=/api/pushes/1/complete12822026/10/06 21:13:52 WARN Failed to register uploaded object key=haz6wc0sk7c2ay069d0pg71qrin1zdxd.narinfo error="server returned 404: 404 page not found\n"12832026/10/06 21:13:52 INFO Upload complete. (75ms)12842026/10/06 21:13:52 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=012852026/10/06 21:13:52 INFO Vacuumed table table=pending_closures12862026/10/06 21:13:52 INFO Vacuumed table table=pending_objects12872026/10/06 21:13:52 INFO Vacuumed table table=multipart_uploads12882026/10/06 21:13:52 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZDUzODNmN2YtMjlhNC00N2ViLWIyNjMtM2FmNWEzODMzNzFmLmI2YTI0NDBlLTA0NmEtNDg1Yy05NDgwLTllNWVhMTE3ZGM4OHgxNzkxMzIxMjMyMTA4MTM1Njc0 parts=1212892026/10/06 21:13:52 INFO Vacuumed table table=closures12902026/10/06 21:13:52 INFO Received uploads request method=POST path=/api/pending_closures12912026/10/06 21:13:52 INFO Vacuumed table table=objects12922026/10/06 21:13:52 INFO lead: acquired remote=192.0.2.1:123412932026/10/06 21:13:52 INFO lead: released remote=192.0.2.1:12341294--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.60s)1295=== CONT TestReadProxy4041296--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.23s)1297=== CONT TestReadProxyConditionalGet12982026/10/06 21:13:52 INFO Received push request method=POST path=/api/pushes1299=== NAME TestClientMultipleUploads1300 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads2805185131/001/store/a0sgaznd7q6y756c66d9m29cn0wcpfb7-test-file-2.txt13012026/10/06 21:13:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13022026/10/06 21:13:52 INFO Uploading swd93aj7d95101vi5982da3pwv6x345l-test-script (136B)13032026/10/06 21:13:52 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"13042026/10/06 21:13:52 WARN Failed to register uploaded object key=swd93aj7d95101vi5982da3pwv6x345l.ls error="server returned 404: 404 page not found\n"13052026/10/06 21:13:52 WARN Failed to register uploaded object key=log/l1hss81w3zccvhh96ni6vbxmxv4bx7vv-test-script.drv error="server returned 404: 404 page not found\n"13062026/10/06 21:13:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13072026/10/06 21:13:52 INFO Signed narinfos id=1 count=113082026/10/06 21:13:52 INFO Uploading 1 narinfos13092026/10/06 21:13:52 INFO Received complete push request method=POST path=/api/pushes/1/complete13102026/10/06 21:13:52 WARN Failed to register uploaded object key=swd93aj7d95101vi5982da3pwv6x345l.narinfo error="server returned 404: 404 page not found\n"13112026/10/06 21:13:52 INFO All 1 paths already cached1312=== NAME TestClientCADerivations1313 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3689564632/001/store/n6mad2407h0r92prv09dj071s5gfxzj6-ca-test1314=== NAME TestClientIntegration1315 client_integration_test.go:312: Retrieved narinfo from S3:1316 StorePath: /build/TestClientIntegration395779727/002/store/haz6wc0sk7c2ay069d0pg71qrin1zdxd-test-file.txt1317 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1318 Compression: zstd1319 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11320 NarSize: 1521321 References: 1322 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11323 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1324 client_integration_test.go:313: Decompressed .ls content (64 bytes):1325 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1326 client_integration_test.go:316: Testing garbage collection...13272026/10/06 21:13:52 INFO Upload complete. (75ms)1328=== NAME TestClientWithDependencies1329 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies555631786/001/store) requires matching store prefix1330--- PASS: TestClientWithDependencies (0.78s)1331=== CONT TestReadProxyNarStreaming13322026/10/06 21:13:52 INFO lead: acquired remote=192.0.2.1:12341333=== NAME TestClientCADerivations1334 client_ca_test.go:139: Found 1 dependencies (including self)13352026/10/06 21:13:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13362026/10/06 21:13:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures13372026/10/06 21:13:52 INFO Garbage collection started13382026/10/06 21:13:52 INFO Aborted multipart uploads count=0 kept=013392026/10/06 21:13:52 WARN Force mode enabled - objects will be deleted immediately without grace period13402026/10/06 21:13:52 INFO Received push request method=POST path=/api/pushes13412026/10/06 21:13:52 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)13422026/10/06 21:13:52 INFO Uploading fjcflql4l0cfp4k6dj14zmvl0d8bx4d2-test-file-0.txt (160B)13432026/10/06 21:13:52 INFO Uploading phjz9nmrhlcg7l3xdbf4fmivs5khn1gj-test-file-1.txt (160B)13442026/10/06 21:13:52 INFO Uploading a0sgaznd7q6y756c66d9m29cn0wcpfb7-test-file-2.txt (160B)13452026/10/06 21:13:52 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZDUzODNmN2YtMjlhNC00N2ViLWIyNjMtM2FmNWEzODMzNzFmLmM2MDJmNzIxLWRlZDMtNGRkNC05ZjQ5LTVkMzdjNjYwZThjY3gxNzkxMzIxMjMyMjMzNjA4Mzg5 parts=1213462026/10/06 21:13:52 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=013472026/10/06 21:13:52 INFO Received uploads request method=POST path=/api/pending_closures13482026/10/06 21:13:52 WARN Failed to register uploaded object key=fjcflql4l0cfp4k6dj14zmvl0d8bx4d2.ls error="server returned 404: 404 page not found\n"13492026/10/06 21:13:52 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"13502026/10/06 21:13:52 INFO Vacuumed table table=pending_closures13512026/10/06 21:13:52 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"13522026/10/06 21:13:52 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"13532026/10/06 21:13:52 WARN Failed to register uploaded object key=phjz9nmrhlcg7l3xdbf4fmivs5khn1gj.ls error="server returned 404: 404 page not found\n"13542026/10/06 21:13:52 WARN Failed to register uploaded object key=a0sgaznd7q6y756c66d9m29cn0wcpfb7.ls error="server returned 404: 404 page not found\n"13552026/10/06 21:13:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13562026/10/06 21:13:52 INFO Signed narinfos id=1 count=313572026/10/06 21:13:52 INFO Uploading 3 narinfos13582026/10/06 21:13:52 INFO Vacuumed table table=pending_objects13592026/10/06 21:13:52 INFO Vacuumed table table=multipart_uploads13602026/10/06 21:13:52 INFO Received uploads request method=POST path=/api/pending_closures13612026/10/06 21:13:52 WARN Failed to register uploaded object key=fjcflql4l0cfp4k6dj14zmvl0d8bx4d2.narinfo error="server returned 404: 404 page not found\n"13622026/10/06 21:13:52 WARN Failed to register uploaded object key=phjz9nmrhlcg7l3xdbf4fmivs5khn1gj.narinfo error="server returned 404: 404 page not found\n"13632026/10/06 21:13:52 INFO Received complete push request method=POST path=/api/pushes/1/complete13642026/10/06 21:13:52 INFO Vacuumed table table=closures13652026/10/06 21:13:52 WARN Failed to register uploaded object key=a0sgaznd7q6y756c66d9m29cn0wcpfb7.narinfo error="server returned 404: 404 page not found\n"1366--- PASS: TestGCBugBareHashReferences (0.77s)1367=== CONT TestReadProxyOutlastsServerWriteTimeout13682026/10/06 21:13:52 INFO Vacuumed table table=objects13692026/10/06 21:13:52 INFO Upload complete. (71ms)1370=== NAME TestClientMultipleUploads1371 client_integration_test.go:369: Uploaded 3 paths in 119.360171ms13722026/10/06 21:13:52 INFO Starting HTTP server address=127.0.0.1:4180713732026/10/06 21:13:52 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket2381905854/001/proxy.sock13742026/10/06 21:13:52 WARN mTLS auth: subject not in bound subjects subject="CN=someone"13752026/10/06 21:13:52 INFO Shutdown signal received, draining in-flight requests timeout=10s1376--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.54s)1377=== CONT TestReadProxyContentNegotiation1378--- PASS: TestClientMultipleUploads (0.85s)1379=== CONT TestReadProxyHead1380=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1381=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1382=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1383=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1384=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1385=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1386=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1387=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1388=== CONT TestOrphanedObjectsGCStressTest1389--- PASS: TestService_ReadScope_PublicByDefault (0.50s)1390=== CONT TestReadProxyInvalidPath13912026/10/06 21:13:52 INFO Received push request method=POST path=/api/pushes13922026/10/06 21:13:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13932026/10/06 21:13:52 INFO Uploading n6mad2407h0r92prv09dj071s5gfxzj6-ca-test (144B)13942026/10/06 21:13:52 WARN Failed to register uploaded object key=n6mad2407h0r92prv09dj071s5gfxzj6.ls error="server returned 404: 404 page not found\n"13952026/10/06 21:13:52 WARN Failed to register uploaded object key=log/m4s7xxycvj6rphgwxfl0w1cjrr3srhri-ca-test.drv error="server returned 404: 404 page not found\n"13962026/10/06 21:13:52 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13972026/10/06 21:13:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13982026/10/06 21:13:52 INFO Signed narinfos id=1 count=113992026/10/06 21:13:52 INFO Uploading 1 narinfos14002026/10/06 21:13:52 INFO Received complete push request method=POST path=/api/pushes/1/complete14012026/10/06 21:13:52 WARN Failed to register uploaded object key=n6mad2407h0r92prv09dj071s5gfxzj6.narinfo error="server returned 404: 404 page not found\n"1402=== RUN TestService_RequireScope_OIDC/builder_may_write1403=== PAUSE TestService_RequireScope_OIDC/builder_may_write1404=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1405=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1406=== RUN TestService_RequireScope_OIDC/ops_may_admin1407=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1408=== RUN TestService_RequireScope_OIDC/ops_may_not_write1409=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1410=== RUN TestService_RequireScope_OIDC/reader_may_not_write1411=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1412=== RUN TestService_RequireScope_OIDC/static_token_may_admin1413=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1414=== RUN TestService_RequireScope_OIDC/static_token_may_write1415=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1416=== RUN TestService_RequireScope_OIDC/reader_may_read1417=== PAUSE TestService_RequireScope_OIDC/reader_may_read1418=== RUN TestService_RequireScope_OIDC/writer_implies_read1419=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1420=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1421=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1422=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1423=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1424=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1425=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1426=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1427=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1428=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1429=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1430=== CONT TestParseSingleRange1431=== RUN TestParseSingleRange/none1432=== PAUSE TestParseSingleRange/none1433=== RUN TestParseSingleRange/unknown_unit1434=== PAUSE TestParseSingleRange/unknown_unit1435=== RUN TestParseSingleRange/multi-range_ignored1436=== PAUSE TestParseSingleRange/multi-range_ignored1437=== RUN TestParseSingleRange/malformed_no_dash1438=== PAUSE TestParseSingleRange/malformed_no_dash1439=== RUN TestParseSingleRange/malformed_both_empty1440=== PAUSE TestParseSingleRange/malformed_both_empty1441=== RUN TestParseSingleRange/malformed_end_before_start1442=== PAUSE TestParseSingleRange/malformed_end_before_start1443=== RUN TestParseSingleRange/closed1444=== PAUSE TestParseSingleRange/closed1445=== RUN TestParseSingleRange/open-ended1446=== PAUSE TestParseSingleRange/open-ended1447=== RUN TestParseSingleRange/end_clamped_to_size1448=== PAUSE TestParseSingleRange/end_clamped_to_size1449=== RUN TestParseSingleRange/suffix1450=== PAUSE TestParseSingleRange/suffix1451=== RUN TestParseSingleRange/suffix_exceeds_size1452=== PAUSE TestParseSingleRange/suffix_exceeds_size1453=== RUN TestParseSingleRange/single_byte1454=== PAUSE TestParseSingleRange/single_byte1455=== RUN TestParseSingleRange/start_past_EOF1456=== PAUSE TestParseSingleRange/start_past_EOF1457=== RUN TestParseSingleRange/start_far_past_EOF1458=== PAUSE TestParseSingleRange/start_far_past_EOF1459=== CONT TestPresentNotReportedWhileGCDeletesClosure1460=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1461=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1462=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1463=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1464=== CONT TestService_AuthMiddleware_MTLSProxyHeader14652026/10/06 21:13:52 INFO Upload complete. (127ms)1466--- PASS: TestReadProxyDisabled (0.37s)1467=== CONT TestReadProxyNarinfoAlreadyDecompressed1468=== NAME TestClientCADerivations1469 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3689564632/001/store/n6mad2407h0r92prv09dj071s5gfxzj6-ca-test1470 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1471 Compression: zstd1472 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1473 NarSize: 1441474 References: 1475 Deriver: /build/TestClientCADerivations3689564632/001/store/m4s7xxycvj6rphgwxfl0w1cjrr3srhri-ca-test.drv1476 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1477 client_ca_test.go:185: Checking for realisation files in S3...1478 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1479 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache14802026/10/06 21:13:52 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"14812026/10/06 21:13:52 WARN mTLS auth: bound subjects configured but subject DN unavailable14822026/10/06 21:13:53 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1483--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.38s)1484=== CONT TestPresentRefreshesOnlyStaleClosures1485--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.35s)1486=== CONT TestIsValidCachePath1487=== RUN TestIsValidCachePath/narinfo1488=== PAUSE TestIsValidCachePath/narinfo1489=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1490=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1491=== RUN TestIsValidCachePath/nar_zst1492=== PAUSE TestIsValidCachePath/nar_zst1493=== RUN TestIsValidCachePath/nar_xz1494=== PAUSE TestIsValidCachePath/nar_xz1495=== RUN TestIsValidCachePath/nar_bz21496=== PAUSE TestIsValidCachePath/nar_bz21497=== RUN TestIsValidCachePath/nar_uncompressed1498=== PAUSE TestIsValidCachePath/nar_uncompressed1499=== RUN TestIsValidCachePath/ls1500=== PAUSE TestIsValidCachePath/ls1501=== RUN TestIsValidCachePath/log1502=== PAUSE TestIsValidCachePath/log1503=== RUN TestIsValidCachePath/realisation1504=== PAUSE TestIsValidCachePath/realisation1505=== RUN TestIsValidCachePath/nix-cache-info1506=== PAUSE TestIsValidCachePath/nix-cache-info1507=== RUN TestIsValidCachePath/index.html1508=== PAUSE TestIsValidCachePath/index.html1509=== RUN TestIsValidCachePath/traversal_parent1510=== PAUSE TestIsValidCachePath/traversal_parent1511=== RUN TestIsValidCachePath/traversal_in_middle1512=== PAUSE TestIsValidCachePath/traversal_in_middle1513=== RUN TestIsValidCachePath/invalid_char_e1514=== PAUSE TestIsValidCachePath/invalid_char_e1515=== RUN TestIsValidCachePath/invalid_char_u1516=== PAUSE TestIsValidCachePath/invalid_char_u1517=== RUN TestIsValidCachePath/random_path1518=== PAUSE TestIsValidCachePath/random_path1519=== RUN TestIsValidCachePath/empty1520=== PAUSE TestIsValidCachePath/empty1521=== RUN TestIsValidCachePath/leading_slash1522=== PAUSE TestIsValidCachePath/leading_slash1523=== RUN TestIsValidCachePath/wrong_extension1524=== PAUSE TestIsValidCachePath/wrong_extension1525=== RUN TestIsValidCachePath/short_hash1526=== PAUSE TestIsValidCachePath/short_hash1527=== CONT TestPresentReportsOnlyClosureRoots15282026/10/06 21:13:53 INFO Received uploads request method=POST path=/api/pending_closures15292026/10/06 21:13:53 INFO Received uploads request method=POST path=/api/pending_closures15302026/10/06 21:13:53 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15312026/10/06 21:13:53 INFO Uploading nyvcal8jwvwcfp0ghdm20blnb1p1vllr-a (216B)15322026/10/06 21:13:53 INFO Uploading jvjq2cz78fnkanxzsd9ghxgzbjzx0zgy-shared-dep (136B)15332026/10/06 21:13:53 WARN Failed to register uploaded object key=fjrd9ablgjwh0wvgsgdwvy85rni68lzk.ls error="server returned 404: 404 page not found\n"15342026/10/06 21:13:53 WARN Failed to register uploaded object key=nar/1242wpi6dg09x1264qggsbz318a43waj1q1ca3l9jsmdd24g0agq.nar.zst error="server returned 404: 404 page not found\n"15352026/10/06 21:13:53 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15362026/10/06 21:13:53 WARN Failed to register uploaded object key=nyvcal8jwvwcfp0ghdm20blnb1p1vllr.ls error="server returned 404: 404 page not found\n"15372026/10/06 21:13:53 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15382026/10/06 21:13:53 WARN Failed to register uploaded object key=jvjq2cz78fnkanxzsd9ghxgzbjzx0zgy.ls error="server returned 404: 404 page not found\n"15392026/10/06 21:13:53 INFO Signed narinfos id=1 count=215402026/10/06 21:13:53 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign1541--- PASS: TestService_ReadAuthMiddleware (0.37s)1542=== CONT TestReadProxyNarinfo15432026/10/06 21:13:53 INFO Signed narinfos id=2 count=215442026/10/06 21:13:53 INFO Uploading 4 narinfos15452026/10/06 21:13:53 WARN Failed to register uploaded object key=nyvcal8jwvwcfp0ghdm20blnb1p1vllr.narinfo error="server returned 404: 404 page not found\n"15462026/10/06 21:13:53 WARN Failed to register uploaded object key=jvjq2cz78fnkanxzsd9ghxgzbjzx0zgy.narinfo error="server returned 404: 404 page not found\n"15472026/10/06 21:13:53 WARN Failed to register uploaded object key=fjrd9ablgjwh0wvgsgdwvy85rni68lzk.narinfo error="server returned 404: 404 page not found\n"15482026/10/06 21:13:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15492026/10/06 21:13:53 WARN Failed to register uploaded object key=jvjq2cz78fnkanxzsd9ghxgzbjzx0zgy.narinfo error="server returned 404: 404 page not found\n"15502026/10/06 21:13:53 INFO Completed upload id=115512026/10/06 21:13:53 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15522026/10/06 21:13:53 INFO Completed upload id=215532026/10/06 21:13:53 INFO Upload complete. (102ms)15542026/10/06 21:13:53 INFO Received push request method=POST path=/api/pushes1555=== NAME TestClientFallsBackToClosures1556 client_pushes_test.go:112: Retrieved narinfo from S3:1557 StorePath: /build/TestClientFallsBackToClosures487051473/001/store/jvjq2cz78fnkanxzsd9ghxgzbjzx0zgy-shared-dep1558 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1559 Compression: zstd1560 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821561 NarSize: 1361562 References: 1563 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1564 client_pushes_test.go:112: Retrieved narinfo from S3:1565 StorePath: /build/TestClientFallsBackToClosures487051473/001/store/nyvcal8jwvwcfp0ghdm20blnb1p1vllr-a1566 URL: nar/1242wpi6dg09x1264qggsbz318a43waj1q1ca3l9jsmdd24g0agq.nar.zst1567 Compression: zstd1568 NarHash: sha256:1242wpi6dg09x1264qggsbz318a43waj1q1ca3l9jsmdd24g0agq1569 NarSize: 2161570 References: /build/TestClientFallsBackToClosures487051473/001/store/jvjq2cz78fnkanxzsd9ghxgzbjzx0zgy-shared-dep1571 CA: text:sha256:138l5gdx5i5cg3xsj4q0zs0pabw444nqp963i6608w9vwpl8zd2x15722026/10/06 21:13:53 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15732026/10/06 21:13:53 INFO Uploading vnrr8hlpspp62j87hzd42mcsfqgj8y39-a (208B)15742026/10/06 21:13:53 INFO Uploading yh2h8xvwgj69d8sbhq3pp00rlv02g59c-shared-dep (136B)1575 client_pushes_test.go:112: Retrieved narinfo from S3:1576 StorePath: /build/TestClientFallsBackToClosures487051473/001/store/fjrd9ablgjwh0wvgsgdwvy85rni68lzk-b1577 URL: nar/1242wpi6dg09x1264qggsbz318a43waj1q1ca3l9jsmdd24g0agq.nar.zst1578 Compression: zstd1579 NarHash: sha256:1242wpi6dg09x1264qggsbz318a43waj1q1ca3l9jsmdd24g0agq1580 NarSize: 2161581 References: /build/TestClientFallsBackToClosures487051473/001/store/jvjq2cz78fnkanxzsd9ghxgzbjzx0zgy-shared-dep1582 CA: text:sha256:138l5gdx5i5cg3xsj4q0zs0pabw444nqp963i6608w9vwpl8zd2x1583--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.93s)1584=== CONT TestCreatePin_ReservedPins15852026/10/06 21:13:53 WARN Failed to register uploaded object key=vnrr8hlpspp62j87hzd42mcsfqgj8y39.ls error="server returned 404: 404 page not found\n"15862026/10/06 21:13:53 WARN Failed to register uploaded object key=46rkvf7rgr4y1kcfn6kzjbnj44js1rfl.ls error="server returned 404: 404 page not found\n"15872026/10/06 21:13:53 WARN Failed to register uploaded object key=nar/0r0934dxgpkgdyspfjjq2yahlslkqanylxpclvwzf3wrmkls0pzf.nar.zst error="server returned 404: 404 page not found\n"15882026/10/06 21:13:53 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15892026/10/06 21:13:53 WARN Failed to register uploaded object key=yh2h8xvwgj69d8sbhq3pp00rlv02g59c.ls error="server returned 404: 404 page not found\n"15902026/10/06 21:13:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15912026/10/06 21:13:53 INFO Signed narinfos id=1 count=315922026/10/06 21:13:53 INFO Uploading 3 narinfos1593--- PASS: TestClientFallsBackToClosures (0.87s)1594=== CONT TestPendingCleanupUsesOneCutoff15952026/10/06 21:13:53 WARN Failed to register uploaded object key=46rkvf7rgr4y1kcfn6kzjbnj44js1rfl.narinfo error="server returned 404: 404 page not found\n"15962026/10/06 21:13:53 WARN Failed to register uploaded object key=yh2h8xvwgj69d8sbhq3pp00rlv02g59c.narinfo error="server returned 404: 404 page not found\n"15972026/10/06 21:13:53 INFO Received complete push request method=POST path=/api/pushes/1/complete15982026/10/06 21:13:53 WARN Failed to register uploaded object key=vnrr8hlpspp62j87hzd42mcsfqgj8y39.narinfo error="server returned 404: 404 page not found\n"15992026/10/06 21:13:53 INFO Upload complete. (65ms)1600=== NAME TestClientPushesUseOnePush1601 client_pushes_test.go:97: Retrieved narinfo from S3:1602 StorePath: /build/TestClientPushesUseOnePush187046002/001/store/yh2h8xvwgj69d8sbhq3pp00rlv02g59c-shared-dep1603 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1604 Compression: zstd1605 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821606 NarSize: 1361607 References: 1608 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1609--- PASS: TestReadProxy404 (0.37s)1610=== CONT TestMultipartCleanup1611=== NAME TestClientPushesUseOnePush1612 client_pushes_test.go:97: Retrieved narinfo from S3:1613 StorePath: /build/TestClientPushesUseOnePush187046002/001/store/vnrr8hlpspp62j87hzd42mcsfqgj8y39-a1614 URL: nar/0r0934dxgpkgdyspfjjq2yahlslkqanylxpclvwzf3wrmkls0pzf.nar.zst1615 Compression: zstd1616 NarHash: sha256:0r0934dxgpkgdyspfjjq2yahlslkqanylxpclvwzf3wrmkls0pzf1617 NarSize: 2081618 References: /build/TestClientPushesUseOnePush187046002/001/store/yh2h8xvwgj69d8sbhq3pp00rlv02g59c-shared-dep1619 CA: text:sha256:1i6np8ix6g8dadcjamm7zjin11j2np06dwyhazzwiqyqc2adpz6y1620 client_pushes_test.go:97: Retrieved narinfo from S3:1621 StorePath: /build/TestClientPushesUseOnePush187046002/001/store/46rkvf7rgr4y1kcfn6kzjbnj44js1rfl-b1622 URL: nar/0r0934dxgpkgdyspfjjq2yahlslkqanylxpclvwzf3wrmkls0pzf.nar.zst1623 Compression: zstd1624 NarHash: sha256:0r0934dxgpkgdyspfjjq2yahlslkqanylxpclvwzf3wrmkls0pzf1625 NarSize: 2081626 References: /build/TestClientPushesUseOnePush187046002/001/store/yh2h8xvwgj69d8sbhq3pp00rlv02g59c-shared-dep1627 CA: text:sha256:1i6np8ix6g8dadcjamm7zjin11j2np06dwyhazzwiqyqc2adpz6y16282026/10/06 21:13:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34243/oidc1629--- PASS: TestClientPushesUseOnePush (0.83s)1630=== CONT TestOrphanedObjectsGC1631--- PASS: TestReadProxyConditionalGet (0.39s)1632=== CONT TestObjectStatsTrigger1633=== NAME TestClientCADerivations1634 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1635 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1636 error: binary cache 's3://bucket53?endpoint=http://localhost:34567®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3689564632/001/store'1637 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11638--- PASS: TestReadProxyNarStreaming (0.38s)1639--- PASS: TestClientCADerivations (1.04s)1640=== CONT TestServerTLSConfig1641=== RUN TestServerTLSConfig/no_client_CA1642=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1643=== PAUSE TestServerTLSConfig/no_client_CA1644=== RUN TestServerTLSConfig/missing_CA_file1645=== PAUSE TestServerTLSConfig/missing_CA_file1646=== RUN TestServerTLSConfig/not_a_PEM_file1647=== PAUSE TestServerTLSConfig/not_a_PEM_file1648=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1649--- PASS: TestReadProxyHead (0.36s)1650=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1651--- PASS: TestReadProxyContentNegotiation (0.39s)1652=== CONT TestGCEndsOnShutdown/before_the_run1653--- PASS: TestReadProxyInvalidPath (0.38s)1654=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1655--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.37s)1656=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1657--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.39s)1658=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16592026/10/06 21:13:53 INFO Received uploads request method=POST path=/1660=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16612026/10/06 21:13:53 INFO Received complete multipart upload request method=POST path=/1662=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16632026/10/06 21:13:53 INFO Received request for more parts method=POST path=/1664=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16652026/10/06 21:13:53 INFO Received uploads request method=POST path=/1666--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1667 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1668 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1669 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1670 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1671=== CONT TestIsValidUploadKey/narinfo1672=== CONT TestIsValidUploadKey/realisation_plus_in_output1673=== CONT TestIsValidUploadKey/unknown_type1674=== CONT TestIsValidUploadKey/empty_key1675=== CONT TestIsValidUploadKey/absolute1676=== CONT TestIsValidUploadKey/traversal_nar1677=== CONT TestIsValidUploadKey/traversal1678=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1679=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1680=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1681=== CONT TestIsValidUploadKey/index.html1682=== CONT TestIsValidUploadKey/nix-cache-info1683=== CONT TestIsValidUploadKey/build_log_home-manager_file1684=== CONT TestIsValidUploadKey/realisation1685=== CONT TestIsValidUploadKey/build_log_equals1686=== CONT TestIsValidUploadKey/build_log_question_mark1687=== CONT TestIsValidUploadKey/build_log_plus_in_name1688=== CONT TestIsValidUploadKey/nar_plain1689=== CONT TestIsValidUploadKey/build_log1690=== CONT TestIsValidUploadKey/listing1691=== CONT TestIsValidUploadKey/nar_xz1692=== CONT TestIsValidUploadKey/nar_zst1693--- PASS: TestIsValidUploadKey (0.14s)1694 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1695 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1696 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1697 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1698 --- PASS: TestIsValidUploadKey/absolute (0.00s)1699 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1700 --- PASS: TestIsValidUploadKey/traversal (0.00s)1701 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1702 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1703 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1704 --- PASS: TestIsValidUploadKey/index.html (0.00s)1705 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1706 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1707 --- PASS: TestIsValidUploadKey/realisation (0.00s)1708 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1709 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1710 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1711 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1712 --- PASS: TestIsValidUploadKey/build_log (0.00s)1713 --- PASS: TestIsValidUploadKey/listing (0.00s)1714 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1715 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1716=== CONT TestPendingClosureWriteTimeout/empty1717=== CONT TestPendingClosureWriteTimeout/670k_objects1718=== CONT TestPendingClosureWriteTimeout/400_objects1719=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1720--- PASS: TestPresentRefreshesOnlyStaleClosures (0.39s)1721=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17222026/10/06 21:13:53 INFO Received uploads request method=POST path=/17232026/10/06 21:13:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17242026/10/06 21:13:53 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZDUzODNmN2YtMjlhNC00N2ViLWIyNjMtM2FmNWEzODMzNzFmLmI4NzM5ZTU5LWQ4MjAtNGZhNi04ZjUyLTc0MTFhNDIxZjE2YngxNzkxMzIxMjMyODU1NzI4MjE5 error="Get \"http://127.0.0.1:1/bucket39/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"17252026/10/06 21:13:53 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZDUzODNmN2YtMjlhNC00N2ViLWIyNjMtM2FmNWEzODMzNzFmLjY5ZGZjNTI4LTJmMjctNDlhMy1iMjE1LWUzNWM2YzYwMWJkY3gxNzkxMzIxMjMyODQ3OTU3ODQ2 parts=1217262026/10/06 21:13:53 INFO Received cleanup request method=DELETE path=/api/pending_closures17272026/10/06 21:13:53 INFO Aborted multipart uploads count=1 kept=01728--- PASS: TestPresentReportsOnlyClosureRoots (0.38s)1729=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17302026/10/06 21:13:53 INFO Received request for more parts method=POST path=/1731--- PASS: TestRedundantMultipartUpload (1.71s)1732=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17332026/10/06 21:13:53 INFO Received complete multipart upload request method=POST path=/17342026/10/06 21:13:53 INFO Received uploads request method=POST path=/api/pending_closures1735=== CONT TestProxyWriteTimeout/narinfo1736=== CONT TestProxyWriteTimeout/10_GiB_nar1737=== CONT TestProxyWriteTimeout/unknown_size1738=== CONT TestProxyWriteTimeout/1_GiB_nar1739--- PASS: TestProxyWriteTimeout (0.00s)1740 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1741 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1742 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1743 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1744=== CONT TestPush_RejectsBadRequests/no_roots17452026/10/06 21:13:53 INFO Received push request method=POST path=/api/pushes1746=== CONT TestPush_RejectsBadRequests/bad_root17472026/10/06 21:13:53 INFO Received push request method=POST path=/api/pushes1748=== CONT TestPush_RejectsBadRequests/root_not_in_objects17492026/10/06 21:13:53 INFO Received push request method=POST path=/api/pushes1750=== CONT TestPush_RejectsBadRequests/no_objects17512026/10/06 21:13:53 INFO Received push request method=POST path=/api/pushes1752=== CONT TestClientErrorHandling/InvalidStorePath1753--- PASS: TestPush_RejectsBadRequests (0.78s)1754 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1755 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1756 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1757 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1758=== CONT TestClientErrorHandling/ServerNotAvailable17592026/10/06 21:13:53 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1760--- PASS: TestReadProxyNarinfo (0.47s)1761=== CONT TestClientErrorHandling/InvalidAuthToken17622026/10/06 21:13:53 INFO Received uploads request method=POST path=/api/pending_closures17632026/10/06 21:13:53 INFO Received uploads request method=POST path=/api/pending_closures17642026/10/06 21:13:53 INFO Received cleanup request method=DELETE path=/api/pending_closures17652026/10/06 21:13:53 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux17662026/10/06 21:13:53 WARN Refused reserved pin name=worker-x86_64-linux17672026/10/06 21:13:53 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux17682026/10/06 21:13:53 INFO Received create pin request method=POST path=/api/pins/my-app17692026/10/06 21:13:53 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1770--- PASS: TestCreatePin_ReservedPins (0.54s)1771=== CONT TestResolveDBConnectionString/flag_wins1772=== CONT TestResolveDBConnectionString/missing_file_is_an_error1773=== CONT TestResolveDBConnectionString/file_when_flag_empty1774=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1775=== CONT TestResolveDBConnectionString/nothing_configured1776=== CONT TestCacheConfigHandler/full_config,_no_issuer1777=== CONT TestCacheConfigHandler/no_signing_keys1778=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1779=== CONT TestCacheConfigHandler/no_cache_url_configured1780--- PASS: TestCacheConfigHandler (0.00s)1781 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1782 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1783 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1784 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1785=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token17862026/10/06 21:13:53 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/present1787--- PASS: TestResolveDBConnectionString (0.00s)1788 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1789 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1790 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1791 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1792 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1793=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected17942026/10/06 21:13:53 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]1795=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1796=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected17972026/10/06 21:13:53 WARN Authentication failed token_preview=eyJhbGciOi...deIa6ctRrg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1798=== CONT TestService_RequireScope_OIDC/builder_may_write1799--- PASS: TestService_AuthMiddleware_OIDC (0.58s)1800 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1801 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1802 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1803 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1804=== CONT TestService_RequireScope_OIDC/reader_may_read1805=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1806=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18072026/10/06 21:13:53 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]1808=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1809=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1810=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1811=== CONT TestService_RequireScope_OIDC/writer_implies_read1812=== CONT TestService_RequireScope_OIDC/reader_may_not_write1813=== CONT TestService_RequireScope_OIDC/static_token_may_write1814=== CONT TestService_RequireScope_OIDC/static_token_may_admin1815=== CONT TestService_RequireScope_OIDC/ops_may_admin1816=== CONT TestService_RequireScope_OIDC/ops_may_not_write1817=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1818=== CONT TestParseSingleRange/none1819=== CONT TestParseSingleRange/open-ended1820=== CONT TestParseSingleRange/start_far_past_EOF1821=== CONT TestParseSingleRange/malformed_both_empty1822=== CONT TestParseSingleRange/closed1823=== CONT TestParseSingleRange/start_past_EOF1824=== CONT TestParseSingleRange/malformed_end_before_start1825--- PASS: TestService_RequireScope_OIDC (0.57s)1826 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1827 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1828 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1829 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1830 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1831 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1832 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1833 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1834 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1835 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1836 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1837 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1838 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1839 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1840=== CONT TestParseSingleRange/single_byte1841=== CONT TestParseSingleRange/suffix1842=== CONT TestParseSingleRange/suffix_exceeds_size1843=== CONT TestParseSingleRange/end_clamped_to_size1844=== CONT TestParseSingleRange/multi-range_ignored1845=== CONT TestParseSingleRange/malformed_no_dash1846=== CONT TestParseSingleRange/unknown_unit1847--- PASS: TestParseSingleRange (0.00s)1848 --- PASS: TestParseSingleRange/none (0.00s)1849 --- PASS: TestParseSingleRange/open-ended (0.00s)1850 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1851 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1852 --- PASS: TestParseSingleRange/closed (0.00s)1853 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1854 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1855 --- PASS: TestParseSingleRange/single_byte (0.00s)1856 --- PASS: TestParseSingleRange/suffix (0.00s)1857 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1858 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1859 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1860 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1861 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1862=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale18632026/10/06 21:13:53 INFO Received cleanup request method=DELETE path=/api/pending_closures18642026/10/06 21:13:53 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=217.925931ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18652026/10/06 21:13:53 INFO lead: released remote=192.0.2.1:12341866--- PASS: TestLeadEndsOnShutdown (1.73s)1867=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh18682026/10/06 21:13:53 INFO Received uploads request method=POST path=/api/pending_closures18692026/10/06 21:13:53 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket82/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""18702026/10/06 21:13:53 INFO Aborted multipart uploads count=0 kept=118712026/10/06 21:13:53 INFO Received cleanup request method=DELETE path=/api/pending_closures1872--- PASS: TestObjectStatsTrigger (0.73s)18732026/10/06 21:13:53 INFO Aborted multipart uploads count=1 kept=01874=== CONT TestIsValidCachePath/narinfo1875=== CONT TestIsValidCachePath/index.html1876=== CONT TestIsValidCachePath/nix-cache-info1877=== CONT TestIsValidCachePath/realisation1878=== CONT TestIsValidCachePath/log1879=== CONT TestIsValidCachePath/ls1880=== CONT TestIsValidCachePath/nar_uncompressed1881=== CONT TestIsValidCachePath/nar_bz21882=== CONT TestIsValidCachePath/nar_xz1883=== CONT TestIsValidCachePath/nar_zst1884=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1885=== CONT TestIsValidCachePath/traversal_parent1886=== CONT TestIsValidCachePath/empty1887=== CONT TestIsValidCachePath/random_path1888=== CONT TestIsValidCachePath/invalid_char_u1889=== CONT TestIsValidCachePath/invalid_char_e1890=== CONT TestIsValidCachePath/traversal_in_middle1891=== CONT TestIsValidCachePath/wrong_extension1892=== CONT TestIsValidCachePath/short_hash1893=== CONT TestIsValidCachePath/leading_slash1894--- PASS: TestIsValidCachePath (0.00s)1895 --- PASS: TestIsValidCachePath/narinfo (0.00s)1896 --- PASS: TestIsValidCachePath/index.html (0.00s)1897 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1898 --- PASS: TestIsValidCachePath/realisation (0.00s)1899 --- PASS: TestIsValidCachePath/log (0.00s)1900 --- PASS: TestIsValidCachePath/ls (0.00s)1901 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1902 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1903 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1904 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1905 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1906 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1907 --- PASS: TestIsValidCachePath/empty (0.00s)1908 --- PASS: TestIsValidCachePath/random_path (0.00s)1909 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1910 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1911 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1912 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1913 --- PASS: TestIsValidCachePath/short_hash (0.00s)1914 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1915=== CONT TestServerTLSConfig/no_client_CA1916=== CONT TestServerTLSConfig/not_a_PEM_file1917=== CONT TestServerTLSConfig/missing_CA_file1918--- PASS: TestServerTLSConfig (0.00s)1919 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1920 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1921 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1922--- PASS: TestMultipartCleanup (0.75s)1923--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.71s)19242026/10/06 21:13:53 INFO Received uploads request method=POST path=/api/pending_closures19252026/10/06 21:13:53 INFO Aborted multipart uploads count=0 kept=019262026/10/06 21:13:53 WARN Force mode enabled - objects will be deleted immediately without grace period19272026/10/06 21:13:53 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=019282026/10/06 21:13:53 INFO Vacuumed table table=pending_closures19292026/10/06 21:13:53 INFO Vacuumed table table=pending_objects19302026/10/06 21:13:53 INFO Vacuumed table table=multipart_uploads19312026/10/06 21:13:53 INFO Vacuumed table table=closures19322026/10/06 21:13:53 INFO Received uploads request method=POST path=/api/pending_closures19332026/10/06 21:13:53 INFO Vacuumed table table=objects19342026/10/06 21:13:53 INFO Aborted multipart uploads count=0 kept=019352026/10/06 21:13:53 WARN Force mode enabled - objects will be deleted immediately without grace period19362026/10/06 21:13:53 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=019372026/10/06 21:13:53 INFO Vacuumed table table=pending_closures19382026/10/06 21:13:53 INFO Vacuumed table table=pending_objects19392026/10/06 21:13:53 INFO Vacuumed table table=multipart_uploads19402026/10/06 21:13:53 INFO Vacuumed table table=closures19412026/10/06 21:13:53 INFO Vacuumed table table=objects1942--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1943 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.78s)1944 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.71s)19452026/10/06 21:13:53 INFO Aborted multipart uploads count=0 kept=019462026/10/06 21:13:53 WARN Force mode enabled - objects will be deleted immediately without grace period1947=== NAME TestOrphanedObjectsGC1948 orphaned_objects_gc_test.go:290: GC Test Summary:1949 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1950 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1951 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1952 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1953 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1954--- PASS: TestOrphanedObjectsGC (0.86s)19552026/10/06 21:13:53 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:34567/bucket91/?delete=\": context canceled"19562026/10/06 21:13:53 INFO Received uploads request method=POST path=/api/pending_closures19572026/10/06 21:13:53 INFO lead: released remote=192.0.2.1:123419582026/10/06 21:13:54 INFO Aborted multipart uploads count=0 kept=019592026/10/06 21:13:54 WARN Force mode enabled - objects will be deleted immediately without grace period19602026/10/06 21:13:54 INFO lead: acquired remote=192.0.2.1:12341961--- PASS: TestGCEndsOnShutdown (0.00s)1962 --- PASS: TestGCEndsOnShutdown/before_the_run (0.68s)1963 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.68s)1964 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.71s)19652026/10/06 21:13:54 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=377.538254ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19662026/10/06 21:13:54 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19672026/10/06 21:13:54 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1968--- PASS: TestUploadHandlersRejectOversizedBody (0.39s)1969 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)1970 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)1971 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.82s)19722026/10/06 21:13:54 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=835.197742ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1973--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)1974 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.95s)1975 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.78s)19762026/10/06 21:13:54 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=019772026/10/06 21:13:54 INFO Received create pin request method=POST path=/api/pins/myapp19782026/10/06 21:13:54 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3195018900/001/store/rkiwfsxql3cg5jxzwmn5r3qbcgvzhkbz-pinned-file.txt narinfo_key=rkiwfsxql3cg5jxzwmn5r3qbcgvzhkbz.narinfo19792026/10/06 21:13:54 INFO Starting cleanup of old closures method=DELETE path=/api/closures19802026/10/06 21:13:54 INFO Garbage collection started19812026/10/06 21:13:54 INFO Aborted multipart uploads count=0 kept=019822026/10/06 21:13:54 WARN Force mode enabled - objects will be deleted immediately without grace period19832026/10/06 21:13:54 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=019842026/10/06 21:13:54 INFO Vacuumed table table=pending_closures19852026/10/06 21:13:54 INFO Vacuumed table table=pending_objects19862026/10/06 21:13:54 INFO Vacuumed table table=multipart_uploads19872026/10/06 21:13:54 INFO Vacuumed table table=closures19882026/10/06 21:13:54 INFO Vacuumed table table=objects1989--- PASS: TestPendingClosureWriteTimeout (0.00s)1990 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1991 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1992 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1993 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.43s)1994=== NAME TestOrphanedObjectsGCStressTest1995 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains19962026/10/06 21:13:54 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01997=== NAME TestClientIntegration1998 client_integration_test.go:323: Objects in database after GC:1999 client_integration_test.go:323: Successfully deleted all objects with GC --force2000=== NAME TestOrphanedObjectsGCStressTest2001 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion2002--- PASS: TestClientIntegration (2.80s)20032026/10/06 21:13:55 INFO lead: released remote=192.0.2.1:12342004--- PASS: TestLeadElectsOneAndHandsOver (2.94s)2005=== NAME TestOrphanedObjectsGCStressTest2006 orphaned_objects_gc_test.go:509: Stress test completed successfully:2007 orphaned_objects_gc_test.go:510: - Active objects preserved: 202008 orphaned_objects_gc_test.go:511: - Objects deleted: 2102009 orphaned_objects_gc_test.go:512: - Total GC'd: 2102010--- PASS: TestOrphanedObjectsGCStressTest (2.30s)20112026/10/06 21:13:55 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.475899471s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20122026/10/06 21:13:56 WARN Rate limiter enabled after throttle name=s3-test rate=520132026/10/06 21:13:56 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2014=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2015 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102016 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002017--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.13s)2018=== NAME TestPinProtectsFromGC2019 client_integration_test.go:840: Pin successfully protected closure from garbage collection2020--- PASS: TestPinProtectsFromGC (4.89s)20212026/10/06 21:13:56 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-config20222026/10/06 21:13:56 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=219.719607ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20232026/10/06 21:13:57 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=372.03668ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2024--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.53s)2025--- PASS: TestConnectWaitsForAPeerMigration (5.17s)20262026/10/06 21:13:57 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=862.197177ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20272026/10/06 21:13:58 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.620220638s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20282026/10/06 21:13:59 INFO Aborted multipart uploads count=1 kept=020292026/10/06 21:13:59 INFO Received cleanup request method=DELETE path=/api/pending_closures20302026/10/06 21:13:59 INFO Aborted multipart uploads count=1 kept=02031--- PASS: TestPendingCleanupUsesOneCutoff (6.54s)20322026/10/06 21:13:59 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"20332026/10/06 21:13:59 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-config20342026/10/06 21:14:00 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=207.039167ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20352026/10/06 21:14:00 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=411.926701ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20362026/10/06 21:14:00 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=837.266938ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20372026/10/06 21:14:01 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.464207273s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20382026/10/06 21:14:03 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_closures20392026/10/06 21:14:03 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=187.643996ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20402026/10/06 21:14:03 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=404.7891ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20412026/10/06 21:14:03 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=878.445814ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20422026/10/06 21:14:04 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.519498755s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2043--- PASS: TestClientErrorHandling (0.00s)2044 --- PASS: TestClientErrorHandling/InvalidStorePath (0.63s)2045 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.62s)2046 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.63s)2047PASS20482026-10-06 21:14:06.523 UTC [130] LOG: received smart shutdown request20492026-10-06 21:14:06.528 UTC [130] LOG: background worker "logical replication launcher" (PID 140) exited with exit code 120502026-10-06 21:14:06.542 UTC [135] LOG: shutting down20512026-10-06 21:14:06.543 UTC [135] LOG: checkpoint starting: shutdown immediate20522026-10-06 21:14:08.038 UTC [135] LOG: checkpoint complete: wrote 11408 buffers (69.6%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 28 recycled; write=0.347 s, sync=1.097 s, total=1.496 s; sync files=33016, longest=0.005 s, average=0.001 s; distance=455887 kB, estimate=455887 kB; lsn=0/1D499A40, redo lsn=0/1D499A4020532026-10-06 21:14:08.100 UTC [130] LOG: database system is shut down2054Running OIDC tests...2055=== RUN TestAudienceForIssuer2056=== PAUSE TestAudienceForIssuer2057=== RUN TestGlobMatch2058=== PAUSE TestGlobMatch2059=== RUN TestValidateToken_ValidToken2060=== PAUSE TestValidateToken_ValidToken2061=== RUN TestValidateToken_WrongAudience2062=== PAUSE TestValidateToken_WrongAudience2063=== RUN TestValidateToken_Expired2064=== PAUSE TestValidateToken_Expired2065=== RUN TestValidateToken_BoundClaimsMismatch2066=== PAUSE TestValidateToken_BoundClaimsMismatch2067=== RUN TestValidateToken_BoundSubjectMismatch2068=== PAUSE TestValidateToken_BoundSubjectMismatch2069=== RUN TestValidateToken_MultipleProviders2070=== PAUSE TestValidateToken_MultipleProviders2071=== RUN TestValidateToken_NoMatchingProvider2072=== PAUSE TestValidateToken_NoMatchingProvider2073=== RUN TestValidateToken_KubernetesServiceAccount2074=== PAUSE TestValidateToken_KubernetesServiceAccount2075=== RUN TestNewValidator_KubernetesRequiresCA2076=== PAUSE TestNewValidator_KubernetesRequiresCA2077=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2078=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2079=== RUN TestPins_ReservedForMatchingRule2080=== PAUSE TestPins_ReservedForMatchingRule2081=== RUN TestPins_TopLevelShorthand2082=== PAUSE TestPins_TopLevelShorthand2083=== RUN TestPins_ConfigValidation2084=== PAUSE TestPins_ConfigValidation2085=== RUN TestScopes_LegacyProviderDefaultsToWrite2086=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2087=== RUN TestScopes_Rules2088=== PAUSE TestScopes_Rules2089=== RUN TestScopes_ConfigValidation2090=== PAUSE TestScopes_ConfigValidation2091=== CONT TestAudienceForIssuer2092=== CONT TestScopes_ConfigValidation2093=== CONT TestValidateToken_MultipleProviders2094--- PASS: TestAudienceForIssuer (0.00s)2095=== CONT TestValidateToken_KubernetesServiceAccount2096=== CONT TestValidateToken_Expired2097=== CONT TestValidateToken_WrongAudience2098--- PASS: TestScopes_ConfigValidation (0.00s)2099=== CONT TestValidateToken_ValidToken2100=== CONT TestGlobMatch2101=== RUN TestGlobMatch/foo_foo2102=== PAUSE TestGlobMatch/foo_foo2103=== CONT TestPins_TopLevelShorthand2104=== CONT TestScopes_Rules2105=== CONT TestScopes_LegacyProviderDefaultsToWrite2106=== CONT TestPins_ConfigValidation2107=== CONT TestValidateToken_BoundSubjectMismatch2108=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2109=== CONT TestPins_ReservedForMatchingRule2110=== CONT TestValidateToken_NoMatchingProvider2111=== CONT TestNewValidator_KubernetesRequiresCA2112=== CONT TestValidateToken_BoundClaimsMismatch2113=== RUN TestGlobMatch/foo_bar2114=== PAUSE TestGlobMatch/foo_bar2115=== RUN TestGlobMatch/*_2116=== PAUSE TestGlobMatch/*_2117=== RUN TestGlobMatch/*_anything2118=== PAUSE TestGlobMatch/*_anything2119=== RUN TestGlobMatch/foo*_foo2120=== PAUSE TestGlobMatch/foo*_foo2121=== RUN TestGlobMatch/foo*_foobar2122=== PAUSE TestGlobMatch/foo*_foobar2123=== RUN TestGlobMatch/foo*_bar2124=== PAUSE TestGlobMatch/foo*_bar2125=== RUN TestGlobMatch/*bar_bar2126=== PAUSE TestGlobMatch/*bar_bar2127=== RUN TestGlobMatch/*bar_foobar2128=== PAUSE TestGlobMatch/*bar_foobar2129=== RUN TestGlobMatch/*bar_foo2130=== PAUSE TestGlobMatch/*bar_foo2131=== RUN TestGlobMatch/foo*bar_foobar2132=== PAUSE TestGlobMatch/foo*bar_foobar2133=== RUN TestGlobMatch/foo*bar_foo123bar2134=== PAUSE TestGlobMatch/foo*bar_foo123bar2135=== RUN TestGlobMatch/foo*bar_foobarbaz2136=== PAUSE TestGlobMatch/foo*bar_foobarbaz2137=== RUN TestGlobMatch/*/*_foo/bar2138=== PAUSE TestGlobMatch/*/*_foo/bar2139=== RUN TestGlobMatch/*/*_foo2140=== PAUSE TestGlobMatch/*/*_foo2141=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2142=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2143=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02144=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02145=== RUN TestGlobMatch/refs/*/main_refs/heads/main2146=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2147=== RUN TestGlobMatch/fo?_foo2148=== PAUSE TestGlobMatch/fo?_foo2149=== RUN TestGlobMatch/fo?_fo2150=== PAUSE TestGlobMatch/fo?_fo2151=== RUN TestGlobMatch/fo?_fooo2152=== PAUSE TestGlobMatch/fo?_fooo2153=== RUN TestGlobMatch/?oo_foo2154=== PAUSE TestGlobMatch/?oo_foo2155=== RUN TestGlobMatch/?oo_boo2156=== PAUSE TestGlobMatch/?oo_boo2157=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2158=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2159=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2160=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2161=== CONT TestGlobMatch/foo_foo2162=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2163=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2164=== CONT TestGlobMatch/?oo_boo2165=== CONT TestGlobMatch/?oo_foo2166=== CONT TestGlobMatch/fo?_fooo2167=== CONT TestGlobMatch/fo?_fo2168=== CONT TestGlobMatch/fo?_foo2169=== CONT TestGlobMatch/refs/*/main_refs/heads/main2170=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02171=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2172=== CONT TestGlobMatch/*/*_foo2173=== CONT TestGlobMatch/*/*_foo/bar2174=== CONT TestGlobMatch/foo*bar_foobarbaz2175=== CONT TestGlobMatch/foo*bar_foo123bar2176=== CONT TestGlobMatch/foo*bar_foobar2177=== CONT TestGlobMatch/*bar_foo2178=== CONT TestGlobMatch/*bar_foobar2179=== CONT TestGlobMatch/*bar_bar2180=== CONT TestGlobMatch/foo*_bar2181=== CONT TestGlobMatch/foo*_foobar2182=== CONT TestGlobMatch/foo*_foo2183=== CONT TestGlobMatch/*_anything2184=== CONT TestGlobMatch/*_2185=== CONT TestGlobMatch/foo_bar2186--- PASS: TestGlobMatch (0.00s)2187 --- PASS: TestGlobMatch/foo_foo (0.00s)2188 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2189 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2190 --- PASS: TestGlobMatch/?oo_boo (0.00s)2191 --- PASS: TestGlobMatch/?oo_foo (0.00s)2192 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2193 --- PASS: TestGlobMatch/fo?_fo (0.00s)2194 --- PASS: TestGlobMatch/fo?_foo (0.00s)2195 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2196 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2197 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2198 --- PASS: TestGlobMatch/*/*_foo (0.00s)2199 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2200 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2201 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2202 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2203 --- PASS: TestGlobMatch/*bar_foo (0.00s)2204 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2205 --- PASS: TestGlobMatch/*bar_bar (0.00s)2206 --- PASS: TestGlobMatch/foo*_bar (0.00s)2207 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2208 --- PASS: TestGlobMatch/foo*_foo (0.00s)2209 --- PASS: TestGlobMatch/*_anything (0.00s)2210 --- PASS: TestGlobMatch/*_ (0.00s)2211 --- PASS: TestGlobMatch/foo_bar (0.00s)2212--- PASS: TestPins_ConfigValidation (0.00s)22132026/10/06 21:14:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39947/oidc22142026/10/06 21:14:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40305/oidc2215--- PASS: TestPins_TopLevelShorthand (0.03s)22162026/10/06 21:14:11 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232217--- PASS: TestScopes_Rules (0.03s)22182026/10/06 21:14:11 http: TLS handshake error from 127.0.0.1:43464: remote error: tls: bad certificate2219--- PASS: TestNewValidator_KubernetesRequiresCA (0.03s)2220--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.03s)22212026/10/06 21:14:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45763/oidc2222--- PASS: TestValidateToken_ValidToken (0.05s)22232026/10/06 21:14:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36523/oidc2224--- PASS: TestValidateToken_Expired (0.05s)22252026/10/06 21:14:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45941/oidc2226--- PASS: TestValidateToken_WrongAudience (0.06s)22272026/10/06 21:14:11 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:3424522282026/10/06 21:14:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34517/oidc2229--- PASS: TestValidateToken_KubernetesServiceAccount (0.06s)2230--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.06s)22312026/10/06 21:14:11 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:38457/oidc2232--- PASS: TestValidateToken_NoMatchingProvider (0.07s)22332026/10/06 21:14:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34669/oidc2234--- PASS: TestValidateToken_BoundSubjectMismatch (0.08s)22352026/10/06 21:14:11 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:33445/oidc22362026/10/06 21:14:11 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:37673/oidc22372026/10/06 21:14:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46009/oidc2238--- PASS: TestValidateToken_MultipleProviders (0.10s)2239--- PASS: TestPins_ReservedForMatchingRule (0.10s)22402026/10/06 21:14:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33329/oidc2241--- PASS: TestValidateToken_BoundClaimsMismatch (0.11s)2242PASS2243Running hook tests...2244=== RUN TestSendPathsEmpty2245=== PAUSE TestSendPathsEmpty2246=== RUN TestQueueEnqueueAndFetch2247=== PAUSE TestQueueEnqueueAndFetch2248=== RUN TestQueueDeduplication2249=== PAUSE TestQueueDeduplication2250=== RUN TestQueueRemove2251=== PAUSE TestQueueRemove2252=== RUN TestQueueFetchBatchLimit2253=== PAUSE TestQueueFetchBatchLimit2254=== RUN TestQueueRetryMovesToBack2255=== PAUSE TestQueueRetryMovesToBack2256=== RUN TestQueueFetchRemoveLifecycle2257=== PAUSE TestQueueFetchRemoveLifecycle2258=== RUN TestQueueConcurrentWriters2259=== PAUSE TestQueueConcurrentWriters2260=== RUN TestQueueRemoveLargeClosure2261=== PAUSE TestQueueRemoveLargeClosure2262=== RUN TestServerClientIntegration2263=== PAUSE TestServerClientIntegration2264=== RUN TestServerQueueError2265=== PAUSE TestServerQueueError2266=== RUN TestGetListenerSocketActivation2267 server_test.go:210: === RUN TestGetListenerSocketActivation2268 --- PASS: TestGetListenerSocketActivation (0.00s)2269 PASS2270 2271--- PASS: TestGetListenerSocketActivation (0.01s)2272=== RUN TestDrainIsolatesPoisonPath2273=== PAUSE TestDrainIsolatesPoisonPath2274=== RUN TestRunNotBlockedByPoisonHead2275=== PAUSE TestRunNotBlockedByPoisonHead2276=== RUN TestDrainGivesUpWhenServerDown2277=== PAUSE TestDrainGivesUpWhenServerDown2278=== RUN TestFailedPathPrunedByLaterClosure2279=== PAUSE TestFailedPathPrunedByLaterClosure2280=== RUN TestWorkerUploadsAndRemoves2281=== PAUSE TestWorkerUploadsAndRemoves2282=== RUN TestWorkerSkipsGCdPaths2283=== PAUSE TestWorkerSkipsGCdPaths2284=== RUN TestWorkerPrunesClosureDeps2285=== PAUSE TestWorkerPrunesClosureDeps2286=== RUN TestDrainTimeout2287=== PAUSE TestDrainTimeout2288=== CONT TestSendPathsEmpty2289=== CONT TestWorkerUploadsAndRemoves2290=== CONT TestWorkerPrunesClosureDeps2291=== CONT TestServerQueueError2292=== CONT TestFailedPathPrunedByLaterClosure2293--- PASS: TestSendPathsEmpty (0.00s)2294=== CONT TestDrainGivesUpWhenServerDown2295=== CONT TestServerClientIntegration2296=== CONT TestRunNotBlockedByPoisonHead2297=== CONT TestQueueRemoveLargeClosure2298=== CONT TestQueueConcurrentWriters2299=== CONT TestQueueFetchRemoveLifecycle23002026/10/06 21:14:11 ERROR Failed to queue paths error="permission denied" count=12301=== CONT TestQueueRetryMovesToBack2302=== CONT TestQueueFetchBatchLimit2303--- PASS: TestServerQueueError (0.00s)2304=== CONT TestQueueRemove2305=== CONT TestQueueDeduplication2306=== CONT TestDrainIsolatesPoisonPath2307=== CONT TestQueueEnqueueAndFetch2308=== CONT TestWorkerSkipsGCdPaths2309=== CONT TestDrainTimeout2310--- PASS: TestServerClientIntegration (0.00s)23112026/10/06 21:14:11 INFO Uploading batch count=223122026/10/06 21:14:11 INFO Upload queue status pending=223132026/10/06 21:14:11 INFO Uploading batch count=223142026/10/06 21:14:11 INFO Upload queue status pending=223152026/10/06 21:14:11 INFO Uploading batch count=123162026/10/06 21:14:11 ERROR Upload failed error="upload failed" count=123172026/10/06 21:14:11 INFO Uploading batch count=223182026/10/06 21:14:11 INFO Uploading batch count=423192026/10/06 21:14:11 ERROR Upload failed error="upload failed" count=423202026/10/06 21:14:11 ERROR Upload failed error="upload failed" count=223212026/10/06 21:14:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3006138707/002/a23222026/10/06 21:14:11 INFO Upload queue status pending=323232026/10/06 21:14:11 INFO Uploading batch count=123242026/10/06 21:14:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath1042502789/002/bbb23252026/10/06 21:14:11 INFO Uploading batch count=123262026/10/06 21:14:11 ERROR Upload failed error="upload failed" count=12327--- PASS: TestQueueRetryMovesToBack (0.19s)2328--- PASS: TestQueueFetchBatchLimit (0.19s)23292026/10/06 21:14:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3006138707/002/b2330--- PASS: TestQueueRemove (0.19s)23312026/10/06 21:14:11 INFO Uploading batch count=123322026/10/06 21:14:11 INFO Upload queue status pending=22333--- PASS: TestQueueFetchRemoveLifecycle (0.20s)2334--- PASS: TestQueueDeduplication (0.20s)23352026/10/06 21:14:11 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths902916648/002/nonexistent2336--- PASS: TestQueueEnqueueAndFetch (0.20s)23372026/10/06 21:14:11 INFO Uploading batch count=223382026/10/06 21:14:11 ERROR Upload failed error="upload failed" count=223392026/10/06 21:14:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3006138707/002/c23402026/10/06 21:14:11 INFO Uploading batch count=123412026/10/06 21:14:11 INFO Uploading batch count=123422026/10/06 21:14:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3006138707/002/d23432026/10/06 21:14:11 INFO Uploading batch count=223442026/10/06 21:14:11 ERROR Upload failed error="upload failed" count=223452026/10/06 21:14:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3006138707/002/e23462026/10/06 21:14:11 INFO Uploading batch count=123472026/10/06 21:14:11 ERROR Upload failed error="upload failed" count=123482026/10/06 21:14:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3006138707/002/f2349--- PASS: TestWorkerUploadsAndRemoves (0.21s)23502026/10/06 21:14:11 ERROR Drain finished with paths left in queue remaining=1023512026/10/06 21:14:11 ERROR Upload failed error="context deadline exceeded" count=223522026/10/06 21:14:11 ERROR Drain finished with paths left in queue remaining=423532026/10/06 21:14:11 INFO Uploading batch count=123542026/10/06 21:14:11 ERROR Upload failed error="upload failed" count=12355--- PASS: TestWorkerPrunesClosureDeps (0.22s)2356--- PASS: TestWorkerSkipsGCdPaths (0.21s)2357--- PASS: TestFailedPathPrunedByLaterClosure (0.22s)23582026/10/06 21:14:11 INFO Uploading batch count=123592026/10/06 21:14:11 ERROR Upload failed error="upload failed" count=123602026/10/06 21:14:11 ERROR Drain finished with paths left in queue remaining=12361--- PASS: TestDrainTimeout (0.22s)2362--- PASS: TestDrainGivesUpWhenServerDown (0.22s)2363--- PASS: TestDrainIsolatesPoisonPath (0.22s)2364--- PASS: TestQueueRemoveLargeClosure (0.26s)2365--- PASS: TestQueueConcurrentWriters (0.79s)23662026/10/06 21:14:12 INFO Uploading batch count=123672026/10/06 21:14:12 INFO Uploading batch count=123682026/10/06 21:14:12 INFO Uploading batch count=123692026/10/06 21:14:12 ERROR Upload failed error="upload failed" count=123702026/10/06 21:14:12 INFO Uploading batch count=123712026/10/06 21:14:12 ERROR Upload failed error="upload failed" count=123722026/10/06 21:14:12 INFO Uploading batch count=123732026/10/06 21:14:12 ERROR Upload failed error="upload failed" count=123742026/10/06 21:14:12 INFO Uploading batch count=123752026/10/06 21:14:12 ERROR Upload failed error="upload failed" count=123762026/10/06 21:14:12 ERROR Drain finished with paths left in queue remaining=12377--- PASS: TestRunNotBlockedByPoisonHead (1.23s)2378PASS2379Running signing tests...2380=== RUN TestExternalSigner2381=== PAUSE TestExternalSigner2382=== RUN TestExternalSignerWrongPublicKey2383=== PAUSE TestExternalSignerWrongPublicKey2384=== RUN TestExternalSignerErrors2385=== PAUSE TestExternalSignerErrors2386=== RUN TestExternalSignerRestartsAfterCrash2387=== PAUSE TestExternalSignerRestartsAfterCrash2388=== RUN TestExternalSignerProgramErrorKeepsProcess2389=== PAUSE TestExternalSignerProgramErrorKeepsProcess2390=== RUN TestExternalSignerClose2391=== PAUSE TestExternalSignerClose2392=== RUN TestExternalSignerRejectsInvalidPublicKey2393=== PAUSE TestExternalSignerRejectsInvalidPublicKey2394=== RUN TestExternalSignerCancellation2395=== PAUSE TestExternalSignerCancellation2396=== RUN TestGenerateFingerprint2397=== PAUSE TestGenerateFingerprint2398=== RUN TestParseSigningKey2399=== PAUSE TestParseSigningKey2400=== RUN TestSign2401=== PAUSE TestSign2402=== RUN TestSignBatch2403=== PAUSE TestSignBatch2404=== RUN TestNilKeyPublicKey2405=== PAUSE TestNilKeyPublicKey2406=== RUN TestSignErrors2407=== PAUSE TestSignErrors2408=== CONT TestExternalSigner2409=== CONT TestExternalSignerCancellation2410=== CONT TestExternalSignerProgramErrorKeepsProcess2411=== CONT TestSignErrors2412=== CONT TestNilKeyPublicKey2413--- PASS: TestNilKeyPublicKey (0.00s)2414=== CONT TestExternalSignerRejectsInvalidPublicKey2415=== CONT TestExternalSignerClose2416=== RUN TestExternalSignerRejectsInvalidPublicKey/#002417=== CONT TestParseSigningKey2418=== CONT TestSign2419=== CONT TestGenerateFingerprint2420=== CONT TestExternalSignerErrors2421=== CONT TestExternalSignerRestartsAfterCrash2422=== CONT TestExternalSignerWrongPublicKey2423=== CONT TestSignBatch2424=== RUN TestParseSigningKey/valid_32-byte_key2425=== PAUSE TestParseSigningKey/valid_32-byte_key2426=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002427=== RUN TestGenerateFingerprint/basic_with_references2428=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2429=== PAUSE TestGenerateFingerprint/basic_with_references2430=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2431=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2432=== RUN TestSignErrors/nil_key2433=== RUN TestParseSigningKey/no_colon2434=== PAUSE TestSignErrors/nil_key2435=== RUN TestSignErrors/nil_narinfo2436=== PAUSE TestSignErrors/nil_narinfo2437=== RUN TestSignErrors/invalid_narinfo2438=== PAUSE TestSignErrors/invalid_narinfo2439=== RUN TestSignErrors/canceled2440=== PAUSE TestSignErrors/canceled2441=== CONT TestSignErrors/nil_key2442=== RUN TestGenerateFingerprint/no_references2443=== PAUSE TestGenerateFingerprint/no_references2444--- PASS: TestSign (0.00s)2445--- PASS: TestSignBatch (0.00s)2446=== RUN TestExternalSignerErrors/wrong_signatures_shape2447=== PAUSE TestParseSigningKey/no_colon2448=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2449=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2450=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2451=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2452=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2453=== CONT TestSignErrors/invalid_narinfo2454=== CONT TestSignErrors/canceled2455=== CONT TestSignErrors/nil_narinfo2456--- PASS: TestSignErrors (0.00s)2457 --- PASS: TestSignErrors/nil_key (0.00s)2458 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2459 --- PASS: TestSignErrors/canceled (0.00s)2460 --- PASS: TestSignErrors/nil_narinfo (0.00s)2461=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2462=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2463=== RUN TestParseSigningKey/empty_name2464=== RUN TestExternalSignerErrors/wrong_shape2465=== PAUSE TestExternalSignerErrors/wrong_shape2466=== RUN TestExternalSignerErrors/wrong_signature_length2467=== PAUSE TestExternalSignerErrors/wrong_signature_length2468=== RUN TestExternalSignerErrors/program_error2469=== PAUSE TestExternalSignerErrors/program_error2470=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2471=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2472=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2473=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2474=== PAUSE TestParseSigningKey/empty_name2475=== RUN TestExternalSignerErrors/exit_on_request2476=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2477=== CONT TestExternalSignerRejectsInvalidPublicKey/#002478=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2479=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2480=== RUN TestParseSigningKey/invalid_base642481=== PAUSE TestParseSigningKey/invalid_base642482=== PAUSE TestExternalSignerErrors/exit_on_request2483--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2484=== RUN TestGenerateFingerprint/invalid_nar_hash_length2485=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2486=== RUN TestGenerateFingerprint/invalid_store_path_prefix2487=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2488=== RUN TestGenerateFingerprint/invalid_reference_prefix2489=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2490=== CONT TestGenerateFingerprint/basic_with_references2491=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2492=== CONT TestGenerateFingerprint/invalid_nar_hash_length2493=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2494=== RUN TestParseSigningKey/wrong_length2495=== PAUSE TestParseSigningKey/wrong_length2496=== CONT TestParseSigningKey/valid_32-byte_key2497=== CONT TestParseSigningKey/invalid_base642498=== RUN TestExternalSignerErrors/null2499=== PAUSE TestExternalSignerErrors/null2500=== CONT TestGenerateFingerprint/invalid_reference_prefix2501=== CONT TestGenerateFingerprint/invalid_store_path_prefix2502=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2503--- PASS: TestExternalSignerClose (0.00s)2504=== CONT TestGenerateFingerprint/no_references2505--- PASS: TestExternalSignerWrongPublicKey (0.00s)2506=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2507=== CONT TestParseSigningKey/empty_name2508=== CONT TestParseSigningKey/wrong_length2509=== CONT TestParseSigningKey/no_colon2510=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2511=== RUN TestExternalSignerErrors/too_few_signatures2512=== PAUSE TestExternalSignerErrors/too_few_signatures2513=== RUN TestExternalSignerErrors/unrequested_key2514=== PAUSE TestExternalSignerErrors/unrequested_key2515=== RUN TestExternalSignerErrors/invalid_JSON2516=== PAUSE TestExternalSignerErrors/invalid_JSON2517=== RUN TestExternalSignerErrors/missing_signatures2518=== PAUSE TestExternalSignerErrors/missing_signatures2519=== RUN TestExternalSignerErrors/missing_signature_name2520=== PAUSE TestExternalSignerErrors/missing_signature_name2521=== RUN TestExternalSignerErrors/wrong_signature_name2522=== PAUSE TestExternalSignerErrors/wrong_signature_name2523=== RUN TestExternalSignerErrors/invalid_signature_base642524=== PAUSE TestExternalSignerErrors/invalid_signature_base642525=== RUN TestExternalSignerErrors/exit_at_startup2526=== PAUSE TestExternalSignerErrors/exit_at_startup2527=== RUN TestExternalSignerErrors/wrong_id2528=== PAUSE TestExternalSignerErrors/wrong_id2529=== RUN TestExternalSignerErrors/null_signatures2530=== PAUSE TestExternalSignerErrors/null_signatures2531--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2532 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2533 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2534 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2535 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2536 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2537=== CONT TestExternalSignerErrors/wrong_signatures_shape2538=== CONT TestExternalSignerErrors/null_signatures2539=== CONT TestExternalSignerErrors/wrong_id2540=== CONT TestExternalSignerErrors/exit_at_startup2541=== CONT TestExternalSignerErrors/invalid_signature_base642542=== CONT TestExternalSignerErrors/wrong_signature_name2543=== CONT TestExternalSignerErrors/missing_signature_name2544=== CONT TestExternalSignerErrors/missing_signatures2545=== CONT TestExternalSignerErrors/invalid_JSON2546=== CONT TestExternalSignerErrors/unrequested_key2547=== CONT TestExternalSignerErrors/too_few_signatures2548=== CONT TestExternalSignerErrors/null2549=== CONT TestExternalSignerErrors/exit_on_request2550=== CONT TestExternalSignerErrors/wrong_shape2551=== CONT TestExternalSignerErrors/wrong_signature_length2552=== CONT TestExternalSignerErrors/program_error2553--- PASS: TestGenerateFingerprint (0.00s)2554 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2555 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2556 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2557 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2558 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2559 --- PASS: TestGenerateFingerprint/no_references (0.00s)2560 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2561--- PASS: TestParseSigningKey (0.00s)2562 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2563 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2564 --- PASS: TestParseSigningKey/empty_name (0.00s)2565 --- PASS: TestParseSigningKey/wrong_length (0.00s)2566 --- PASS: TestParseSigningKey/no_colon (0.00s)2567 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2568--- PASS: TestExternalSigner (0.01s)2569--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2570--- PASS: TestExternalSignerErrors (0.00s)2571 --- PASS: TestExternalSignerErrors/wrong_id (0.00s)2572 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.00s)2573 --- PASS: TestExternalSignerErrors/null_signatures (0.00s)2574 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2575 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2576 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2577 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2578 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2579 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2580 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2581 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2582 --- PASS: TestExternalSignerErrors/program_error (0.01s)2583 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2584 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2585 --- PASS: TestExternalSignerErrors/null (0.01s)2586 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2587--- PASS: TestExternalSignerCancellation (0.02s)2588PASS2589Running OpenBao signer tests...2590=== RUN TestSign2591=== PAUSE TestSign2592=== RUN TestSignErrors2593=== PAUSE TestSignErrors2594=== RUN TestServe2595=== PAUSE TestServe2596=== RUN TestServeRejectsGarbage2597=== PAUSE TestServeRejectsGarbage2598=== CONT TestSign2599=== CONT TestSignErrors2600=== CONT TestServeRejectsGarbage2601=== RUN TestSignErrors/no_prefix2602=== PAUSE TestSignErrors/no_prefix2603=== CONT TestServe2604--- PASS: TestServeRejectsGarbage (0.00s)2605=== RUN TestSignErrors/invalid_base642606=== PAUSE TestSignErrors/invalid_base642607=== RUN TestSignErrors/http_error2608=== PAUSE TestSignErrors/http_error2609=== RUN TestSignErrors/invalid_json2610=== PAUSE TestSignErrors/invalid_json2611=== CONT TestSignErrors/no_prefix2612=== CONT TestSignErrors/http_error2613--- PASS: TestServe (0.00s)2614=== CONT TestSignErrors/invalid_json2615=== CONT TestSignErrors/invalid_base642616--- PASS: TestSignErrors (0.00s)2617 --- PASS: TestSignErrors/no_prefix (0.00s)2618 --- PASS: TestSignErrors/invalid_base64 (0.00s)2619 --- PASS: TestSignErrors/http_error (0.00s)2620 --- PASS: TestSignErrors/invalid_json (0.00s)2621--- PASS: TestSign (0.00s)2622PASS