niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #391
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica8=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica9=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun10=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun11=== RUN TestCaseHackSuffix12=== PAUSE TestCaseHackSuffix13=== RUN TestFilterOversizedClosures14=== PAUSE TestFilterOversizedClosures15=== RUN TestUploadMultipart_PartsInParallel16=== PAUSE TestUploadMultipart_PartsInParallel17=== RUN TestPartSizeForNAR18=== PAUSE TestPartSizeForNAR19=== RUN TestUploadMultipart_SupersededByPeer20=== PAUSE TestUploadMultipart_SupersededByPeer21=== RUN TestDumpPathCaseHackMatchesNix22--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestDumpPathMatchesNix26=== PAUSE TestDumpPathMatchesNix27=== RUN TestDumpPathSingleFile28=== PAUSE TestDumpPathSingleFile29=== RUN TestDumpPathWriterError30=== PAUSE TestDumpPathWriterError31=== RUN TestEncodeNixBase3232=== PAUSE TestEncodeNixBase3233=== RUN TestEncodeNixBase32WithRealHash34=== PAUSE TestEncodeNixBase32WithRealHash35=== RUN TestConvertHashToNix3236=== PAUSE TestConvertHashToNix3237=== RUN TestGetStorePathHash38=== PAUSE TestGetStorePathHash39=== RUN TestPathInfoHashCompatibility40=== PAUSE TestPathInfoHashCompatibility41=== RUN TestParsePathInfoJSON42=== PAUSE TestParsePathInfoJSON43=== RUN TestParsePathInfoJSONMultiplePaths44=== PAUSE TestParsePathInfoJSONMultiplePaths45=== RUN TestPathInfoCACompatibility46=== PAUSE TestPathInfoCACompatibility47=== RUN TestRateLimiterFeedback48=== PAUSE TestRateLimiterFeedback49=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess51=== RUN TestResolveStorePath52=== PAUSE TestResolveStorePath53=== RUN TestDoWithRetry_BodyReplayedViaGetBody54=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody55=== RUN TestShellSplit56=== PAUSE TestShellSplit57=== RUN TestShellSplitErrors58=== PAUSE TestShellSplitErrors59=== RUN TestStreamPushReportsEveryPath60=== PAUSE TestStreamPushReportsEveryPath61=== RUN TestStreamPushBatchesUnderLoad62=== PAUSE TestStreamPushBatchesUnderLoad63=== RUN TestStreamPushIsolatesFailures64=== PAUSE TestStreamPushIsolatesFailures65=== RUN TestStreamPushGivesUpOnDeadServer66=== PAUSE TestStreamPushGivesUpOnDeadServer67=== RUN TestStreamPushRequestLine68=== PAUSE TestStreamPushRequestLine69=== RUN TestStreamPushReportsSignatures70=== PAUSE TestStreamPushReportsSignatures71=== RUN TestClientSignaturesByStorePath72=== PAUSE TestClientSignaturesByStorePath73=== RUN TestSetClientTLS74=== PAUSE TestSetClientTLS75=== RUN TestSetClientTLSDoesNotMutateDefaultTransport76=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport77=== RUN TestSetClientTLSErrors78=== PAUSE TestSetClientTLSErrors79=== RUN TestStaticToken80=== PAUSE TestStaticToken81=== RUN TestFileTokenReadsAndCaches82=== PAUSE TestFileTokenReadsAndCaches83=== RUN TestFileTokenMissing84=== PAUSE TestFileTokenMissing85=== RUN TestFileTokenEmpty86=== PAUSE TestFileTokenEmpty87=== RUN TestScriptTokenNoExpiryRerunsEveryCall88=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall89=== RUN TestScriptTokenCachesUntilRefresh90=== PAUSE TestScriptTokenCachesUntilRefresh91=== RUN TestScriptTokenEmptyToken92=== PAUSE TestScriptTokenEmptyToken93=== RUN TestScriptTokenBadJSON94=== PAUSE TestScriptTokenBadJSON95=== RUN TestScriptTokenScriptFails96=== PAUSE TestScriptTokenScriptFails97=== RUN TestScriptTokenEmptyCommand98=== PAUSE TestScriptTokenEmptyCommand99=== CONT TestScriptTokenEmptyCommand100--- PASS: TestScriptTokenEmptyCommand (0.00s)101=== CONT TestDoServerRequestAttachesToken102=== CONT TestResolveStorePath103=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess104=== CONT TestRateLimiterFeedback105=== RUN TestRateLimiterFeedback/429_enables_limiter106=== PAUSE TestRateLimiterFeedback/429_enables_limiter107=== RUN TestRateLimiterFeedback/503_enables_limiter108=== PAUSE TestRateLimiterFeedback/503_enables_limiter109=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter110=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter111=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter112=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter113=== CONT TestStreamPushIsolatesFailures114=== CONT TestDoWithRetry_BodyReplayedViaGetBody1152026/10/07 06:12:04 WARN Rate limiter enabled after throttle name=server-test rate=5116=== CONT TestScriptTokenScriptFails1172026/10/07 06:12:04 ERROR Upload failed error="bad path" count=3118=== CONT TestPathInfoCACompatibility119=== RUN TestPathInfoCACompatibility/null_ca_field120=== CONT TestDumpPathMatchesNix121=== PAUSE TestPathInfoCACompatibility/null_ca_field122=== CONT TestStaticToken123=== RUN TestPathInfoCACompatibility/old_string_format_-_text124=== CONT TestStreamPushBatchesUnderLoad125--- PASS: TestResolveStorePath (0.00s)126=== CONT TestUploadMultipart_SupersededByPeer127=== RUN TestUploadMultipart_SupersededByPeer/exists128=== CONT TestScriptTokenEmptyToken129=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text130=== CONT TestPartSizeForNAR131=== RUN TestPartSizeForNAR/zero_stays_at_minimum132=== CONT TestUploadMultipart_PartsInParallel133=== CONT TestScriptTokenCachesUntilRefresh134=== CONT TestFilterOversizedClosures135=== CONT TestScriptTokenNoExpiryRerunsEveryCall136=== CONT TestCaseHackSuffix137=== RUN TestFilterOversizedClosures/no_limit_keeps_everything138=== CONT TestStreamPushReportsSignatures139=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun140=== CONT TestStreamPushRequestLine141=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica142=== CONT TestStreamPushGivesUpOnDeadServer143=== CONT TestDumpPathSingleFile144=== CONT TestRegisterUploadedObjectReusesConnections145=== CONT TestScriptTokenBadJSON146--- PASS: TestStaticToken (0.00s)147--- PASS: TestStreamPushIsolatesFailures (0.00s)148--- PASS: TestScriptTokenScriptFails (0.00s)149=== PAUSE TestUploadMultipart_SupersededByPeer/exists1502026/10/07 06:12:04 ERROR Upload failed error=boom count=11512026/10/07 06:12:04 ERROR Upload failed error=boom count=11522026/10/07 06:12:04 ERROR Upload failed error="connection refused" count=201532026/10/07 06:12:04 ERROR Server seems unavailable, giving up on batch untried=17154=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive155=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum156=== CONT TestFileTokenEmpty157=== RUN TestUploadMultipart_SupersededByPeer/missing158=== CONT TestFileTokenMissing159=== CONT TestFileTokenReadsAndCaches1602026/10/07 06:12:04 INFO Garbage collection started1612026/10/07 06:12:04 INFO Garbage collection started162=== CONT TestParsePathInfoJSON163=== RUN TestParsePathInfoJSON/Nix_format164=== PAUSE TestParsePathInfoJSON/Nix_format165=== RUN TestParsePathInfoJSON/Lix_format166=== PAUSE TestParsePathInfoJSON/Lix_format167=== RUN TestParsePathInfoJSON/empty_input168=== PAUSE TestParsePathInfoJSON/empty_input169=== RUN TestParsePathInfoJSON/whitespace_only170=== PAUSE TestParsePathInfoJSON/whitespace_only171=== RUN TestParsePathInfoJSON/invalid_JSON172=== PAUSE TestParsePathInfoJSON/invalid_JSON173=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive174=== RUN TestPathInfoCACompatibility/new_structured_format_-_text175=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text176=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method177=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method178=== RUN TestPartSizeForNAR/small_stays_at_minimum179=== PAUSE TestPartSizeForNAR/small_stays_at_minimum180=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum181=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum182=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts183=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts184=== RUN TestPartSizeForNAR/1_TiB185=== PAUSE TestPartSizeForNAR/1_TiB186=== RUN TestPartSizeForNAR/5_TiB_S3_max_object187=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object188=== RUN TestPartSizeForNAR/capped_at_5_GiB189=== PAUSE TestPartSizeForNAR/capped_at_5_GiB190=== CONT TestEncodeNixBase32WithRealHash1912026/10/07 06:12:04 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=0192=== CONT TestGetStorePathHash193=== RUN TestGetStorePathHash/valid_store_path194=== PAUSE TestGetStorePathHash/valid_store_path195=== RUN TestGetStorePathHash/basename_without_hyphen_should_error196=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error197=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error198=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error199=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error200=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error201=== CONT TestSetClientTLS202=== CONT TestConvertHashToNix32203=== RUN TestConvertHashToNix32/SRI_format_to_Nix32204=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32205=== RUN TestConvertHashToNix32/already_Nix32_format206=== PAUSE TestConvertHashToNix32/already_Nix32_format207=== RUN TestConvertHashToNix32/invalid_format208=== PAUSE TestConvertHashToNix32/invalid_format209=== CONT TestPathInfoHashCompatibility210=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)211=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)212=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon213=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon214=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI215=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI216=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512217=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512218=== PAUSE TestUploadMultipart_SupersededByPeer/missing219=== CONT TestDumpPathWriterError220=== CONT TestClientSignaturesByStorePath221=== CONT TestRateLimiterFeedback/429_enables_limiter2222026/10/07 06:12:04 WARN Rate limiter enabled after throttle name=server-test rate=5223=== CONT TestShellSplit2242026/10/07 06:12:04 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:35423225=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter226--- PASS: TestStreamPushReportsSignatures (0.00s)2272026/10/07 06:12:04 WARN Garbage collection finished on another replica. Its statistics are not available here228--- PASS: TestDoServerRequestAttachesToken (0.03s)229=== CONT TestStreamPushReportsEveryPath230=== CONT TestParsePathInfoJSONMultiplePaths231=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths232=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths233=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths234=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths235=== CONT TestParsePathInfoJSON/Nix_format2362026/10/07 06:12:04 WARN Rate limiter backed off name=server-test rate=52372026/10/07 06:12:04 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:35423238=== CONT TestPathInfoCACompatibility/null_ca_field239=== CONT TestPartSizeForNAR/zero_stays_at_minimum240=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method241=== CONT TestGetStorePathHash/valid_store_path242=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error243=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error244=== CONT TestGetStorePathHash/basename_without_hyphen_should_error245=== CONT TestParsePathInfoJSON/whitespace_only246=== CONT TestParsePathInfoJSON/empty_input247=== CONT TestParsePathInfoJSON/Lix_format248=== CONT TestConvertHashToNix32/SRI_format_to_Nix32249=== CONT TestConvertHashToNix32/already_Nix32_format250=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)251=== CONT TestUploadMultipart_SupersededByPeer/exists252=== CONT TestParsePathInfoJSON/invalid_JSON253=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI254=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512255=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon256=== CONT TestUploadMultipart_SupersededByPeer/missing2572026/10/07 06:12:04 WARN Rate limiter enabled after throttle name=server-test rate=5258=== RUN TestSetClientTLS/rejects_connection_without_client_cert2592026/10/07 06:12:04 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:44319260=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert261=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA262=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA263=== RUN TestSetClientTLS/preserves_debug_logging_transport264=== PAUSE TestSetClientTLS/preserves_debug_logging_transport265=== CONT TestSetClientTLSErrors2662026/10/07 06:12:04 WARN Rate limiter backed off name=server-test rate=5267=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths268=== CONT TestConvertHashToNix32/invalid_format269=== CONT TestSetClientTLS/rejects_connection_without_client_cert270=== CONT TestPathInfoCACompatibility/new_structured_format_-_text271=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive272=== CONT TestPathInfoCACompatibility/old_string_format_-_text273=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum274=== CONT TestPartSizeForNAR/capped_at_5_GiB275=== CONT TestPartSizeForNAR/5_TiB_S3_max_object276=== CONT TestPartSizeForNAR/1_TiB277=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts278=== CONT TestPartSizeForNAR/small_stays_at_minimum279=== CONT TestEncodeNixBase32280=== RUN TestEncodeNixBase32/test_string_hash281=== PAUSE TestEncodeNixBase32/test_string_hash282=== RUN TestEncodeNixBase32/empty_input283=== PAUSE TestEncodeNixBase32/empty_input284=== CONT TestEncodeNixBase32/test_string_hash285--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)286--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)287--- PASS: TestFileTokenMissing (0.00s)288--- PASS: TestFileTokenReadsAndCaches (0.00s)289--- PASS: TestFileTokenEmpty (0.00s)290--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)291--- PASS: TestEncodeNixBase32WithRealHash (0.00s)292--- PASS: TestScriptTokenBadJSON (0.00s)293--- PASS: TestClientSignaturesByStorePath (0.00s)294--- PASS: TestShellSplit (0.00s)295--- PASS: TestStreamPushReportsEveryPath (0.00s)296--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)297=== CONT TestEncodeNixBase32/empty_input298=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter299--- PASS: TestGetStorePathHash (0.00s)300 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)301 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)302 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)303 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)304=== CONT TestShellSplitErrors305=== CONT TestRateLimiterFeedback/503_enables_limiter306=== RUN TestSetClientTLSErrors/missing_cert_file307=== PAUSE TestSetClientTLSErrors/missing_cert_file308=== RUN TestSetClientTLSErrors/missing_key_file309=== PAUSE TestSetClientTLSErrors/missing_key_file310=== RUN TestSetClientTLSErrors/missing_ca_file311=== PAUSE TestSetClientTLSErrors/missing_ca_file312=== RUN TestSetClientTLSErrors/invalid_ca_file313=== PAUSE TestSetClientTLSErrors/invalid_ca_file314=== CONT TestSetClientTLSErrors/missing_cert_file315=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths316=== CONT TestSetClientTLS/preserves_debug_logging_transport317=== CONT TestSetClientTLSDoesNotMutateDefaultTransport318=== CONT TestSetClientTLSErrors/missing_ca_file319=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything320=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped321=== CONT TestSetClientTLSErrors/invalid_ca_file322=== CONT TestSetClientTLSErrors/missing_key_file323=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA324=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped325=== RUN TestFilterOversizedClosures/all_closures_skipped326=== PAUSE TestFilterOversizedClosures/all_closures_skipped327=== CONT TestFilterOversizedClosures/no_limit_keeps_everything328=== CONT TestFilterOversizedClosures/all_closures_skipped3292026/10/07 06:12:04 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=50330=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3312026/10/07 06:12:04 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=2000332--- PASS: TestPathInfoHashCompatibility (0.00s)333 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)334 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)335 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)336 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)337--- PASS: TestParsePathInfoJSON (0.00s)338 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)339 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)340 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)341 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)342 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)343--- PASS: TestPathInfoCACompatibility (0.03s)344 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)345 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)346 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)347 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)348 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)349--- PASS: TestPartSizeForNAR (0.02s)350 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)351 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)352 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)353 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)354 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)355 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)356 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)357--- PASS: TestEncodeNixBase32 (0.00s)358 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)359 --- PASS: TestEncodeNixBase32/empty_input (0.00s)360--- PASS: TestShellSplitErrors (0.00s)361--- PASS: TestConvertHashToNix32 (0.00s)362 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)363 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)364 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)365--- PASS: TestScriptTokenEmptyToken (0.03s)366--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)367--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)368--- PASS: TestFilterOversizedClosures (0.03s)369 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)370 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)371 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)372--- PASS: TestSetClientTLSErrors (0.00s)373 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)374 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)375 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)376 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)377--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)378 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)379 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)380--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)3812026/10/07 06:12:04 WARN Rate limiter enabled after throttle name=server-test rate=53822026/10/07 06:12:04 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:394673832026/10/07 06:12:04 WARN Rate limiter backed off name=server-test rate=5384--- PASS: TestRateLimiterFeedback (0.00s)385 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)386 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)387 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)388 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)389--- PASS: TestUploadMultipart_SupersededByPeer (0.03s)390 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)391 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)3922026/10/07 06:12:04 http: TLS handshake error from 127.0.0.1:45196: remote error: tls: bad certificate393--- PASS: TestSetClientTLS (0.00s)394 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)395 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)396 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)397--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)398--- PASS: TestStreamPushRequestLine (0.03s)399--- PASS: TestDumpPathSingleFile (0.03s)400--- PASS: TestDumpPathWriterError (0.03s)401--- PASS: TestCaseHackSuffix (0.06s)402--- PASS: TestDumpPathMatchesNix (0.10s)403--- PASS: TestStreamPushBatchesUnderLoad (0.10s)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/postgres3303411376/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/postgres3303411376/data -l logfile start434435/build/postgres3303411376:5432 - no response4362026-10-07 06:12:06.236 UTC [129] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-07 06:12:06.236 UTC [129] LOG: listening on Unix socket "/build/postgres3303411376/.s.PGSQL.5432"4382026-10-07 06:12:06.241 UTC [136] LOG: database system was shut down at 2026-10-07 06:12:06 UTC4392026-10-07 06:12:06.245 UTC [129] LOG: database system is ready to accept connections440/build/postgres3303411376: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 TestDeleteClosuresRacingPins478=== PAUSE TestDeleteClosuresRacingPins479=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock480=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock481=== RUN TestResolveDBConnectionString482=== PAUSE TestResolveDBConnectionString483=== RUN TestConnectWaitsForAPeerMigration484=== PAUSE TestConnectWaitsForAPeerMigration485=== RUN TestLeadElectsOneAndHandsOver486=== PAUSE TestLeadElectsOneAndHandsOver487=== RUN TestLeadIncumbentWinsAfterRestart4882026/10/07 06:12:06 INFO lead: acquired remote=192.0.2.1:12344892026/10/07 06:12:07 INFO lead: released remote=192.0.2.1:12344902026/10/07 06:12:07 INFO lead: acquired remote=192.0.2.1:12344912026/10/07 06:12:08 INFO lead: released remote=192.0.2.1:1234492--- PASS: TestLeadIncumbentWinsAfterRestart (1.84s)493=== RUN TestLeadIncumbentAnnouncesAtOnce494=== PAUSE TestLeadIncumbentAnnouncesAtOnce495=== RUN TestLeadEndsOnShutdown496=== PAUSE TestLeadEndsOnShutdown497=== RUN TestLeadEndsWhenItsConnectionHangs4982026/10/07 06:12:08 INFO lead: acquired remote=192.0.2.1:12344992026-10-07 06:12:09.896 UTC [382] FATAL: terminating connection due to administrator command5002026/10/07 06:12:10 INFO lead: acquired remote=192.0.2.1:12345012026/10/07 06:12:11 WARN lead: lock connection lost error="timeout: context deadline exceeded"5022026/10/07 06:12:11 INFO lead: released remote=192.0.2.1:12345032026/10/07 06:12:11 INFO lead: released remote=192.0.2.1:1234504--- PASS: TestLeadEndsWhenItsConnectionHangs (2.92s)505=== RUN TestGCAdvisoryLockBlocksConcurrentRun506=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun507=== RUN TestGCBugBareHashReferences508=== PAUSE TestGCBugBareHashReferences509=== RUN TestGCMetrics510=== PAUSE TestGCMetrics511=== RUN TestPushDedupSurvivesConcurrentGC512=== PAUSE TestPushDedupSurvivesConcurrentGC513=== RUN TestDeduplicatedObjectsRecordedAsPending514=== PAUSE TestDeduplicatedObjectsRecordedAsPending515=== RUN TestGCSweepSkipsPendingObjects516=== PAUSE TestGCSweepSkipsPendingObjects517=== RUN TestTombstonedObjectOfferedWithoutWaiting518=== PAUSE TestTombstonedObjectOfferedWithoutWaiting519=== RUN TestGCSweepDeliversEachKeyOnce520=== PAUSE TestGCSweepDeliversEachKeyOnce521=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection522=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== RUN TestForceGCDuringPushOffersSweptObject524=== PAUSE TestForceGCDuringPushOffersSweptObject525=== RUN TestFailedS3DeleteKeepsTombstone526=== PAUSE TestFailedS3DeleteKeepsTombstone527=== RUN TestSweepSkipsRowsLockedByPush528=== PAUSE TestSweepSkipsRowsLockedByPush529=== RUN TestRegisterCompletedObjectNeedsPendingRow530=== PAUSE TestRegisterCompletedObjectNeedsPendingRow531=== RUN TestGetExistingObjectsLocksRows532=== PAUSE TestGetExistingObjectsLocksRows533=== RUN TestSweepRechecksPendingAfterLocking534=== PAUSE TestSweepRechecksPendingAfterLocking535=== RUN TestPushWaitsForSweepHoldingRow536=== PAUSE TestPushWaitsForSweepHoldingRow537=== RUN TestCommitRacingPendingCleanupKeepsObjects538=== PAUSE TestCommitRacingPendingCleanupKeepsObjects539=== RUN TestGCEndsOnShutdown540=== PAUSE TestGCEndsOnShutdown541=== RUN TestGCTaskStore_StartNew542=== PAUSE TestGCTaskStore_StartNew543=== RUN TestGCTaskStore_DeduplicateSameParams544=== PAUSE TestGCTaskStore_DeduplicateSameParams545=== RUN TestGCTaskStore_ConflictDifferentParams546=== PAUSE TestGCTaskStore_ConflictDifferentParams547=== RUN TestGCTaskStore_GetEmpty548=== PAUSE TestGCTaskStore_GetEmpty549=== RUN TestGCTaskStore_GetReturnsLatest550=== PAUSE TestGCTaskStore_GetReturnsLatest551=== RUN TestGCTaskStore_CompletedAllowsNewTask552=== PAUSE TestGCTaskStore_CompletedAllowsNewTask553=== RUN TestGCTaskStore_PhaseUpdates554=== PAUSE TestGCTaskStore_PhaseUpdates555=== RUN TestGCTaskStore_Fail556=== PAUSE TestGCTaskStore_Fail557=== RUN TestGracefulShutdownDrainsInflight558=== PAUSE TestGracefulShutdownDrainsInflight559=== RUN TestService_healthCheckHandler560=== PAUSE TestService_healthCheckHandler561=== RUN TestService_readinessHandler562=== PAUSE TestService_readinessHandler563=== RUN TestGenerateLandingPage564=== PAUSE TestGenerateLandingPage565=== RUN TestCacheConfigHandlerMaxNarSize566=== PAUSE TestCacheConfigHandlerMaxNarSize567=== RUN TestCreatePendingClosureRejectsOversizedNAR568=== PAUSE TestCreatePendingClosureRejectsOversizedNAR569=== RUN TestNARDeduplicationMetadataUploadBug570=== PAUSE TestNARDeduplicationMetadataUploadBug571=== RUN TestMetricsInventory572=== PAUSE TestMetricsInventory573=== RUN TestMetricsCommit574=== PAUSE TestMetricsCommit575=== RUN TestService_NativeMTLS576=== PAUSE TestService_NativeMTLS577=== RUN TestServerTLSConfig578=== PAUSE TestServerTLSConfig579=== RUN TestMultipartCleanup580=== PAUSE TestMultipartCleanup581=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded582=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded583=== RUN TestPendingCleanupUsesOneCutoff584=== PAUSE TestPendingCleanupUsesOneCutoff585=== RUN TestObjectStatsTrigger586=== PAUSE TestObjectStatsTrigger587=== RUN TestObjectStatsLargeCommit588=== PAUSE TestObjectStatsLargeCommit589=== RUN TestOrphanedObjectsGC590=== PAUSE TestOrphanedObjectsGC591=== RUN TestOrphanedObjectsGCStressTest592=== PAUSE TestOrphanedObjectsGCStressTest593=== RUN TestCreatePin_ReservedPins594=== PAUSE TestCreatePin_ReservedPins595=== RUN TestPresentReportsOnlyClosureRoots596=== PAUSE TestPresentReportsOnlyClosureRoots597=== RUN TestPresentRefreshesOnlyStaleClosures598=== PAUSE TestPresentRefreshesOnlyStaleClosures599=== RUN TestPresentNotReportedWhileGCDeletesClosure600=== PAUSE TestPresentNotReportedWhileGCDeletesClosure601=== RUN TestParseSingleRange602=== PAUSE TestParseSingleRange603=== RUN TestProxyHeadersOnlyTrustedOnSocket604=== PAUSE TestProxyHeadersOnlyTrustedOnSocket605=== RUN TestIsValidCachePath606=== PAUSE TestIsValidCachePath607=== RUN TestReadProxyNarinfo608=== PAUSE TestReadProxyNarinfo609=== RUN TestReadProxyNarinfoAlreadyDecompressed610=== PAUSE TestReadProxyNarinfoAlreadyDecompressed611=== RUN TestReadProxyContentNegotiation612=== PAUSE TestReadProxyContentNegotiation613=== RUN TestReadProxyNarStreaming614=== PAUSE TestReadProxyNarStreaming615=== RUN TestReadProxy404616=== PAUSE TestReadProxy404617=== RUN TestReadProxyInvalidPath618=== PAUSE TestReadProxyInvalidPath619=== RUN TestReadProxyHead620=== PAUSE TestReadProxyHead621=== RUN TestReadProxyOutlastsServerWriteTimeout622=== PAUSE TestReadProxyOutlastsServerWriteTimeout623=== RUN TestReadProxyConditionalGet624=== PAUSE TestReadProxyConditionalGet625=== RUN TestReadProxyRootRedirectsToIndexHTML626=== PAUSE TestReadProxyRootRedirectsToIndexHTML627=== RUN TestReadProxyDisabled628=== PAUSE TestReadProxyDisabled629=== RUN TestReadRedirectNar630=== PAUSE TestReadRedirectNar631=== RUN TestReadRedirectKeepsNarinfoProxied632=== PAUSE TestReadRedirectKeepsNarinfoProxied633=== RUN TestReadProxyRangeRequest634=== PAUSE TestReadProxyRangeRequest635=== RUN TestReadRedirectUsesPublicS3URL636=== PAUSE TestReadRedirectUsesPublicS3URL637=== RUN TestPush_OverlappingRootsStoreOneRowPerKey638=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey639=== RUN TestPush_CompleteCommitsEveryRoot640=== PAUSE TestPush_CompleteCommitsEveryRoot641=== RUN TestPush_RepeatedRootCommitsOnce642=== PAUSE TestPush_RepeatedRootCommitsOnce643=== RUN TestPush_CompleteWaitsForCleanupOfThePush644=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush645=== RUN TestPush_RootsAreLockedInByteOrder646=== PAUSE TestPush_RootsAreLockedInByteOrder647=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit648=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit649=== RUN TestPush_RejectsBadRequests650=== PAUSE TestPush_RejectsBadRequests651=== RUN TestPush_SignsNarinfosOfItsPendingObjects652=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects653=== RUN TestRedundantMultipartUpload654=== PAUSE TestRedundantMultipartUpload655=== RUN TestCompleteMultipartUpload_ErrorButObjectExists656=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists657=== RUN TestCompletedNarNotReofferedAcrossClosures658=== PAUSE TestCompletedNarNotReofferedAcrossClosures659=== RUN TestPresignedUploadRegisteredBeforeCommit660=== PAUSE TestPresignedUploadRegisteredBeforeCommit661=== RUN TestService_Rustfstest662=== PAUSE TestService_Rustfstest663=== RUN TestParseSize664=== PAUSE TestParseSize665=== RUN TestSkippedUploadsHandler666=== PAUSE TestSkippedUploadsHandler667=== RUN TestSystemdListenerNotActivated668--- PASS: TestSystemdListenerNotActivated (0.00s)669=== RUN TestWatchdogBeatsWhenHealthy670--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)671=== RUN TestWatchdogSkipsWhenUnhealthy6722026/10/07 06:12:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6732026/10/07 06:12:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6742026/10/07 06:12:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6752026/10/07 06:12:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6762026/10/07 06:12:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6772026/10/07 06:12:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6782026/10/07 06:12:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6792026/10/07 06:12:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6802026/10/07 06:12:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6812026/10/07 06:12:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"682--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)683=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle684=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle685=== RUN TestProxyWriteTimeout686=== PAUSE TestProxyWriteTimeout687=== RUN TestPendingClosureWriteTimeout688=== PAUSE TestPendingClosureWriteTimeout689=== RUN TestIsValidUploadKey690=== PAUSE TestIsValidUploadKey691=== RUN TestUploadHandlersRejectInvalidKeys692=== PAUSE TestUploadHandlersRejectInvalidKeys693=== RUN TestUploadHandlersRejectOversizedBody694=== PAUSE TestUploadHandlersRejectOversizedBody695=== RUN TestService_cleanupPendingClosuresHandler696=== PAUSE TestService_cleanupPendingClosuresHandler697=== RUN TestService_createPendingClosureHandler698=== PAUSE TestService_createPendingClosureHandler699=== RUN TestService_verifyS3Integrity700=== PAUSE TestService_verifyS3Integrity701=== RUN TestCompleteMultipartUnregistered702=== PAUSE TestCompleteMultipartUnregistered703=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT704=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT705=== CONT TestSkippedUploadsHandler706=== CONT TestPresignedUploadRegisteredBeforeCommit707=== CONT TestGracefulShutdownDrainsInflight708=== CONT TestGCBugBareHashReferences709=== CONT TestService_AuthMiddleware710=== CONT TestParseSize7112026/10/07 06:12:11 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000712=== CONT TestGCTaskStore_Fail713=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection7142026/10/07 06:12:11 INFO Starting HTTP server address=127.0.0.1:39507715=== CONT TestGCTaskStore_PhaseUpdates716=== CONT TestTombstonedObjectOfferedWithoutWaiting717=== CONT TestGCTaskStore_CompletedAllowsNewTask718=== CONT TestGCAdvisoryLockBlocksConcurrentRun719=== CONT TestGCTaskStore_GetReturnsLatest720=== CONT TestGCSweepSkipsPendingObjects721=== CONT TestGCTaskStore_GetEmpty7222026/10/07 06:12:11 INFO Shutdown signal received, draining in-flight requests timeout=10s723=== CONT TestGCSweepDeliversEachKeyOnce724=== CONT TestGCTaskStore_ConflictDifferentParams725=== CONT TestGCTaskStore_DeduplicateSameParams726=== CONT TestGCTaskStore_StartNew727=== CONT TestGCEndsOnShutdown728=== CONT TestCommitRacingPendingCleanupKeepsObjects729=== CONT TestPushWaitsForSweepHoldingRow730=== CONT TestSweepRechecksPendingAfterLocking731=== CONT TestGetExistingObjectsLocksRows732=== CONT TestRegisterCompletedObjectNeedsPendingRow733=== CONT TestSweepSkipsRowsLockedByPush734=== CONT TestFailedS3DeleteKeepsTombstone735=== CONT TestForceGCDuringPushOffersSweptObject736=== CONT TestService_Rustfstest737--- PASS: TestParseSize (0.00s)738--- PASS: TestGCTaskStore_Fail (0.00s)739--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)740--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)741--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)742--- PASS: TestGCTaskStore_GetEmpty (0.00s)743--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)744=== CONT TestDeduplicatedObjectsRecordedAsPending745--- PASS: TestSkippedUploadsHandler (0.00s)746=== CONT TestLeadEndsOnShutdown747--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)748=== CONT TestPushDedupSurvivesConcurrentGC749=== CONT TestClientWithDependencies750--- PASS: TestGCTaskStore_StartNew (0.00s)751=== CONT TestLeadIncumbentAnnouncesAtOnce752=== RUN TestGCEndsOnShutdown/before_the_run753=== PAUSE TestGCEndsOnShutdown/before_the_run754=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete755=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete756=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark757=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark758=== CONT TestGCMetrics759=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows760=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows761=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check762=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check763=== CONT TestLeadElectsOneAndHandsOver764--- PASS: TestGracefulShutdownDrainsInflight (0.07s)765=== CONT TestUploadHandlersRejectOversizedBody766=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure767=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure768=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart769=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart770=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts771=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts772=== CONT TestConnectWaitsForAPeerMigration7732026/10/07 06:12:11 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"774--- PASS: TestService_AuthMiddleware (0.32s)775=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT7762026/10/07 06:12:11 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"777--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.37s)778=== CONT TestResolveDBConnectionString779=== RUN TestResolveDBConnectionString/flag_wins780=== PAUSE TestResolveDBConnectionString/flag_wins781=== RUN TestResolveDBConnectionString/file_when_flag_empty782=== PAUSE TestResolveDBConnectionString/file_when_flag_empty783=== RUN TestResolveDBConnectionString/missing_file_is_an_error784=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error785=== RUN TestResolveDBConnectionString/PGHOST_allows_empty786=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty787=== RUN TestResolveDBConnectionString/nothing_configured788=== PAUSE TestResolveDBConnectionString/nothing_configured789=== CONT TestCompleteMultipartUnregistered7902026/10/07 06:12:11 INFO Received uploads request method=POST path=/api/pending_closures7912026/10/07 06:12:11 INFO Received uploads request method=POST path=/api/pending_closures792--- PASS: TestGetExistingObjectsLocksRows (0.42s)793=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock794--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.42s)795=== CONT TestService_verifyS3Integrity7962026/10/07 06:12:11 INFO Received uploads request method=POST path=/api/pending_closures797--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.44s)798=== CONT TestDeleteClosuresRacingPins7992026/10/07 06:12:11 INFO Received uploads request method=POST path=/api/pending_closures8002026/10/07 06:12:11 INFO Received uploads request method=POST path=/api/pending_closures8012026/10/07 06:12:12 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst8022026/10/07 06:12:12 INFO Received uploads request method=POST path=/api/pending_closures803--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.49s)804=== CONT TestService_createPendingClosureHandler8052026/10/07 06:12:12 INFO Aborted multipart uploads count=0 kept=08062026/10/07 06:12:12 WARN Force mode enabled - objects will be deleted immediately without grace period8072026/10/07 06:12:12 INFO Received uploads request method=POST path=/api/pending_closures8082026/10/07 06:12:12 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=08092026/10/07 06:12:12 INFO Vacuumed table table=pending_closures8102026/10/07 06:12:12 INFO Aborted multipart uploads count=0 kept=08112026/10/07 06:12:12 INFO Vacuumed table table=pending_objects8122026/10/07 06:12:12 INFO Vacuumed table table=multipart_uploads8132026/10/07 06:12:12 INFO Vacuumed table table=closures8142026/10/07 06:12:12 INFO Vacuumed table table=objects815--- PASS: TestSweepRechecksPendingAfterLocking (0.54s)816=== CONT TestClientFallsBackToClosures8172026/10/07 06:12:12 INFO Aborted multipart uploads count=0 kept=08182026/10/07 06:12:12 WARN Force mode enabled - objects will be deleted immediately without grace period8192026/10/07 06:12:12 INFO Received uploads request method=POST path=/api/pending_closures8202026/10/07 06:12:12 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=08212026/10/07 06:12:12 WARN Force mode enabled - objects will be deleted immediately without grace period8222026/10/07 06:12:12 INFO Vacuumed table table=pending_closures8232026/10/07 06:12:12 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=08242026/10/07 06:12:12 INFO Vacuumed table table=pending_objects8252026/10/07 06:12:12 INFO Vacuumed table table=multipart_uploads8262026/10/07 06:12:12 INFO Vacuumed table table=closures8272026/10/07 06:12:12 INFO Vacuumed table table=objects8282026/10/07 06:12:12 INFO Vacuumed table table=pending_closures8292026/10/07 06:12:12 INFO Vacuumed table table=pending_objects8302026/10/07 06:12:12 INFO Vacuumed table table=multipart_uploads8312026/10/07 06:12:12 INFO Vacuumed table table=closures8322026/10/07 06:12:12 INFO Vacuumed table table=objects833--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.56s)834=== CONT TestService_cleanupPendingClosuresHandler835--- PASS: TestGCSweepSkipsPendingObjects (0.56s)836=== CONT TestClientPushesUseOnePush8372026/10/07 06:12:12 INFO Aborted multipart uploads count=0 kept=0838--- PASS: TestGCBugBareHashReferences (0.57s)839=== CONT TestClientSharedPathCommittedMidPush8402026/10/07 06:12:12 WARN Force mode enabled - objects will be deleted immediately without grace period8412026/10/07 06:12:12 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=08422026/10/07 06:12:12 INFO Vacuumed table table=pending_closures8432026/10/07 06:12:12 INFO Vacuumed table table=pending_objects8442026/10/07 06:12:12 INFO Vacuumed table table=multipart_uploads8452026/10/07 06:12:12 INFO Vacuumed table table=closures8462026/10/07 06:12:12 INFO Vacuumed table table=objects847--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.58s)848=== CONT TestPinProtectsFromGC849=== CONT TestCacheConfigHandler850=== RUN TestCacheConfigHandler/full_config,_no_issuer851--- PASS: TestGCMetrics (0.58s)852=== PAUSE TestCacheConfigHandler/full_config,_no_issuer853=== RUN TestCacheConfigHandler/no_cache_url_configured854=== PAUSE TestCacheConfigHandler/no_cache_url_configured855=== RUN TestCacheConfigHandler/no_signing_keys856=== PAUSE TestCacheConfigHandler/no_signing_keys857=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator858=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator859=== CONT TestReadProxyNarinfoAlreadyDecompressed860--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.59s)861=== CONT TestClientMultipleUploads8622026/10/07 06:12:12 INFO Received uploads request method=POST path=/api/pending_closures8632026/10/07 06:12:12 INFO Aborted multipart uploads count=0 kept=08642026/10/07 06:12:12 WARN Force mode enabled - objects will be deleted immediately without grace period8652026/10/07 06:12:12 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."8662026/10/07 06:12:12 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."8672026/10/07 06:12:12 INFO Aborted multipart uploads count=0 kept=0868--- PASS: TestFailedS3DeleteKeepsTombstone (0.71s)869=== CONT TestCompletedNarNotReofferedAcrossClosures8702026/10/07 06:12:12 WARN Force mode enabled - objects will be deleted immediately without grace period8712026/10/07 06:12:12 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=08722026/10/07 06:12:12 INFO Vacuumed table table=pending_closures8732026/10/07 06:12:12 INFO Vacuumed table table=pending_objects8742026/10/07 06:12:12 INFO Vacuumed table table=multipart_uploads8752026/10/07 06:12:12 INFO Vacuumed table table=closures8762026/10/07 06:12:12 INFO lead: acquired remote=192.0.2.1:12348772026/10/07 06:12:12 INFO Vacuumed table table=objects8782026/10/07 06:12:12 INFO Aborted multipart uploads count=0 kept=08792026/10/07 06:12:12 WARN Force mode enabled - objects will be deleted immediately without grace period8802026/10/07 06:12:12 INFO Aborted multipart uploads count=0 kept=08812026/10/07 06:12:12 WARN Force mode enabled - objects will be deleted immediately without grace period8822026/10/07 06:12:12 INFO lead: acquired remote=192.0.2.1:12348832026/10/07 06:12:12 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=08842026/10/07 06:12:12 INFO Vacuumed table table=pending_closures8852026/10/07 06:12:12 INFO Vacuumed table table=pending_objects8862026/10/07 06:12:12 INFO Vacuumed table table=multipart_uploads8872026/10/07 06:12:12 INFO Vacuumed table table=closures8882026/10/07 06:12:12 INFO Vacuumed table table=objects8892026/10/07 06:12:12 INFO Aborted multipart uploads count=0 kept=0890--- PASS: TestSweepSkipsRowsLockedByPush (0.75s)891=== CONT TestClientIntegration8922026/10/07 06:12:12 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=08932026/10/07 06:12:12 INFO Vacuumed table table=pending_closures8942026/10/07 06:12:12 INFO Vacuumed table table=pending_objects8952026/10/07 06:12:12 INFO Vacuumed table table=multipart_uploads8962026/10/07 06:12:12 INFO Vacuumed table table=closures8972026/10/07 06:12:12 INFO Vacuumed table table=objects898--- PASS: TestGCSweepDeliversEachKeyOnce (0.77s)899=== CONT TestCompleteMultipartUpload_ErrorButObjectExists9002026/10/07 06:12:12 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=09012026/10/07 06:12:12 INFO Vacuumed table table=pending_closures9022026/10/07 06:12:12 INFO Vacuumed table table=pending_objects9032026/10/07 06:12:12 INFO Vacuumed table table=multipart_uploads9042026/10/07 06:12:12 INFO Vacuumed table table=closures9052026/10/07 06:12:12 INFO Vacuumed table table=objects9062026/10/07 06:12:12 INFO Aborted multipart uploads count=0 kept=09072026/10/07 06:12:12 WARN Force mode enabled - objects will be deleted immediately without grace period9082026/10/07 06:12:12 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=09092026/10/07 06:12:12 INFO Vacuumed table table=pending_closures9102026/10/07 06:12:12 INFO Vacuumed table table=pending_objects9112026/10/07 06:12:12 INFO Vacuumed table table=multipart_uploads9122026/10/07 06:12:12 INFO Vacuumed table table=closures9132026/10/07 06:12:12 INFO Vacuumed table table=objects914--- PASS: TestPushDedupSurvivesConcurrentGC (0.79s)915=== CONT TestClientErrorHandling916=== RUN TestClientErrorHandling/InvalidStorePath917=== PAUSE TestClientErrorHandling/InvalidStorePath918=== RUN TestClientErrorHandling/InvalidAuthToken919=== PAUSE TestClientErrorHandling/InvalidAuthToken920=== RUN TestClientErrorHandling/ServerNotAvailable921=== PAUSE TestClientErrorHandling/ServerNotAvailable922=== CONT TestRedundantMultipartUpload9232026/10/07 06:12:12 INFO lead: acquired remote=192.0.2.1:12349242026/10/07 06:12:12 INFO lead: released remote=192.0.2.1:1234925--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.79s)926=== CONT TestClientCADerivations927--- PASS: TestService_Rustfstest (0.83s)928=== CONT TestPush_SignsNarinfosOfItsPendingObjects9292026/10/07 06:12:12 INFO Received uploads request method=POST path=/api/pending_closures930--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.54s)931=== CONT TestCacheStatsHandler932=== NAME TestClientWithDependencies933 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2047289256/001/store/24m4hal3riq87vxyiba8iqzq6nxwqbvm-test-script9342026/10/07 06:12:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9352026/10/07 06:12:12 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst936--- PASS: TestCompleteMultipartUnregistered (0.50s)937=== CONT TestPush_RejectsBadRequests938=== NAME TestClientWithDependencies939 client_integration_test.go:615: Found 1 dependencies (including self)9402026/10/07 06:12:12 INFO Received uploads request method=POST path=/api/pending_closures9412026/10/07 06:12:12 INFO Received uploads request method=POST path=/api/pending_closures9422026/10/07 06:12:12 INFO Received uploads request method=POST path=/api/pending_closures9432026/10/07 06:12:12 INFO Received uploads request method=POST path=/api/pending_closures944--- PASS: TestPushWaitsForSweepHoldingRow (0.96s)945=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit9462026/10/07 06:12:12 INFO Received push request method=POST path=/api/pushes9472026/10/07 06:12:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9482026/10/07 06:12:12 INFO Uploading 24m4hal3riq87vxyiba8iqzq6nxwqbvm-test-script (136B)9492026/10/07 06:12:12 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"9502026/10/07 06:12:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9512026/10/07 06:12:12 WARN Failed to register uploaded object key=log/qx1j76b7kdwsgpgsi09fv33r0k1z23gj-test-script.drv error="server returned 404: 404 page not found\n"9522026/10/07 06:12:12 WARN Failed to register uploaded object key=24m4hal3riq87vxyiba8iqzq6nxwqbvm.ls error="server returned 404: 404 page not found\n"9532026/10/07 06:12:12 INFO Signed narinfos id=1 count=19542026/10/07 06:12:12 INFO Uploading 1 narinfos9552026/10/07 06:12:12 INFO Received complete push request method=POST path=/api/pushes/1/complete9562026/10/07 06:12:12 WARN Failed to register uploaded object key=24m4hal3riq87vxyiba8iqzq6nxwqbvm.narinfo error="server returned 404: 404 page not found\n"9572026/10/07 06:12:12 INFO Completed push id=1 objects=4 duration=14.438008ms9582026/10/07 06:12:12 INFO Upload complete. (71ms)959=== NAME TestClientWithDependencies960 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2047289256/001/store) requires matching store prefix961--- PASS: TestClientWithDependencies (1.01s)962=== CONT TestPendingCleanupUsesOneCutoff9632026/10/07 06:12:12 INFO Received cleanup request method=DELETE path=/api/pending_closures9642026/10/07 06:12:12 INFO Aborted multipart uploads count=0 kept=09652026/10/07 06:12:12 INFO Received uploads request method=POST path=/api/pending_closures9662026/10/07 06:12:12 INFO Received cleanup request method=DELETE path=/api/pending_closures9672026/10/07 06:12:12 INFO Aborted multipart uploads count=1 kept=09682026/10/07 06:12:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9692026-10-07 06:12:12.560 UTC [526] ERROR: Closure does not exist: id=19702026-10-07 06:12:12.560 UTC [526] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9712026-10-07 06:12:12.560 UTC [526] STATEMENT: -- name: CommitPendingClosure :one972 SELECT commit_pending_closure($1::bigint)::bigint973 974--- PASS: TestService_cleanupPendingClosuresHandler (0.47s)975=== CONT TestPush_RootsAreLockedInByteOrder976--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.48s)977=== CONT TestReadProxyNarinfo9782026/10/07 06:12:12 INFO Received uploads request method=POST path=/api/pending_closures979=== NAME TestClientMultipleUploads980 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads156965112/001/store/124mc54hz5f43rj1krpnd5ri6pn5923k-test-file-0.txt981=== NAME TestPinProtectsFromGC982 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC752986200/001/store/9c92i2kl8mfyrxvp9ln3cj2v9vr9gil6-pinned-file.txt983 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC752986200/001/store/2l39zn96kdcsqm8hff6v5ccir31xjanm-unpinned-file.txt9842026/10/07 06:12:12 INFO Received uploads request method=POST path=/api/pending_closures985--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.75s)986=== CONT TestPush_CompleteWaitsForCleanupOfThePush9872026/10/07 06:12:12 INFO Received uploads request method=POST path=/api/pending_closures9882026/10/07 06:12:12 INFO Received uploads request method=POST path=/api/pending_closures9892026/10/07 06:12:12 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)9902026/10/07 06:12:12 INFO Uploading 23zysmr7zlqc7fsb5ilvn9wsqwkz9gd7-a (216B)9912026/10/07 06:12:12 INFO Uploading a98ymhzqlilg3qiyp2fkj90r6qldgz8z-shared-dep (136B)9922026/10/07 06:12:12 INFO Received push request method=POST path=/api/pushes9932026/10/07 06:12:12 WARN Failed to register uploaded object key=lwyf451bhsbrq0lnalflgxy3vnvqqjfh.ls error="server returned 404: 404 page not found\n"9942026/10/07 06:12:12 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"9952026/10/07 06:12:12 WARN Failed to register uploaded object key=nar/0zdayhi9qzgd3d82sgk91j365snw69f8phan94vx8kdsjd04fdg4.nar.zst error="server returned 404: 404 page not found\n"9962026/10/07 06:12:12 WARN Failed to register uploaded object key=a98ymhzqlilg3qiyp2fkj90r6qldgz8z.ls error="server returned 404: 404 page not found\n"9972026/10/07 06:12:12 WARN Failed to register uploaded object key=23zysmr7zlqc7fsb5ilvn9wsqwkz9gd7.ls error="server returned 404: 404 page not found\n"9982026/10/07 06:12:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9992026/10/07 06:12:12 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)10002026/10/07 06:12:12 INFO Uploading fb11rfixzdxfj3r6447qcs61yvb738cr-shared-dep (136B)10012026/10/07 06:12:12 INFO Uploading sixax290m1w01sn275nn6qxi5wvkwmwl-b (216B)10022026/10/07 06:12:12 INFO Signed narinfos id=1 count=210032026/10/07 06:12:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10042026/10/07 06:12:12 INFO Signed narinfos id=2 count=210052026/10/07 06:12:12 INFO Uploading 4 narinfos1006=== NAME TestClientMultipleUploads1007 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads156965112/001/store/arfv57zfh4292s2k3lay1nrm8bxif3ab-test-file-1.txt10082026/10/07 06:12:12 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10092026/10/07 06:12:12 WARN Failed to register uploaded object key=9jz2gi3j7df9iagv2fk8ka1zwp0wqgd2.ls error="server returned 404: 404 page not found\n"10102026/10/07 06:12:12 WARN Failed to register uploaded object key=nar/0ka5d2mn3svpxw54yrr0d6l6ghchvdcycf95gp4xbnpi234vq6yc.nar.zst error="server returned 404: 404 page not found\n"10112026/10/07 06:12:12 WARN Failed to register uploaded object key=fb11rfixzdxfj3r6447qcs61yvb738cr.ls error="server returned 404: 404 page not found\n"10122026/10/07 06:12:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10132026/10/07 06:12:12 WARN Failed to register uploaded object key=lwyf451bhsbrq0lnalflgxy3vnvqqjfh.narinfo error="server returned 404: 404 page not found\n"10142026/10/07 06:12:12 WARN Failed to register uploaded object key=a98ymhzqlilg3qiyp2fkj90r6qldgz8z.narinfo error="server returned 404: 404 page not found\n"10152026/10/07 06:12:12 WARN Failed to register uploaded object key=sixax290m1w01sn275nn6qxi5wvkwmwl.ls error="server returned 404: 404 page not found\n"10162026/10/07 06:12:12 WARN Failed to register uploaded object key=a98ymhzqlilg3qiyp2fkj90r6qldgz8z.narinfo error="server returned 404: 404 page not found\n"10172026/10/07 06:12:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10182026/10/07 06:12:12 WARN Failed to register uploaded object key=23zysmr7zlqc7fsb5ilvn9wsqwkz9gd7.narinfo error="server returned 404: 404 page not found\n"10192026/10/07 06:12:12 INFO Received push request method=POST path=/api/pushes10202026/10/07 06:12:12 INFO Signed narinfos id=1 count=310212026/10/07 06:12:12 INFO Uploading 3 narinfos1022=== NAME TestClientIntegration1023 client_integration_test.go:286: Created store path: /build/TestClientIntegration1144534363/002/store/yychi8bihxqhww27b2h7f8vmkbbpj8cy-test-file.txt10242026/10/07 06:12:12 WARN Failed to register uploaded object key=fb11rfixzdxfj3r6447qcs61yvb738cr.narinfo error="server returned 404: 404 page not found\n"10252026/10/07 06:12:12 WARN Failed to register uploaded object key=sixax290m1w01sn275nn6qxi5wvkwmwl.narinfo error="server returned 404: 404 page not found\n"10262026/10/07 06:12:12 INFO Received complete push request method=POST path=/api/pushes/1/complete10272026/10/07 06:12:12 INFO Completed upload id=1 objects=6 duration=5.808752ms10282026/10/07 06:12:12 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)10292026/10/07 06:12:12 WARN Failed to register uploaded object key=9jz2gi3j7df9iagv2fk8ka1zwp0wqgd2.narinfo error="server returned 404: 404 page not found\n"10302026/10/07 06:12:12 INFO Uploading 0jbg4jysd8km40qiq778y7hag0cbg1f0-top (224B)10312026/10/07 06:12:12 INFO Uploading lx0gvvv3vw530x0haxcqgk97npgmg7ff-shared-dep (136B)10322026/10/07 06:12:12 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10332026/10/07 06:12:12 INFO Received push request method=POST path=/api/pushes10342026/10/07 06:12:12 INFO Completed upload id=2 objects=6 duration=1.582774ms10352026/10/07 06:12:12 INFO Upload complete. (73ms)1036=== NAME TestClientFallsBackToClosures1037 client_pushes_test.go:112: Retrieved narinfo from S3:1038 StorePath: /build/TestClientFallsBackToClosures3795947454/001/store/a98ymhzqlilg3qiyp2fkj90r6qldgz8z-shared-dep1039 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1040 Compression: zstd1041 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821042 NarSize: 1361043 References: 1044 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n10452026/10/07 06:12:12 WARN Failed to register uploaded object key=nar/1p72i2ymcja35b18j7cnvjkbaxk2ms6cvqlz78fy76xw80zmxpi9.nar.zst error="server returned 404: 404 page not found\n"10462026/10/07 06:12:12 WARN Failed to register uploaded object key=0jbg4jysd8km40qiq778y7hag0cbg1f0.ls error="server returned 404: 404 page not found\n"10472026/10/07 06:12:12 INFO Completed push id=1 objects=8 duration=5.652909ms10482026/10/07 06:12:12 INFO Upload complete. (62ms)10492026/10/07 06:12:12 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10502026/10/07 06:12:12 WARN Failed to register uploaded object key=lx0gvvv3vw530x0haxcqgk97npgmg7ff.ls error="server returned 404: 404 page not found\n"1051 client_pushes_test.go:112: Retrieved narinfo from S3:10522026/10/07 06:12:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1053 StorePath: /build/TestClientFallsBackToClosures3795947454/001/store/23zysmr7zlqc7fsb5ilvn9wsqwkz9gd7-a1054 URL: nar/0zdayhi9qzgd3d82sgk91j365snw69f8phan94vx8kdsjd04fdg4.nar.zst1055 Compression: zstd1056 NarHash: sha256:0zdayhi9qzgd3d82sgk91j365snw69f8phan94vx8kdsjd04fdg41057 NarSize: 2161058 References: /build/TestClientFallsBackToClosures3795947454/001/store/a98ymhzqlilg3qiyp2fkj90r6qldgz8z-shared-dep1059 CA: text:sha256:1iz5b35zmk2a0pyc6j3vp07pdgjkxxfbhd30m9m0cb8z4sr0ndbs10602026/10/07 06:12:12 INFO Signed narinfos id=1 count=21061=== NAME TestClientPushesUseOnePush1062 client_pushes_test.go:97: Retrieved narinfo from S3:1063 StorePath: /build/TestClientPushesUseOnePush2033048783/001/store/fb11rfixzdxfj3r6447qcs61yvb738cr-shared-dep1064 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1065 Compression: zstd1066 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821067 NarSize: 13610682026/10/07 06:12:12 INFO Uploading 2 narinfos1069 References: 1070 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n10712026/10/07 06:12:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1072=== NAME TestClientFallsBackToClosures1073 client_pushes_test.go:112: Retrieved narinfo from S3:1074 StorePath: /build/TestClientFallsBackToClosures3795947454/001/store/lwyf451bhsbrq0lnalflgxy3vnvqqjfh-b1075 URL: nar/0zdayhi9qzgd3d82sgk91j365snw69f8phan94vx8kdsjd04fdg4.nar.zst1076 Compression: zstd1077 NarHash: sha256:0zdayhi9qzgd3d82sgk91j365snw69f8phan94vx8kdsjd04fdg41078 NarSize: 2161079 References: /build/TestClientFallsBackToClosures3795947454/001/store/a98ymhzqlilg3qiyp2fkj90r6qldgz8z-shared-dep1080 CA: text:sha256:1iz5b35zmk2a0pyc6j3vp07pdgjkxxfbhd30m9m0cb8z4sr0ndbs1081=== NAME TestClientPushesUseOnePush1082 client_pushes_test.go:97: Retrieved narinfo from S3:1083 StorePath: /build/TestClientPushesUseOnePush2033048783/001/store/9jz2gi3j7df9iagv2fk8ka1zwp0wqgd2-a1084 URL: nar/0ka5d2mn3svpxw54yrr0d6l6ghchvdcycf95gp4xbnpi234vq6yc.nar.zst1085 Compression: zstd1086 NarHash: sha256:0ka5d2mn3svpxw54yrr0d6l6ghchvdcycf95gp4xbnpi234vq6yc1087 NarSize: 2161088 References: /build/TestClientPushesUseOnePush2033048783/001/store/fb11rfixzdxfj3r6447qcs61yvb738cr-shared-dep1089 CA: text:sha256:1m47br5bdxwzymif8qyv2hc7bhqy70wvsv8npw1c14k5w29zdk5z10902026/10/07 06:12:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10912026/10/07 06:12:12 WARN Failed to register uploaded object key=lx0gvvv3vw530x0haxcqgk97npgmg7ff.narinfo error="server returned 404: 404 page not found\n"10922026/10/07 06:12:12 INFO Received complete push request method=POST path=/api/pushes/1/complete10932026/10/07 06:12:12 WARN Failed to register uploaded object key=0jbg4jysd8km40qiq778y7hag0cbg1f0.narinfo error="server returned 404: 404 page not found\n"10942026/10/07 06:12:12 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZTc0MjIyMGMtNjQ0NS00OTI3LTk1ZDMtZWUwNTVmNmI0OGY4LjA2NWYzNDc1LTk0MGQtNDBjMi04MTE4LTM3ZWExZDdmOWE3N3gxNzkxMzUzNTMyNzAyMTIyNDgw1095--- PASS: TestClientFallsBackToClosures (0.67s)1096=== CONT TestIsValidCachePath1097=== RUN TestIsValidCachePath/narinfo1098=== PAUSE TestIsValidCachePath/narinfo1099=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1100=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1101=== RUN TestIsValidCachePath/nar_zst1102=== PAUSE TestIsValidCachePath/nar_zst1103=== RUN TestIsValidCachePath/nar_xz1104=== PAUSE TestIsValidCachePath/nar_xz1105=== RUN TestIsValidCachePath/nar_bz21106=== PAUSE TestIsValidCachePath/nar_bz21107=== RUN TestIsValidCachePath/nar_uncompressed1108=== PAUSE TestIsValidCachePath/nar_uncompressed1109=== RUN TestIsValidCachePath/ls1110=== PAUSE TestIsValidCachePath/ls1111=== RUN TestIsValidCachePath/log1112=== PAUSE TestIsValidCachePath/log1113=== NAME TestClientPushesUseOnePush1114 client_pushes_test.go:97: Retrieved narinfo from S3:1115 StorePath: /build/TestClientPushesUseOnePush2033048783/001/store/sixax290m1w01sn275nn6qxi5wvkwmwl-b1116 URL: nar/0ka5d2mn3svpxw54yrr0d6l6ghchvdcycf95gp4xbnpi234vq6yc.nar.zst1117 Compression: zstd1118 NarHash: sha256:0ka5d2mn3svpxw54yrr0d6l6ghchvdcycf95gp4xbnpi234vq6yc1119 NarSize: 2161120 References: /build/TestClientPushesUseOnePush2033048783/001/store/fb11rfixzdxfj3r6447qcs61yvb738cr-shared-dep1121 CA: text:sha256:1m47br5bdxwzymif8qyv2hc7bhqy70wvsv8npw1c14k5w29zdk5z1122=== RUN TestIsValidCachePath/realisation1123=== PAUSE TestIsValidCachePath/realisation1124=== RUN TestIsValidCachePath/nix-cache-info1125=== PAUSE TestIsValidCachePath/nix-cache-info1126=== RUN TestIsValidCachePath/index.html1127=== PAUSE TestIsValidCachePath/index.html1128=== RUN TestIsValidCachePath/traversal_parent1129=== PAUSE TestIsValidCachePath/traversal_parent1130=== RUN TestIsValidCachePath/traversal_in_middle1131=== PAUSE TestIsValidCachePath/traversal_in_middle1132=== RUN TestIsValidCachePath/invalid_char_e1133=== PAUSE TestIsValidCachePath/invalid_char_e1134=== RUN TestIsValidCachePath/invalid_char_u1135=== PAUSE TestIsValidCachePath/invalid_char_u1136=== RUN TestIsValidCachePath/random_path1137=== PAUSE TestIsValidCachePath/random_path1138=== RUN TestIsValidCachePath/empty1139=== PAUSE TestIsValidCachePath/empty1140=== RUN TestIsValidCachePath/leading_slash1141=== PAUSE TestIsValidCachePath/leading_slash1142=== RUN TestIsValidCachePath/wrong_extension1143=== PAUSE TestIsValidCachePath/wrong_extension1144=== RUN TestIsValidCachePath/short_hash1145=== PAUSE TestIsValidCachePath/short_hash1146=== CONT TestPush_RepeatedRootCommitsOnce11472026/10/07 06:12:12 INFO Signed narinfos id=1 count=111482026/10/07 06:12:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11492026/10/07 06:12:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11502026/10/07 06:12:12 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"11512026/10/07 06:12:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11522026/10/07 06:12:12 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"11532026/10/07 06:12:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11542026/10/07 06:12:12 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=111552026/10/07 06:12:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11562026/10/07 06:12:12 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1157--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.38s)1158=== CONT TestProxyHeadersOnlyTrustedOnSocket1159--- PASS: TestClientPushesUseOnePush (0.65s)1160=== CONT TestPush_CompleteCommitsEveryRoot11612026/10/07 06:12:12 INFO Completed push id=1 objects=6 duration=6.994162ms11622026/10/07 06:12:12 INFO Upload complete. (68ms)1163=== NAME TestClientSharedPathCommittedMidPush1164 client_integration_test.go:680: Retrieved narinfo from S3:1165 StorePath: /build/TestClientSharedPathCommittedMidPush3582677433/001/store/lx0gvvv3vw530x0haxcqgk97npgmg7ff-shared-dep1166 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1167 Compression: zstd1168 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821169 NarSize: 1361170 References: 1171 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n11722026/10/07 06:12:12 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZTc0MjIyMGMtNjQ0NS00OTI3LTk1ZDMtZWUwNTVmNmI0OGY4LjA2NWYzNDc1LTk0MGQtNDBjMi04MTE4LTM3ZWExZDdmOWE3N3gxNzkxMzUzNTMyNzAyMTIyNDgw parts=11173=== NAME TestClientMultipleUploads1174 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads156965112/001/store/hxx19a24p9w790sx5f6b05njslw1xajn-test-file-2.txt11752026/10/07 06:12:12 INFO Received uploads request method=POST path=/api/pending_closures1176=== NAME TestClientSharedPathCommittedMidPush1177 client_integration_test.go:680: Retrieved narinfo from S3:1178 StorePath: /build/TestClientSharedPathCommittedMidPush3582677433/001/store/0jbg4jysd8km40qiq778y7hag0cbg1f0-top1179 URL: nar/1p72i2ymcja35b18j7cnvjkbaxk2ms6cvqlz78fy76xw80zmxpi9.nar.zst1180 Compression: zstd1181 NarHash: sha256:1p72i2ymcja35b18j7cnvjkbaxk2ms6cvqlz78fy76xw80zmxpi91182 NarSize: 2241183 References: /build/TestClientSharedPathCommittedMidPush3582677433/001/store/lx0gvvv3vw530x0haxcqgk97npgmg7ff-shared-dep1184 CA: text:sha256:1bahkdl3186saq9ya73kzs0lxhg167jm0k7afjcqh2fsphl2liad1185--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.45s)1186=== CONT TestParseSingleRange1187=== RUN TestParseSingleRange/none1188=== PAUSE TestParseSingleRange/none1189=== RUN TestParseSingleRange/unknown_unit1190=== PAUSE TestParseSingleRange/unknown_unit1191=== RUN TestParseSingleRange/multi-range_ignored1192=== PAUSE TestParseSingleRange/multi-range_ignored1193=== RUN TestParseSingleRange/malformed_no_dash1194=== PAUSE TestParseSingleRange/malformed_no_dash1195=== RUN TestParseSingleRange/malformed_both_empty1196=== PAUSE TestParseSingleRange/malformed_both_empty1197=== RUN TestParseSingleRange/malformed_end_before_start1198=== PAUSE TestParseSingleRange/malformed_end_before_start1199=== RUN TestParseSingleRange/closed1200=== PAUSE TestParseSingleRange/closed1201=== RUN TestParseSingleRange/open-ended1202=== PAUSE TestParseSingleRange/open-ended1203=== RUN TestParseSingleRange/end_clamped_to_size1204=== PAUSE TestParseSingleRange/end_clamped_to_size1205=== RUN TestParseSingleRange/suffix1206=== PAUSE TestParseSingleRange/suffix1207=== RUN TestParseSingleRange/suffix_exceeds_size1208=== PAUSE TestParseSingleRange/suffix_exceeds_size1209=== RUN TestParseSingleRange/single_byte1210=== PAUSE TestParseSingleRange/single_byte1211=== RUN TestParseSingleRange/start_past_EOF1212=== PAUSE TestParseSingleRange/start_past_EOF1213=== RUN TestParseSingleRange/start_far_past_EOF1214=== PAUSE TestParseSingleRange/start_far_past_EOF1215=== CONT TestPush_OverlappingRootsStoreOneRowPerKey1216--- PASS: TestClientSharedPathCommittedMidPush (0.65s)1217=== CONT TestPresentNotReportedWhileGCDeletesClosure1218=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1219=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1220=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1221=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1222=== CONT TestReadRedirectUsesPublicS3URL12232026/10/07 06:12:12 INFO Received push request method=POST path=/api/pushes12242026/10/07 06:12:12 INFO Received uploads request method=POST path=/api/pending_closures12252026/10/07 06:12:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12262026/10/07 06:12:12 INFO Uploading 9c92i2kl8mfyrxvp9ln3cj2v9vr9gil6-pinned-file.txt (128B)12272026/10/07 06:12:12 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"12282026/10/07 06:12:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12292026/10/07 06:12:12 WARN Failed to register uploaded object key=9c92i2kl8mfyrxvp9ln3cj2v9vr9gil6.ls error="server returned 404: 404 page not found\n"12302026/10/07 06:12:12 INFO Signed narinfos id=1 count=112312026/10/07 06:12:12 INFO Uploading 1 narinfos12322026/10/07 06:12:12 INFO Received complete push request method=POST path=/api/pushes/1/complete12332026/10/07 06:12:12 WARN Failed to register uploaded object key=9c92i2kl8mfyrxvp9ln3cj2v9vr9gil6.narinfo error="server returned 404: 404 page not found\n"12342026/10/07 06:12:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12352026/10/07 06:12:12 INFO Completed push id=1 objects=3 duration=9.738426ms12362026/10/07 06:12:12 INFO Upload complete. (65ms)12372026/10/07 06:12:12 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZTc0MjIyMGMtNjQ0NS00OTI3LTk1ZDMtZWUwNTVmNmI0OGY4LjFiMTBkZWIyLWRhMzItNDI5Yy04ZTZjLTI2MzFmZDMyZmRkYXgxNzkxMzUzNTMyNDQxMDg3Mjkw parts=1012382026/10/07 06:12:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12392026/10/07 06:12:12 INFO Received push request method=POST path=/api/pushes12402026/10/07 06:12:12 INFO Completed upload id=1 objects=2 duration=4.581341ms12412026/10/07 06:12:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12422026/10/07 06:12:12 INFO Received uploads request method=POST path=/api/pending_closures12432026/10/07 06:12:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12442026/10/07 06:12:12 INFO Uploading yychi8bihxqhww27b2h7f8vmkbbpj8cy-test-file.txt (152B)12452026/10/07 06:12:12 INFO Received uploads request method=POST path=/api/pending_closures12462026/10/07 06:12:12 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12472026/10/07 06:12:12 WARN Failed to register uploaded object key=yychi8bihxqhww27b2h7f8vmkbbpj8cy.ls error="server returned 404: 404 page not found\n"12482026/10/07 06:12:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1249--- PASS: TestCacheStatsHandler (0.41s)1250=== CONT TestPresentRefreshesOnlyStaleClosures12512026/10/07 06:12:12 INFO Signed narinfos id=1 count=112522026/10/07 06:12:12 INFO Uploading 1 narinfos12532026/10/07 06:12:12 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo12542026/10/07 06:12:12 WARN Found objects in DB but missing from S3, will re-upload count=11255--- PASS: TestService_verifyS3Integrity (0.86s)1256=== CONT TestReadProxyRangeRequest12572026/10/07 06:12:12 INFO Received complete push request method=POST path=/api/pushes/1/complete12582026/10/07 06:12:12 WARN Failed to register uploaded object key=yychi8bihxqhww27b2h7f8vmkbbpj8cy.narinfo error="server returned 404: 404 page not found\n"1259=== RUN TestPush_RejectsBadRequests/no_objects1260=== PAUSE TestPush_RejectsBadRequests/no_objects1261=== RUN TestPush_RejectsBadRequests/bad_root1262=== PAUSE TestPush_RejectsBadRequests/bad_root1263=== RUN TestPush_RejectsBadRequests/root_not_in_objects1264=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1265=== RUN TestPush_RejectsBadRequests/no_roots1266=== PAUSE TestPush_RejectsBadRequests/no_roots1267=== CONT TestPresentReportsOnlyClosureRoots12682026/10/07 06:12:12 INFO Completed push id=1 objects=3 duration=10.385812ms12692026/10/07 06:12:12 INFO Upload complete. (66ms)12702026/10/07 06:12:12 INFO Received push request method=POST path=/api/pushes12712026/10/07 06:12:12 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZTc0MjIyMGMtNjQ0NS00OTI3LTk1ZDMtZWUwNTVmNmI0OGY4LmI3ZDhkZjNhLTM2MGEtNDViNS05NzhiLTY0ZTdkNjZjYmUxOHgxNzkxMzUzNTMyNDgwMjc1MDE3 parts=1012722026/10/07 06:12:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12732026/10/07 06:12:12 INFO Completed upload id=1 objects=2 duration=3.40833ms12742026/10/07 06:12:12 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000012752026/10/07 06:12:12 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)12762026/10/07 06:12:12 INFO Uploading arfv57zfh4292s2k3lay1nrm8bxif3ab-test-file-1.txt (160B)12772026/10/07 06:12:12 INFO Uploading hxx19a24p9w790sx5f6b05njslw1xajn-test-file-2.txt (160B)12782026/10/07 06:12:12 INFO Uploading 124mc54hz5f43rj1krpnd5ri6pn5923k-test-file-0.txt (160B)12792026/10/07 06:12:12 INFO Received uploads request method=POST path=/api/pending_closures12802026/10/07 06:12:12 INFO Starting cleanup of old closures method=DELETE path=/api/closures12812026/10/07 06:12:12 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"12822026/10/07 06:12:12 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"12832026/10/07 06:12:12 WARN Failed to register uploaded object key=arfv57zfh4292s2k3lay1nrm8bxif3ab.ls error="server returned 404: 404 page not found\n"12842026/10/07 06:12:12 WARN Failed to register uploaded object key=124mc54hz5f43rj1krpnd5ri6pn5923k.ls error="server returned 404: 404 page not found\n"12852026/10/07 06:12:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12862026/10/07 06:12:12 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"12872026/10/07 06:12:12 WARN Failed to register uploaded object key=hxx19a24p9w790sx5f6b05njslw1xajn.ls error="server returned 404: 404 page not found\n"12882026/10/07 06:12:12 INFO Signed narinfos id=1 count=312892026/10/07 06:12:12 INFO Uploading 3 narinfos12902026/10/07 06:12:12 WARN Failed to register uploaded object key=124mc54hz5f43rj1krpnd5ri6pn5923k.narinfo error="server returned 404: 404 page not found\n"12912026/10/07 06:12:12 WARN Failed to register uploaded object key=hxx19a24p9w790sx5f6b05njslw1xajn.narinfo error="server returned 404: 404 page not found\n"12922026/10/07 06:12:12 INFO Received complete push request method=POST path=/api/pushes/1/complete12932026/10/07 06:12:12 WARN Failed to register uploaded object key=arfv57zfh4292s2k3lay1nrm8bxif3ab.narinfo error="server returned 404: 404 page not found\n"12942026/10/07 06:12:12 INFO Received push request method=POST path=/api/pushes12952026/10/07 06:12:12 INFO Aborted multipart uploads count=0 kept=012962026/10/07 06:12:12 INFO Completed push id=1 objects=9 duration=7.100883ms12972026/10/07 06:12:12 INFO Upload complete. (67ms)1298=== NAME TestClientMultipleUploads1299 client_integration_test.go:369: Uploaded 3 paths in 101.177055ms13002026/10/07 06:12:12 INFO Received push request method=POST path=/api/pushes13012026/10/07 06:12:12 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=01302--- PASS: TestClientMultipleUploads (0.74s)1303=== CONT TestReadRedirectKeepsNarinfoProxied13042026/10/07 06:12:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13052026/10/07 06:12:12 INFO Uploading 2l39zn96kdcsqm8hff6v5ccir31xjanm-unpinned-file.txt (128B)13062026/10/07 06:12:12 INFO Vacuumed table table=pending_closures13072026/10/07 06:12:12 INFO Received complete push request method=POST path=/api/pushes/1/complete13082026/10/07 06:12:12 INFO All 1 paths already cached13092026/10/07 06:12:12 INFO Vacuumed table table=pending_objects1310=== NAME TestClientIntegration1311 client_integration_test.go:312: Retrieved narinfo from S3:1312 StorePath: /build/TestClientIntegration1144534363/002/store/yychi8bihxqhww27b2h7f8vmkbbpj8cy-test-file.txt1313 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1314 Compression: zstd1315 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11316 NarSize: 1521317 References: 1318 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk113192026/10/07 06:12:12 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"13202026/10/07 06:12:12 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13212026/10/07 06:12:12 WARN Failed to register uploaded object key=2l39zn96kdcsqm8hff6v5ccir31xjanm.ls error="server returned 404: 404 page not found\n"1322=== NAME TestClientCADerivations1323 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2096861816/001/store/gz70nhh5qd1p3i7agian6kalpqqddh1a-ca-test13242026/10/07 06:12:12 INFO Signed narinfos id=2 count=113252026/10/07 06:12:12 INFO Uploading 1 narinfos1326=== NAME TestClientIntegration1327 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1328 client_integration_test.go:313: Decompressed .ls content (64 bytes):1329 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1330 client_integration_test.go:316: Testing garbage collection...13312026/10/07 06:12:12 INFO Vacuumed table table=multipart_uploads13322026/10/07 06:12:12 INFO Received uploads request method=POST path=/api/pending_closures13332026/10/07 06:12:12 INFO Received complete push request method=POST path=/api/pushes/2/complete13342026/10/07 06:12:12 INFO Vacuumed table table=closures13352026/10/07 06:12:12 WARN Failed to register uploaded object key=2l39zn96kdcsqm8hff6v5ccir31xjanm.narinfo error="server returned 404: 404 page not found\n"13362026/10/07 06:12:12 INFO Completed push id=1 objects=4 duration=8.868019ms13372026/10/07 06:12:12 INFO Received push request method=POST path=/api/pushes13382026/10/07 06:12:12 INFO Completed push id=2 objects=3 duration=2.552163ms13392026/10/07 06:12:12 INFO Vacuumed table table=objects13402026/10/07 06:12:12 INFO Upload complete. (53ms)13412026/10/07 06:12:12 INFO Received uploads request method=POST path=/api/pending_closures13422026/10/07 06:12:12 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001343--- PASS: TestService_createPendingClosureHandler (0.86s)1344=== CONT TestCreatePin_ReservedPins13452026/10/07 06:12:12 INFO Received push request method=POST path=/api/pushes13462026/10/07 06:12:12 INFO Received cleanup request method=DELETE path=/api/pending_closures1347=== NAME TestClientCADerivations1348 client_ca_test.go:139: Found 1 dependencies (including self)13492026/10/07 06:12:12 INFO Starting cleanup of old closures method=DELETE path=/api/closures13502026/10/07 06:12:12 INFO Garbage collection started13512026/10/07 06:12:12 INFO Starting cleanup of old closures method=DELETE path=/api/closures13522026/10/07 06:12:12 INFO Garbage collection started13532026/10/07 06:12:12 INFO Aborted multipart uploads count=0 kept=013542026/10/07 06:12:12 WARN Force mode enabled - objects will be deleted immediately without grace period13552026/10/07 06:12:12 INFO Aborted multipart uploads count=0 kept=013562026/10/07 06:12:12 WARN Force mode enabled - objects will be deleted immediately without grace period13572026-10-07 06:12:12.924 UTC [1337] ERROR: could not obtain lock on row in relation "closures"13582026-10-07 06:12:12.924 UTC [1337] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT13592026-10-07 06:12:12.925 UTC [1337] ERROR: could not obtain lock on row in relation "closures"13602026-10-07 06:12:12.925 UTC [1337] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT13612026-10-07 06:12:12.926 UTC [1337] ERROR: could not obtain lock on row in relation "closures"13622026-10-07 06:12:12.926 UTC [1337] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT13632026-10-07 06:12:12.926 UTC [1337] ERROR: could not obtain lock on row in relation "closures"13642026-10-07 06:12:12.926 UTC [1337] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT13652026/10/07 06:12:12 INFO Aborted multipart uploads count=0 kept=013662026-10-07 06:12:12.927 UTC [1337] ERROR: could not obtain lock on row in relation "closures"13672026-10-07 06:12:12.927 UTC [1337] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT13682026/10/07 06:12:12 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=013692026/10/07 06:12:12 WARN Force mode enabled - objects will be deleted immediately without grace period1370--- PASS: TestPush_RootsAreLockedInByteOrder (0.37s)1371=== CONT TestReadRedirectNar13722026/10/07 06:12:12 INFO Vacuumed table table=pending_closures13732026/10/07 06:12:12 INFO Received push request method=POST path=/api/pushes13742026/10/07 06:12:12 INFO Vacuumed table table=pending_objects13752026/10/07 06:12:12 INFO Vacuumed table table=multipart_uploads13762026/10/07 06:12:12 INFO Vacuumed table table=closures13772026/10/07 06:12:12 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=013782026/10/07 06:12:12 INFO Vacuumed table table=objects13792026/10/07 06:12:12 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=013802026/10/07 06:12:12 INFO Vacuumed table table=pending_closures13812026/10/07 06:12:12 INFO Vacuumed table table=pending_closures13822026/10/07 06:12:12 INFO Vacuumed table table=pending_objects13832026/10/07 06:12:12 INFO Vacuumed table table=multipart_uploads13842026/10/07 06:12:12 INFO Vacuumed table table=pending_objects13852026/10/07 06:12:12 INFO Vacuumed table table=closures13862026/10/07 06:12:12 INFO Vacuumed table table=multipart_uploads13872026/10/07 06:12:12 INFO Vacuumed table table=objects13882026/10/07 06:12:12 INFO Vacuumed table table=closures13892026/10/07 06:12:12 INFO Vacuumed table table=objects13902026/10/07 06:12:12 INFO Received complete push request method=POST path=/api/pushes/2/complete13912026/10/07 06:12:12 INFO Completed push id=2 objects=4 duration=3.470811ms1392--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.49s)1393=== CONT TestOrphanedObjectsGCStressTest13942026/10/07 06:12:12 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket1204274199/001/proxy.sock13952026/10/07 06:12:12 INFO Starting HTTP server address=127.0.0.1:4334313962026/10/07 06:12:12 WARN mTLS auth: subject not in bound subjects subject="CN=someone"13972026/10/07 06:12:12 INFO Shutdown signal received, draining in-flight requests timeout=10s1398--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.25s)1399=== CONT TestReadProxyDisabled14002026/10/07 06:12:12 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1401--- PASS: TestReadProxyNarinfo (0.40s)1402=== CONT TestOrphanedObjectsGC14032026/10/07 06:12:13 INFO Received push request method=POST path=/api/pushes14042026/10/07 06:12:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34681/oidc14052026/10/07 06:12:13 INFO Received push request method=POST path=/api/pushes14062026/10/07 06:12:13 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14072026/10/07 06:12:13 INFO Uploading gz70nhh5qd1p3i7agian6kalpqqddh1a-ca-test (144B)14082026/10/07 06:12:13 INFO Received complete push request method=POST path=/api/pushes/1/complete14092026/10/07 06:12:13 WARN Failed to register uploaded object key=log/jvnidbf9f7dhbivn20vg3hyxjyvqc1b2-ca-test.drv error="server returned 404: 404 page not found\n"14102026/10/07 06:12:13 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"14112026/10/07 06:12:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14122026/10/07 06:12:13 WARN Failed to register uploaded object key=gz70nhh5qd1p3i7agian6kalpqqddh1a.ls error="server returned 404: 404 page not found\n"14132026/10/07 06:12:13 INFO Signed narinfos id=1 count=114142026/10/07 06:12:13 INFO Uploading 1 narinfos14152026/10/07 06:12:13 INFO Received complete push request method=POST path=/api/pushes/1/complete14162026/10/07 06:12:13 WARN Failed to register uploaded object key=gz70nhh5qd1p3i7agian6kalpqqddh1a.narinfo error="server returned 404: 404 page not found\n"14172026/10/07 06:12:13 INFO Completed push id=1 objects=4 duration=8.247513ms1418--- PASS: TestPush_RepeatedRootCommitsOnce (0.29s)1419=== CONT TestReadProxyRootRedirectsToIndexHTML14202026/10/07 06:12:13 INFO Received push request method=POST path=/api/pushes14212026/10/07 06:12:13 INFO Completed push id=1 objects=4 duration=6.80488ms14222026/10/07 06:12:13 INFO Upload complete. (103ms)1423=== NAME TestClientCADerivations1424 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2096861816/001/store/gz70nhh5qd1p3i7agian6kalpqqddh1a-ca-test1425 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1426 Compression: zstd1427 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1428 NarSize: 1441429 References: 1430 Deriver: /build/TestClientCADerivations2096861816/001/store/jvnidbf9f7dhbivn20vg3hyxjyvqc1b2-ca-test.drv1431 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1432 client_ca_test.go:185: Checking for realisation files in S3...1433 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1434 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache14352026/10/07 06:12:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14362026/10/07 06:12:13 INFO Received push request method=POST path=/api/pushes14372026/10/07 06:12:13 INFO Received complete push request method=POST path=/api/pushes/1/complete14382026/10/07 06:12:13 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZTc0MjIyMGMtNjQ0NS00OTI3LTk1ZDMtZWUwNTVmNmI0OGY4LjMyODM0ODIxLTAwYTAtNDBhZi1hNzk5LWE1ZTIwODBjNGIyN3gxNzkxMzUzNTMyNjYwMzkxNzUx parts=1214392026/10/07 06:12:13 INFO Received uploads request method=POST path=/api/pending_closures1440--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.83s)1441=== CONT TestObjectStatsLargeCommit14422026/10/07 06:12:13 INFO Completed push id=1 objects=6 duration=10.094049ms1443--- PASS: TestPush_CompleteCommitsEveryRoot (0.34s)1444=== CONT TestReadProxyConditionalGet1445--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.33s)1446=== CONT TestObjectStatsTrigger1447--- PASS: TestReadRedirectUsesPublicS3URL (0.35s)1448=== CONT TestReadProxyOutlastsServerWriteTimeout1449--- PASS: TestPresentRefreshesOnlyStaleClosures (0.31s)1450=== CONT TestMetricsInventory14512026/10/07 06:12:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1452--- PASS: TestReadProxyRangeRequest (0.33s)1453=== CONT TestReadProxyHead1454=== NAME TestClientCADerivations1455 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1456 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1457 error: binary cache 's3://bucket44?endpoint=http://localhost:44685®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2096861816/001/store'1458 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11459--- PASS: TestClientCADerivations (0.82s)1460=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded14612026/10/07 06:12:13 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZTc0MjIyMGMtNjQ0NS00OTI3LTk1ZDMtZWUwNTVmNmI0OGY4LmJiZmMxZTIyLTZjOGQtNGY2Yi1hYzBkLTViYTI4NGRmMDk0ZngxNzkxMzUzNTMyNzQ4MDI2NDA3 parts=1214622026/10/07 06:12:13 INFO Received uploads request method=POST path=/api/pending_closures14632026/10/07 06:12:13 INFO Received uploads request method=POST path=/api/pending_closures1464--- PASS: TestPresentReportsOnlyClosureRoots (0.35s)1465=== CONT TestReadProxyInvalidPath1466--- PASS: TestReadRedirectKeepsNarinfoProxied (0.33s)1467=== CONT TestMultipartCleanup1468--- PASS: TestReadRedirectNar (0.27s)1469=== CONT TestReadProxy4041470--- PASS: TestReadProxyDisabled (0.24s)1471=== CONT TestServerTLSConfig1472=== RUN TestServerTLSConfig/no_client_CA1473=== PAUSE TestServerTLSConfig/no_client_CA1474=== RUN TestServerTLSConfig/missing_CA_file1475=== PAUSE TestServerTLSConfig/missing_CA_file1476=== RUN TestServerTLSConfig/not_a_PEM_file1477=== PAUSE TestServerTLSConfig/not_a_PEM_file1478=== CONT TestReadProxyNarStreaming14792026-10-07 06:12:13.256 UTC [1363] ERROR: Push does not exist: id=114802026-10-07 06:12:13.256 UTC [1363] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE14812026-10-07 06:12:13.256 UTC [1363] STATEMENT: SELECT commit_push($1)1482--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.56s)1483=== CONT TestService_NativeMTLS14842026/10/07 06:12:13 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14852026/10/07 06:12:13 WARN Refused reserved pin name=worker-x86_64-linux14862026/10/07 06:12:13 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14872026/10/07 06:12:13 INFO Received create pin request method=POST path=/api/pins/my-app14882026/10/07 06:12:13 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1489--- PASS: TestCreatePin_ReservedPins (0.42s)1490=== CONT TestReadProxyContentNegotiation1491--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.29s)1492=== CONT TestMetricsCommit14932026/10/07 06:12:13 INFO lead: released remote=192.0.2.1:12341494--- PASS: TestLeadEndsOnShutdown (1.80s)1495=== CONT TestService_AuthMiddleware_OIDC1496--- PASS: TestObjectStatsTrigger (0.29s)1497=== CONT TestUploadHandlersRejectInvalidKeys1498=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1499=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1500=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1501=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1502=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1503=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1504=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1505=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1506=== CONT TestService_ReadScope_PublicByDefault1507--- PASS: TestReadProxyConditionalGet (0.31s)1508=== CONT TestPendingClosureWriteTimeout1509=== RUN TestPendingClosureWriteTimeout/empty1510=== PAUSE TestPendingClosureWriteTimeout/empty1511=== RUN TestPendingClosureWriteTimeout/400_objects1512=== PAUSE TestPendingClosureWriteTimeout/400_objects1513=== RUN TestPendingClosureWriteTimeout/670k_objects1514=== PAUSE TestPendingClosureWriteTimeout/670k_objects1515=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1516=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1517=== CONT TestService_RequireScope_OIDC1518--- PASS: TestMetricsInventory (0.32s)1519=== CONT TestIsValidUploadKey1520=== RUN TestIsValidUploadKey/narinfo1521=== PAUSE TestIsValidUploadKey/narinfo1522=== RUN TestIsValidUploadKey/nar_zst1523=== PAUSE TestIsValidUploadKey/nar_zst1524=== RUN TestIsValidUploadKey/nar_xz1525=== PAUSE TestIsValidUploadKey/nar_xz1526=== RUN TestIsValidUploadKey/nar_plain1527=== PAUSE TestIsValidUploadKey/nar_plain1528=== RUN TestIsValidUploadKey/listing1529=== PAUSE TestIsValidUploadKey/listing1530=== RUN TestIsValidUploadKey/build_log1531=== PAUSE TestIsValidUploadKey/build_log1532=== RUN TestIsValidUploadKey/build_log_home-manager_file1533=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1534=== RUN TestIsValidUploadKey/build_log_plus_in_name1535=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1536=== RUN TestIsValidUploadKey/build_log_question_mark1537=== PAUSE TestIsValidUploadKey/build_log_question_mark1538=== RUN TestIsValidUploadKey/build_log_equals1539=== PAUSE TestIsValidUploadKey/build_log_equals1540=== RUN TestIsValidUploadKey/realisation1541=== PAUSE TestIsValidUploadKey/realisation1542=== RUN TestIsValidUploadKey/realisation_plus_in_output1543=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1544=== RUN TestIsValidUploadKey/nix-cache-info1545=== PAUSE TestIsValidUploadKey/nix-cache-info1546=== RUN TestIsValidUploadKey/index.html1547=== PAUSE TestIsValidUploadKey/index.html1548=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1549=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1550=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1551=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1552=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1553=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1554=== RUN TestIsValidUploadKey/traversal1555=== PAUSE TestIsValidUploadKey/traversal1556=== RUN TestIsValidUploadKey/traversal_nar1557=== PAUSE TestIsValidUploadKey/traversal_nar1558=== RUN TestIsValidUploadKey/absolute1559=== PAUSE TestIsValidUploadKey/absolute1560=== RUN TestIsValidUploadKey/empty_key1561=== PAUSE TestIsValidUploadKey/empty_key1562=== RUN TestIsValidUploadKey/unknown_type1563=== PAUSE TestIsValidUploadKey/unknown_type1564=== CONT TestProxyWriteTimeout1565=== RUN TestProxyWriteTimeout/narinfo1566=== PAUSE TestProxyWriteTimeout/narinfo1567=== RUN TestProxyWriteTimeout/1_GiB_nar1568=== PAUSE TestProxyWriteTimeout/1_GiB_nar1569=== RUN TestProxyWriteTimeout/10_GiB_nar1570=== PAUSE TestProxyWriteTimeout/10_GiB_nar1571=== RUN TestProxyWriteTimeout/unknown_size1572=== PAUSE TestProxyWriteTimeout/unknown_size1573=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15742026/10/07 06:12:13 INFO Received uploads request method=POST path=/api/pending_closures1575--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.31s)1576=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1577--- PASS: TestReadProxyHead (0.33s)1578=== CONT TestCacheConfigHandlerMaxNarSize1579--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1580=== CONT TestService_ReadAuthMiddleware1581--- PASS: TestReadProxyInvalidPath (0.34s)1582=== CONT TestNARDeduplicationMetadataUploadBug15832026/10/07 06:12:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37039/oidc15842026/10/07 06:12:13 INFO lead: released remote=192.0.2.1:123415852026/10/07 06:12:13 INFO Received uploads request method=POST path=/api/pending_closures15862026/10/07 06:12:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43087/oidc15872026/10/07 06:12:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15882026/10/07 06:12:13 INFO lead: acquired remote=192.0.2.1:123415892026/10/07 06:12:13 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZTc0MjIyMGMtNjQ0NS00OTI3LTk1ZDMtZWUwNTVmNmI0OGY4LjE5NTI5NGExLTZiNDUtNDMwYy05ZmU5LWRlM2UyOGUzZTdhNHgxNzkxMzUzNTMzMTYxMDA5ODQx error="Get \"http://127.0.0.1:1/bucket43/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"15902026/10/07 06:12:13 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZTc0MjIyMGMtNjQ0NS00OTI3LTk1ZDMtZWUwNTVmNmI0OGY4LmVkMDQ1Y2QxLTllM2MtNDNhYS1hMWMwLTZmMmY4NzQxYzUwZHgxNzkxMzUzNTMzMTU0NDMwMzQz parts=1215912026/10/07 06:12:13 INFO Received cleanup request method=DELETE path=/api/pending_closures15922026/10/07 06:12:13 INFO Aborted multipart uploads count=1 kept=01593--- PASS: TestReadProxy404 (0.36s)1594=== CONT TestCreatePendingClosureRejectsOversizedNAR15952026/10/07 06:12:13 INFO Received uploads request method=POST path=/api/pending_closures1596--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1597=== CONT TestService_AuthMiddleware_MTLSProxyHeader1598--- PASS: TestRedundantMultipartUpload (1.25s)1599=== CONT TestService_readinessHandler1600--- PASS: TestReadProxyNarStreaming (0.35s)1601=== CONT TestService_healthCheckHandler16022026/10/07 06:12:13 WARN mTLS auth: subject not in bound subjects subject="CN=reader"16032026/10/07 06:12:13 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1604--- PASS: TestService_NativeMTLS (0.33s)1605=== CONT TestGenerateLandingPage1606--- PASS: TestGenerateLandingPage (0.00s)1607=== CONT TestGCEndsOnShutdown/before_the_run1608=== NAME TestOrphanedObjectsGC1609 orphaned_objects_gc_test.go:287: GC Test Summary:1610 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1611 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1612 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1613 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1614 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1615--- PASS: TestOrphanedObjectsGC (0.60s)1616=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark16172026/10/07 06:12:13 INFO Received cleanup request method=DELETE path=/api/pending_closures16182026/10/07 06:12:13 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket75/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""16192026/10/07 06:12:13 INFO Aborted multipart uploads count=0 kept=116202026/10/07 06:12:13 INFO Received cleanup request method=DELETE path=/api/pending_closures16212026/10/07 06:12:13 INFO Received push request method=POST path=/api/pushes16222026/10/07 06:12:13 INFO Aborted multipart uploads count=1 kept=01623--- PASS: TestMultipartCleanup (0.46s)1624=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete16252026/10/07 06:12:13 INFO Received complete push request method=POST path=/api/pushes/1/complete1626--- PASS: TestService_ReadScope_PublicByDefault (0.29s)1627=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows16282026/10/07 06:12:13 INFO Completed push id=1 objects=4 duration=6.875421ms16292026/10/07 06:12:13 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16302026/10/07 06:12:13 INFO Completed upload id=2 objects=2 duration=2.246879ms1631--- PASS: TestReadProxyContentNegotiation (0.37s)1632=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1633--- PASS: TestMetricsCommit (0.36s)1634=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16352026/10/07 06:12:13 INFO Received uploads request method=POST path=/16362026/10/07 06:12:13 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16372026/10/07 06:12:13 WARN mTLS auth: bound subjects configured but subject DN unavailable16382026/10/07 06:12:13 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1639--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.25s)1640=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16412026/10/07 06:12:13 INFO Received request for more parts method=POST path=/16422026/10/07 06:12:13 INFO Received uploads request method=POST path=/api/pending_closures1643--- PASS: TestService_ReadAuthMiddleware (0.26s)1644=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16452026/10/07 06:12:13 INFO Received complete multipart upload request method=POST path=/1646--- PASS: TestDeleteClosuresRacingPins (1.76s)1647=== CONT TestResolveDBConnectionString/flag_wins1648=== CONT TestResolveDBConnectionString/nothing_configured1649=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1650=== CONT TestResolveDBConnectionString/missing_file_is_an_error1651=== CONT TestResolveDBConnectionString/file_when_flag_empty1652--- PASS: TestResolveDBConnectionString (0.00s)1653 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1654 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1655 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1656 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1657 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1658=== CONT TestCacheConfigHandler/full_config,_no_issuer1659=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1660=== CONT TestCacheConfigHandler/no_cache_url_configured1661=== CONT TestCacheConfigHandler/no_signing_keys1662--- PASS: TestCacheConfigHandler (0.00s)1663 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1664 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1665 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1666 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1667=== CONT TestClientErrorHandling/InvalidStorePath1668=== CONT TestClientErrorHandling/ServerNotAvailable16692026/10/07 06:12:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1670=== NAME TestNARDeduplicationMetadataUploadBug1671 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3870221720/001/store/s80s149ywclwrvyyqzrm4rvvl7km7dms-file1.txt1672=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1673=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1674=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1675=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1676=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1677=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1678=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1679=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1680=== CONT TestClientErrorHandling/InvalidAuthToken1681=== RUN TestService_RequireScope_OIDC/builder_may_write1682=== PAUSE TestService_RequireScope_OIDC/builder_may_write1683=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1684=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1685=== RUN TestService_RequireScope_OIDC/ops_may_admin1686=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1687=== RUN TestService_RequireScope_OIDC/ops_may_not_write1688=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1689=== RUN TestService_RequireScope_OIDC/reader_may_not_write1690=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1691=== RUN TestService_RequireScope_OIDC/static_token_may_admin1692=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1693=== RUN TestService_RequireScope_OIDC/static_token_may_write1694=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1695=== RUN TestService_RequireScope_OIDC/reader_may_read1696=== PAUSE TestService_RequireScope_OIDC/reader_may_read1697=== RUN TestService_RequireScope_OIDC/writer_implies_read1698=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1699=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1700=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1701=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1702=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1703=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1704=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1705=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1706=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1707=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1708=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1709=== CONT TestIsValidCachePath/narinfo1710=== CONT TestIsValidCachePath/index.html1711=== CONT TestIsValidCachePath/short_hash1712=== CONT TestIsValidCachePath/wrong_extension1713=== CONT TestIsValidCachePath/leading_slash1714=== CONT TestIsValidCachePath/empty1715=== CONT TestIsValidCachePath/random_path1716=== CONT TestIsValidCachePath/invalid_char_u1717=== CONT TestIsValidCachePath/invalid_char_e1718=== CONT TestIsValidCachePath/traversal_in_middle1719=== CONT TestIsValidCachePath/traversal_parent1720=== CONT TestIsValidCachePath/nar_uncompressed1721=== CONT TestIsValidCachePath/nix-cache-info1722=== CONT TestIsValidCachePath/realisation1723=== CONT TestIsValidCachePath/log1724=== CONT TestIsValidCachePath/ls1725=== CONT TestIsValidCachePath/nar_xz1726=== CONT TestIsValidCachePath/nar_bz21727=== CONT TestIsValidCachePath/nar_zst1728=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1729--- PASS: TestIsValidCachePath (0.00s)1730 --- PASS: TestIsValidCachePath/narinfo (0.00s)1731 --- PASS: TestIsValidCachePath/index.html (0.00s)1732 --- PASS: TestIsValidCachePath/short_hash (0.00s)1733 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1734 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1735 --- PASS: TestIsValidCachePath/empty (0.00s)1736 --- PASS: TestIsValidCachePath/random_path (0.00s)1737 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1738 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1739 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1740 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1741 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1742 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1743 --- PASS: TestIsValidCachePath/realisation (0.00s)1744 --- PASS: TestIsValidCachePath/log (0.00s)1745 --- PASS: TestIsValidCachePath/ls (0.00s)1746 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1747 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1748 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1749 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1750=== CONT TestParseSingleRange/none1751=== CONT TestParseSingleRange/start_far_past_EOF1752=== CONT TestParseSingleRange/start_past_EOF1753=== CONT TestParseSingleRange/single_byte1754=== CONT TestParseSingleRange/suffix_exceeds_size1755=== CONT TestParseSingleRange/suffix1756=== CONT TestParseSingleRange/end_clamped_to_size1757=== CONT TestParseSingleRange/open-ended1758=== CONT TestParseSingleRange/closed1759=== CONT TestParseSingleRange/malformed_end_before_start1760=== CONT TestParseSingleRange/malformed_both_empty1761=== CONT TestParseSingleRange/malformed_no_dash1762=== CONT TestParseSingleRange/multi-range_ignored1763=== CONT TestParseSingleRange/unknown_unit1764--- PASS: TestParseSingleRange (0.00s)1765 --- PASS: TestParseSingleRange/none (0.00s)1766 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1767 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1768 --- PASS: TestParseSingleRange/single_byte (0.00s)1769 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1770 --- PASS: TestParseSingleRange/suffix (0.00s)1771 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1772 --- PASS: TestParseSingleRange/open-ended (0.00s)1773 --- PASS: TestParseSingleRange/closed (0.00s)1774 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1775 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1776 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1777 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1778 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1779=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1780=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1781--- PASS: TestService_healthCheckHandler (0.24s)1782=== CONT TestPush_RejectsBadRequests/no_objects17832026/10/07 06:12:13 INFO Received push request method=POST path=/api/pushes1784=== CONT TestPush_RejectsBadRequests/no_roots17852026/10/07 06:12:13 INFO Received push request method=POST path=/api/pushes1786=== CONT TestPush_RejectsBadRequests/root_not_in_objects17872026/10/07 06:12:13 INFO Received push request method=POST path=/api/pushes1788=== CONT TestPush_RejectsBadRequests/bad_root17892026/10/07 06:12:13 INFO Received push request method=POST path=/api/pushes1790=== CONT TestServerTLSConfig/no_client_CA1791=== CONT TestServerTLSConfig/not_a_PEM_file1792--- PASS: TestPush_RejectsBadRequests (0.42s)1793 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1794 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1795 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1796 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1797=== CONT TestServerTLSConfig/missing_CA_file1798=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17992026/10/07 06:12:13 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/present18002026/10/07 06:12:13 INFO Received uploads request method=POST path=/1801--- PASS: TestServerTLSConfig (0.00s)1802 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1803 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1804 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1805=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18062026/10/07 06:12:13 INFO Received complete multipart upload request method=POST path=/1807=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18082026/10/07 06:12:13 INFO Received request for more parts method=POST path=/1809=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18102026/10/07 06:12:13 INFO Received uploads request method=POST path=/1811--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1812 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1813 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1814 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1815 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1816=== CONT TestPendingClosureWriteTimeout/empty1817=== CONT TestPendingClosureWriteTimeout/670k_objects1818=== CONT TestPendingClosureWriteTimeout/400_objects1819=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1820--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.27s)1821=== CONT TestIsValidUploadKey/narinfo1822=== CONT TestIsValidUploadKey/realisation_plus_in_output1823=== CONT TestIsValidUploadKey/unknown_type1824=== CONT TestIsValidUploadKey/empty_key1825=== CONT TestIsValidUploadKey/absolute1826=== CONT TestIsValidUploadKey/traversal_nar1827=== CONT TestIsValidUploadKey/traversal1828=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1829=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1830=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1831=== CONT TestIsValidUploadKey/index.html1832=== CONT TestIsValidUploadKey/nix-cache-info1833=== CONT TestIsValidUploadKey/build_log_home-manager_file1834=== CONT TestIsValidUploadKey/realisation1835=== CONT TestIsValidUploadKey/build_log_equals1836=== CONT TestIsValidUploadKey/build_log_question_mark1837=== CONT TestIsValidUploadKey/build_log_plus_in_name1838=== CONT TestIsValidUploadKey/nar_plain1839=== CONT TestIsValidUploadKey/build_log1840=== CONT TestIsValidUploadKey/listing1841=== CONT TestIsValidUploadKey/nar_xz1842=== CONT TestIsValidUploadKey/nar_zst1843--- PASS: TestIsValidUploadKey (0.00s)1844 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1845 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1846 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1847 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1848 --- PASS: TestIsValidUploadKey/absolute (0.00s)1849 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1850 --- PASS: TestIsValidUploadKey/traversal (0.00s)1851 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1852 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1853 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1854 --- PASS: TestIsValidUploadKey/index.html (0.00s)1855 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1856 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1857 --- PASS: TestIsValidUploadKey/realisation (0.00s)1858 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1859 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1860 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1861 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1862 --- PASS: TestIsValidUploadKey/build_log (0.00s)1863 --- PASS: TestIsValidUploadKey/listing (0.00s)1864 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1865 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1866=== CONT TestProxyWriteTimeout/narinfo1867=== CONT TestProxyWriteTimeout/10_GiB_nar1868=== CONT TestProxyWriteTimeout/unknown_size1869=== CONT TestProxyWriteTimeout/1_GiB_nar1870--- PASS: TestProxyWriteTimeout (0.00s)1871 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1872 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1873 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1874 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1875=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1876=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18772026/10/07 06:12:13 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]1878=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18792026/10/07 06:12:13 WARN Authentication failed token_preview=eyJhbGciOi...QAZeCkQGQA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1880=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1881=== CONT TestService_RequireScope_OIDC/builder_may_write1882--- PASS: TestService_AuthMiddleware_OIDC (0.47s)1883 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1884 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1885 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1886 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1887=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1888=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18892026/10/07 06:12:13 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]1890=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1891=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1892=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1893=== CONT TestService_RequireScope_OIDC/writer_implies_read1894=== CONT TestService_RequireScope_OIDC/reader_may_read1895=== CONT TestService_RequireScope_OIDC/static_token_may_write1896=== CONT TestService_RequireScope_OIDC/static_token_may_admin1897=== CONT TestService_RequireScope_OIDC/reader_may_not_write1898=== CONT TestService_RequireScope_OIDC/ops_may_not_write1899=== CONT TestService_RequireScope_OIDC/ops_may_admin1900=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1901--- PASS: TestService_RequireScope_OIDC (0.41s)1902 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1903 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1904 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1905 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1906 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1907 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1908 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1909 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1910 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1911 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1912 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1913 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1914 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1915 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)19162026/10/07 06:12:13 WARN readiness check failed error="closed pool"1917--- PASS: TestService_readinessHandler (0.28s)19182026/10/07 06:12:13 INFO Received push request method=POST path=/api/pushes19192026/10/07 06:12:13 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19202026/10/07 06:12:13 INFO Uploading s80s149ywclwrvyyqzrm4rvvl7km7dms-file1.txt (160B)19212026/10/07 06:12:13 WARN Failed to register uploaded object key=s80s149ywclwrvyyqzrm4rvvl7km7dms.ls error="server returned 404: 404 page not found\n"19222026/10/07 06:12:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19232026/10/07 06:12:13 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"19242026/10/07 06:12:13 INFO Signed narinfos id=1 count=119252026/10/07 06:12:13 INFO Uploading 1 narinfos19262026/10/07 06:12:13 INFO Received complete push request method=POST path=/api/pushes/1/complete19272026/10/07 06:12:13 WARN Failed to register uploaded object key=s80s149ywclwrvyyqzrm4rvvl7km7dms.narinfo error="server returned 404: 404 page not found\n"19282026/10/07 06:12:13 INFO Completed push id=1 objects=3 duration=5.303667ms19292026/10/07 06:12:13 INFO Upload complete. (58ms)1930=== NAME TestNARDeduplicationMetadataUploadBug1931 metadata_upload_test.go:54: Retrieved narinfo from S3:1932 StorePath: /build/TestNARDeduplicationMetadataUploadBug3870221720/001/store/s80s149ywclwrvyyqzrm4rvvl7km7dms-file1.txt1933 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1934 Compression: zstd1935 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1936 NarSize: 1601937 References: 1938 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1939 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1940 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1941 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}19422026/10/07 06:12:13 INFO Aborted multipart uploads count=0 kept=019432026/10/07 06:12:13 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=183.026812ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19442026/10/07 06:12:13 WARN Force mode enabled - objects will be deleted immediately without grace period19452026/10/07 06:12:13 INFO Aborted multipart uploads count=0 kept=01946 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3870221720/001/store/hmqnws5ap0cw59cxwcb0l40dirh33wli-file2.txt19472026/10/07 06:12:13 WARN Force mode enabled - objects will be deleted immediately without grace period19482026/10/07 06:12:13 INFO Received uploads request method=POST path=/api/pending_closures19492026/10/07 06:12:13 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:44685/bucket93/?delete=\": context canceled"1950--- PASS: TestGCEndsOnShutdown (0.00s)1951 --- PASS: TestGCEndsOnShutdown/before_the_run (0.29s)1952 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.33s)1953 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.29s)19542026/10/07 06:12:13 INFO Aborted multipart uploads count=0 kept=019552026/10/07 06:12:13 WARN Force mode enabled - objects will be deleted immediately without grace period19562026/10/07 06:12:13 INFO Received uploads request method=POST path=/api/pending_closures19572026/10/07 06:12:13 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=019582026/10/07 06:12:13 INFO Vacuumed table table=pending_closures19592026/10/07 06:12:13 INFO Vacuumed table table=pending_objects19602026/10/07 06:12:13 INFO Vacuumed table table=multipart_uploads19612026/10/07 06:12:13 INFO Vacuumed table table=closures19622026/10/07 06:12:13 INFO Vacuumed table table=objects19632026/10/07 06:12:13 INFO Aborted multipart uploads count=0 kept=019642026/10/07 06:12:13 WARN Force mode enabled - objects will be deleted immediately without grace period19652026/10/07 06:12:13 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=019662026/10/07 06:12:13 INFO Vacuumed table table=pending_closures19672026/10/07 06:12:13 INFO Vacuumed table table=pending_objects19682026/10/07 06:12:13 INFO Vacuumed table table=multipart_uploads19692026/10/07 06:12:13 INFO Vacuumed table table=closures19702026/10/07 06:12:13 INFO Vacuumed table table=objects1971--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1972 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.31s)1973 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.31s)19742026/10/07 06:12:13 INFO Received push request method=POST path=/api/pushes19752026/10/07 06:12:13 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19762026/10/07 06:12:13 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign19772026/10/07 06:12:13 WARN Failed to register uploaded object key=hmqnws5ap0cw59cxwcb0l40dirh33wli.ls error="server returned 404: 404 page not found\n"19782026/10/07 06:12:13 INFO Signed narinfos id=2 count=119792026/10/07 06:12:13 INFO Uploading 1 narinfos19802026/10/07 06:12:13 INFO Received complete push request method=POST path=/api/pushes/2/complete19812026/10/07 06:12:13 WARN Failed to register uploaded object key=hmqnws5ap0cw59cxwcb0l40dirh33wli.narinfo error="server returned 404: 404 page not found\n"19822026/10/07 06:12:14 INFO Completed push id=2 objects=3 duration=1.950357ms19832026/10/07 06:12:14 INFO Upload complete. (48ms)1984=== NAME TestNARDeduplicationMetadataUploadBug1985 metadata_upload_test.go:76: Retrieved narinfo from S3:1986 StorePath: /build/TestNARDeduplicationMetadataUploadBug3870221720/001/store/hmqnws5ap0cw59cxwcb0l40dirh33wli-file2.txt1987 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1988 Compression: zstd1989 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1990 NarSize: 1601991 References: 1992 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1993 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1994 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1995 {"version":1,"root":{"type":"regular","size":44}}1996--- PASS: TestNARDeduplicationMetadataUploadBug (0.51s)19972026/10/07 06:12:14 INFO Received uploads request method=POST path=/api/pending_closures19982026/10/07 06:12:14 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19992026/10/07 06:12:14 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20002026/10/07 06:12:14 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=378.19699ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2001--- PASS: TestObjectStatsLargeCommit (1.20s)20022026/10/07 06:12:14 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=785.719536ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2003--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2004 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.71s)2005 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.72s)2006=== NAME TestOrphanedObjectsGCStressTest2007 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2008 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion20092026/10/07 06:12:14 INFO lead: released remote=192.0.2.1:12342010--- PASS: TestLeadElectsOneAndHandsOver (3.13s)2011=== NAME TestOrphanedObjectsGCStressTest2012 orphaned_objects_gc_test.go:503: Stress test completed successfully:2013 orphaned_objects_gc_test.go:504: - Active objects preserved: 202014 orphaned_objects_gc_test.go:505: - Objects deleted: 2102015 orphaned_objects_gc_test.go:506: - Total GC'd: 2102016--- PASS: TestOrphanedObjectsGCStressTest (1.79s)2017--- PASS: TestUploadHandlersRejectOversizedBody (0.14s)2018 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)2019 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)2020 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.10s)2021--- PASS: TestPendingClosureWriteTimeout (0.00s)2022 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2023 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2024 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2025 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.02s)20262026/10/07 06:12:14 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02027=== NAME TestClientIntegration2028 client_integration_test.go:323: Objects in database after GC:2029 client_integration_test.go:323: Successfully deleted all objects with GC --force2030--- PASS: TestClientIntegration (2.62s)20312026/10/07 06:12:14 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020322026/10/07 06:12:14 INFO Received create pin request method=POST path=/api/pins/myapp20332026/10/07 06:12:14 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC752986200/001/store/9c92i2kl8mfyrxvp9ln3cj2v9vr9gil6-pinned-file.txt narinfo_key=9c92i2kl8mfyrxvp9ln3cj2v9vr9gil6.narinfo20342026/10/07 06:12:14 INFO Starting cleanup of old closures method=DELETE path=/api/closures20352026/10/07 06:12:14 INFO Garbage collection started20362026/10/07 06:12:14 INFO Aborted multipart uploads count=0 kept=020372026/10/07 06:12:14 WARN Force mode enabled - objects will be deleted immediately without grace period20382026/10/07 06:12:14 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=020392026/10/07 06:12:14 INFO Vacuumed table table=pending_closures20402026/10/07 06:12:14 INFO Vacuumed table table=pending_objects20412026/10/07 06:12:14 INFO Vacuumed table table=multipart_uploads20422026/10/07 06:12:14 INFO Vacuumed table table=closures20432026/10/07 06:12:14 INFO Vacuumed table table=objects20442026/10/07 06:12:15 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.494878974s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20452026/10/07 06:12:16 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-config20462026/10/07 06:12:16 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=202.610385ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2047--- PASS: TestConnectWaitsForAPeerMigration (5.17s)2048=== NAME TestPinProtectsFromGC2049 client_integration_test.go:840: Pin successfully protected closure from garbage collection2050--- PASS: TestPinProtectsFromGC (4.81s)20512026/10/07 06:12:16 WARN Rate limiter enabled after throttle name=s3-test rate=520522026/10/07 06:12:16 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2053=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2054 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102055 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002056--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (3.54s)20572026/10/07 06:12:17 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=437.019039ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20582026/10/07 06:12:17 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=811.198387ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2059--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.51s)20602026/10/07 06:12:18 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.758132319s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20612026/10/07 06:12:18 INFO Aborted multipart uploads count=1 kept=020622026/10/07 06:12:18 INFO Received cleanup request method=DELETE path=/api/pending_closures20632026/10/07 06:12:18 INFO Aborted multipart uploads count=1 kept=02064--- PASS: TestPendingCleanupUsesOneCutoff (6.37s)20652026/10/07 06:12:20 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"20662026/10/07 06:12:20 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-config20672026/10/07 06:12:20 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=199.217543ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20682026/10/07 06:12:20 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=366.199365ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20692026/10/07 06:12:20 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=782.225136ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20702026/10/07 06:12:21 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.470310746s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20712026/10/07 06:12:23 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_closures20722026/10/07 06:12:23 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=190.157449ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20732026/10/07 06:12:23 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=416.170824ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20742026/10/07 06:12:23 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=736.308347ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20752026/10/07 06:12:24 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.685931249s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2076--- PASS: TestClientErrorHandling (0.00s)2077 --- PASS: TestClientErrorHandling/InvalidStorePath (0.26s)2078 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.29s)2079 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.43s)2080PASS20812026-10-07 06:12:26.420 UTC [129] LOG: received smart shutdown request20822026-10-07 06:12:26.424 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 120832026-10-07 06:12:26.436 UTC [134] LOG: shutting down20842026-10-07 06:12:26.436 UTC [134] LOG: checkpoint starting: shutdown immediate20852026-10-07 06:12:27.263 UTC [134] LOG: checkpoint complete: wrote 11245 buffers (68.6%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.184 s, sync=0.609 s, total=0.827 s; sync files=34046, longest=0.007 s, average=0.001 s; distance=531554 kB, estimate=531554 kB; lsn=0/21E7E600, redo lsn=0/21E7E60020862026-10-07 06:12:27.336 UTC [129] LOG: database system is shut down2087Running OIDC tests...2088=== RUN TestAudienceForIssuer2089=== PAUSE TestAudienceForIssuer2090=== RUN TestGlobMatch2091=== PAUSE TestGlobMatch2092=== RUN TestValidateToken_ValidToken2093=== PAUSE TestValidateToken_ValidToken2094=== RUN TestValidateToken_WrongAudience2095=== PAUSE TestValidateToken_WrongAudience2096=== RUN TestValidateToken_Expired2097=== PAUSE TestValidateToken_Expired2098=== RUN TestValidateToken_BoundClaimsMismatch2099=== PAUSE TestValidateToken_BoundClaimsMismatch2100=== RUN TestValidateToken_BoundSubjectMismatch2101=== PAUSE TestValidateToken_BoundSubjectMismatch2102=== RUN TestValidateToken_MultipleProviders2103=== PAUSE TestValidateToken_MultipleProviders2104=== RUN TestValidateToken_NoMatchingProvider2105=== PAUSE TestValidateToken_NoMatchingProvider2106=== RUN TestValidateToken_KubernetesServiceAccount2107=== PAUSE TestValidateToken_KubernetesServiceAccount2108=== RUN TestNewValidator_KubernetesRequiresCA2109=== PAUSE TestNewValidator_KubernetesRequiresCA2110=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2111=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2112=== RUN TestPins_ReservedForMatchingRule2113=== PAUSE TestPins_ReservedForMatchingRule2114=== RUN TestPins_TopLevelShorthand2115=== PAUSE TestPins_TopLevelShorthand2116=== RUN TestPins_ConfigValidation2117=== PAUSE TestPins_ConfigValidation2118=== RUN TestScopes_LegacyProviderDefaultsToWrite2119=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2120=== RUN TestScopes_Rules2121=== PAUSE TestScopes_Rules2122=== RUN TestScopes_ConfigValidation2123=== PAUSE TestScopes_ConfigValidation2124=== CONT TestAudienceForIssuer2125--- PASS: TestAudienceForIssuer (0.00s)2126=== CONT TestPins_ConfigValidation2127=== CONT TestScopes_Rules2128=== CONT TestValidateToken_KubernetesServiceAccount2129=== CONT TestPins_TopLevelShorthand2130=== CONT TestValidateToken_NoMatchingProvider2131=== CONT TestPins_ReservedForMatchingRule2132=== CONT TestValidateToken_MultipleProviders2133=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2134=== CONT TestValidateToken_BoundSubjectMismatch2135=== CONT TestValidateToken_BoundClaimsMismatch2136=== CONT TestNewValidator_KubernetesRequiresCA2137=== CONT TestValidateToken_Expired2138=== CONT TestValidateToken_WrongAudience2139=== CONT TestValidateToken_ValidToken2140=== CONT TestScopes_LegacyProviderDefaultsToWrite2141=== CONT TestGlobMatch2142=== RUN TestGlobMatch/foo_foo2143=== PAUSE TestGlobMatch/foo_foo2144=== RUN TestGlobMatch/foo_bar2145=== PAUSE TestGlobMatch/foo_bar2146=== RUN TestGlobMatch/*_2147=== PAUSE TestGlobMatch/*_2148=== RUN TestGlobMatch/*_anything2149=== PAUSE TestGlobMatch/*_anything2150=== RUN TestGlobMatch/foo*_foo2151=== PAUSE TestGlobMatch/foo*_foo2152=== RUN TestGlobMatch/foo*_foobar2153=== PAUSE TestGlobMatch/foo*_foobar2154=== RUN TestGlobMatch/foo*_bar2155=== CONT TestScopes_ConfigValidation2156--- PASS: TestPins_ConfigValidation (0.00s)2157=== PAUSE TestGlobMatch/foo*_bar2158=== RUN TestGlobMatch/*bar_bar2159=== PAUSE TestGlobMatch/*bar_bar2160=== RUN TestGlobMatch/*bar_foobar2161=== PAUSE TestGlobMatch/*bar_foobar2162=== RUN TestGlobMatch/*bar_foo2163=== PAUSE TestGlobMatch/*bar_foo2164=== RUN TestGlobMatch/foo*bar_foobar2165=== PAUSE TestGlobMatch/foo*bar_foobar2166=== RUN TestGlobMatch/foo*bar_foo123bar2167=== PAUSE TestGlobMatch/foo*bar_foo123bar2168=== RUN TestGlobMatch/foo*bar_foobarbaz2169=== PAUSE TestGlobMatch/foo*bar_foobarbaz2170=== RUN TestGlobMatch/*/*_foo/bar2171=== PAUSE TestGlobMatch/*/*_foo/bar2172=== RUN TestGlobMatch/*/*_foo2173=== PAUSE TestGlobMatch/*/*_foo2174=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2175=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2176=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02177=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02178=== RUN TestGlobMatch/refs/*/main_refs/heads/main2179=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2180=== RUN TestGlobMatch/fo?_foo2181=== PAUSE TestGlobMatch/fo?_foo2182=== RUN TestGlobMatch/fo?_fo2183=== PAUSE TestGlobMatch/fo?_fo2184=== RUN TestGlobMatch/fo?_fooo2185=== PAUSE TestGlobMatch/fo?_fooo2186=== RUN TestGlobMatch/?oo_foo2187=== PAUSE TestGlobMatch/?oo_foo2188=== RUN TestGlobMatch/?oo_boo2189=== PAUSE TestGlobMatch/?oo_boo2190=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2191=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2192=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2193=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2194=== CONT TestGlobMatch/foo_foo2195=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2196=== CONT TestGlobMatch/?oo_boo2197=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2198=== CONT TestGlobMatch/foo*bar_foo123bar2199=== CONT TestGlobMatch/foo*_foo2200=== CONT TestGlobMatch/*_anything2201--- PASS: TestScopes_ConfigValidation (0.00s)2202=== CONT TestGlobMatch/?oo_foo2203=== CONT TestGlobMatch/refs/*/main_refs/heads/main2204=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02205=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2206=== CONT TestGlobMatch/*/*_foo2207=== CONT TestGlobMatch/*/*_foo/bar2208=== CONT TestGlobMatch/foo*bar_foobarbaz2209=== CONT TestGlobMatch/*_2210=== CONT TestGlobMatch/foo_bar2211=== CONT TestGlobMatch/*bar_foo2212=== CONT TestGlobMatch/*bar_foobar2213=== CONT TestGlobMatch/*bar_bar2214=== CONT TestGlobMatch/foo*_bar2215=== CONT TestGlobMatch/foo*_foobar2216=== CONT TestGlobMatch/fo?_fooo2217=== CONT TestGlobMatch/fo?_fo2218=== CONT TestGlobMatch/fo?_foo2219=== CONT TestGlobMatch/foo*bar_foobar2220--- PASS: TestGlobMatch (0.00s)2221 --- PASS: TestGlobMatch/foo_foo (0.00s)2222 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2223 --- PASS: TestGlobMatch/?oo_boo (0.00s)2224 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2225 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2226 --- PASS: TestGlobMatch/foo*_foo (0.00s)2227 --- PASS: TestGlobMatch/*_anything (0.00s)2228 --- PASS: TestGlobMatch/?oo_foo (0.00s)2229 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2230 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2231 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2232 --- PASS: TestGlobMatch/*/*_foo (0.00s)2233 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2234 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2235 --- PASS: TestGlobMatch/*_ (0.00s)2236 --- PASS: TestGlobMatch/foo_bar (0.00s)2237 --- PASS: TestGlobMatch/*bar_foo (0.00s)2238 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2239 --- PASS: TestGlobMatch/*bar_bar (0.00s)2240 --- PASS: TestGlobMatch/foo*_bar (0.00s)2241 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2242 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2243 --- PASS: TestGlobMatch/fo?_fo (0.00s)2244 --- PASS: TestGlobMatch/fo?_foo (0.00s)2245 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)22462026/10/07 06:12:29 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:338172247--- PASS: TestValidateToken_KubernetesServiceAccount (0.04s)22482026/10/07 06:12:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46607/oidc2249--- PASS: TestValidateToken_BoundClaimsMismatch (0.04s)22502026/10/07 06:12:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42395/oidc2251--- PASS: TestValidateToken_WrongAudience (0.06s)22522026/10/07 06:12:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46157/oidc2253--- PASS: TestValidateToken_BoundSubjectMismatch (0.08s)22542026/10/07 06:12:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42555/oidc2255--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.08s)22562026/10/07 06:12:29 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12322572026/10/07 06:12:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42721/oidc2258--- PASS: TestValidateToken_Expired (0.15s)2259--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.16s)22602026/10/07 06:12:29 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:45143/oidc22612026/10/07 06:12:29 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:46739/oidc22622026/10/07 06:12:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38947/oidc2263--- PASS: TestValidateToken_MultipleProviders (0.17s)2264--- PASS: TestPins_TopLevelShorthand (0.17s)22652026/10/07 06:12:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40841/oidc2266--- PASS: TestPins_ReservedForMatchingRule (0.22s)22672026/10/07 06:12:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42351/oidc22682026/10/07 06:12:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38573/oidc2269--- PASS: TestValidateToken_ValidToken (0.23s)2270--- PASS: TestScopes_Rules (0.23s)22712026/10/07 06:12:29 http: TLS handshake error from 127.0.0.1:59660: remote error: tls: bad certificate2272--- PASS: TestNewValidator_KubernetesRequiresCA (0.43s)22732026/10/07 06:12:29 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:35443/oidc2274--- PASS: TestValidateToken_NoMatchingProvider (0.61s)2275PASS2276Running hook tests...2277=== RUN TestSendPathsEmpty2278=== PAUSE TestSendPathsEmpty2279=== RUN TestQueueEnqueueAndFetch2280=== PAUSE TestQueueEnqueueAndFetch2281=== RUN TestQueueDeduplication2282=== PAUSE TestQueueDeduplication2283=== RUN TestQueueRemove2284=== PAUSE TestQueueRemove2285=== RUN TestQueueFetchBatchLimit2286=== PAUSE TestQueueFetchBatchLimit2287=== RUN TestQueueRetryMovesToBack2288=== PAUSE TestQueueRetryMovesToBack2289=== RUN TestQueueFetchRemoveLifecycle2290=== PAUSE TestQueueFetchRemoveLifecycle2291=== RUN TestQueueConcurrentWriters2292=== PAUSE TestQueueConcurrentWriters2293=== RUN TestQueueRemoveLargeClosure2294=== PAUSE TestQueueRemoveLargeClosure2295=== RUN TestServerClientIntegration2296=== PAUSE TestServerClientIntegration2297=== RUN TestServerQueueError2298=== PAUSE TestServerQueueError2299=== RUN TestGetListenerSocketActivation2300 server_test.go:210: === RUN TestGetListenerSocketActivation2301 --- PASS: TestGetListenerSocketActivation (0.00s)2302 PASS2303 2304--- PASS: TestGetListenerSocketActivation (0.01s)2305=== RUN TestDrainIsolatesPoisonPath2306=== PAUSE TestDrainIsolatesPoisonPath2307=== RUN TestRunNotBlockedByPoisonHead2308=== PAUSE TestRunNotBlockedByPoisonHead2309=== RUN TestDrainGivesUpWhenServerDown2310=== PAUSE TestDrainGivesUpWhenServerDown2311=== RUN TestFailedPathPrunedByLaterClosure2312=== PAUSE TestFailedPathPrunedByLaterClosure2313=== RUN TestWorkerUploadsAndRemoves2314=== PAUSE TestWorkerUploadsAndRemoves2315=== RUN TestWorkerSkipsGCdPaths2316=== PAUSE TestWorkerSkipsGCdPaths2317=== RUN TestWorkerPrunesClosureDeps2318=== PAUSE TestWorkerPrunesClosureDeps2319=== RUN TestDrainTimeout2320=== PAUSE TestDrainTimeout2321=== CONT TestSendPathsEmpty2322=== CONT TestFailedPathPrunedByLaterClosure2323=== CONT TestQueueEnqueueAndFetch2324--- PASS: TestSendPathsEmpty (0.00s)2325=== CONT TestDrainGivesUpWhenServerDown2326=== CONT TestRunNotBlockedByPoisonHead2327=== CONT TestDrainIsolatesPoisonPath2328=== CONT TestServerQueueError2329=== CONT TestWorkerPrunesClosureDeps2330=== CONT TestServerClientIntegration2331=== CONT TestQueueRemoveLargeClosure2332=== CONT TestDrainTimeout2333=== CONT TestQueueConcurrentWriters23342026/10/07 06:12:29 ERROR Failed to queue paths error="permission denied" count=12335=== CONT TestQueueFetchRemoveLifecycle2336=== CONT TestQueueRemove2337--- PASS: TestServerQueueError (0.00s)2338=== CONT TestQueueRetryMovesToBack2339--- PASS: TestServerClientIntegration (0.00s)2340=== CONT TestQueueDeduplication2341=== CONT TestQueueFetchBatchLimit2342=== CONT TestWorkerSkipsGCdPaths2343=== CONT TestWorkerUploadsAndRemoves23442026/10/07 06:12:29 INFO Upload queue status pending=223452026/10/07 06:12:29 INFO Upload queue status pending=223462026/10/07 06:12:29 INFO Uploading batch count=123472026/10/07 06:12:29 INFO Uploading batch count=223482026/10/07 06:12:29 INFO Upload queue status pending=223492026/10/07 06:12:29 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1164723747/002/nonexistent23502026/10/07 06:12:29 INFO Uploading batch count=123512026/10/07 06:12:29 ERROR Upload failed error="upload failed" count=123522026/10/07 06:12:29 INFO Uploading batch count=22353--- PASS: TestQueueFetchBatchLimit (0.01s)23542026/10/07 06:12:29 INFO Uploading batch count=223552026/10/07 06:12:29 ERROR Upload failed error="upload failed" count=223562026/10/07 06:12:29 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1430558718/002/a23572026/10/07 06:12:29 INFO Uploading batch count=42358--- PASS: TestQueueRetryMovesToBack (0.01s)23592026/10/07 06:12:29 ERROR Upload failed error="upload failed" count=423602026/10/07 06:12:29 INFO Uploading batch count=123612026/10/07 06:12:29 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath1342163782/002/bbb2362--- PASS: TestQueueEnqueueAndFetch (0.02s)23632026/10/07 06:12:29 INFO Uploading batch count=123642026/10/07 06:12:29 INFO Upload queue status pending=32365--- PASS: TestQueueDeduplication (0.01s)23662026/10/07 06:12:29 INFO Uploading batch count=123672026/10/07 06:12:29 ERROR Upload failed error="upload failed" count=123682026/10/07 06:12:29 INFO Uploading batch count=12369--- PASS: TestQueueRemove (0.01s)23702026/10/07 06:12:29 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1430558718/002/b2371--- PASS: TestQueueFetchRemoveLifecycle (0.01s)23722026/10/07 06:12:29 INFO Uploading batch count=223732026/10/07 06:12:29 ERROR Upload failed error="upload failed" count=223742026/10/07 06:12:29 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1430558718/002/c23752026/10/07 06:12:29 INFO Uploading batch count=123762026/10/07 06:12:29 ERROR Upload failed error="upload failed" count=123772026/10/07 06:12:29 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1430558718/002/d2378--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)23792026/10/07 06:12:29 INFO Uploading batch count=123802026/10/07 06:12:29 ERROR Upload failed error="upload failed" count=123812026/10/07 06:12:29 INFO Uploading batch count=223822026/10/07 06:12:29 ERROR Upload failed error="upload failed" count=223832026/10/07 06:12:29 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1430558718/002/e23842026/10/07 06:12:29 INFO Uploading batch count=123852026/10/07 06:12:29 ERROR Upload failed error="upload failed" count=123862026/10/07 06:12:29 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1430558718/002/f23872026/10/07 06:12:29 ERROR Drain finished with paths left in queue remaining=123882026/10/07 06:12:29 ERROR Drain finished with paths left in queue remaining=102389--- PASS: TestDrainIsolatesPoisonPath (0.02s)2390--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2391--- PASS: TestWorkerPrunesClosureDeps (0.03s)2392--- PASS: TestWorkerUploadsAndRemoves (0.03s)2393--- PASS: TestWorkerSkipsGCdPaths (0.03s)2394--- PASS: TestQueueRemoveLargeClosure (0.10s)2395--- PASS: TestQueueConcurrentWriters (0.18s)23962026/10/07 06:12:29 ERROR Upload failed error="context deadline exceeded" count=223972026/10/07 06:12:29 ERROR Drain finished with paths left in queue remaining=42398--- PASS: TestDrainTimeout (0.21s)23992026/10/07 06:12:30 INFO Uploading batch count=124002026/10/07 06:12:30 INFO Uploading batch count=124012026/10/07 06:12:30 INFO Uploading batch count=124022026/10/07 06:12:30 ERROR Upload failed error="upload failed" count=124032026/10/07 06:12:30 INFO Uploading batch count=124042026/10/07 06:12:30 ERROR Upload failed error="upload failed" count=124052026/10/07 06:12:30 INFO Uploading batch count=124062026/10/07 06:12:30 ERROR Upload failed error="upload failed" count=124072026/10/07 06:12:30 INFO Uploading batch count=124082026/10/07 06:12:30 ERROR Upload failed error="upload failed" count=124092026/10/07 06:12:30 ERROR Drain finished with paths left in queue remaining=12410--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2411PASS2412Running signing tests...2413=== RUN TestExternalSigner2414=== PAUSE TestExternalSigner2415=== RUN TestExternalSignerWrongPublicKey2416=== PAUSE TestExternalSignerWrongPublicKey2417=== RUN TestExternalSignerErrors2418=== PAUSE TestExternalSignerErrors2419=== RUN TestExternalSignerRestartsAfterCrash2420=== PAUSE TestExternalSignerRestartsAfterCrash2421=== RUN TestExternalSignerProgramErrorKeepsProcess2422=== PAUSE TestExternalSignerProgramErrorKeepsProcess2423=== RUN TestExternalSignerClose2424=== PAUSE TestExternalSignerClose2425=== RUN TestExternalSignerRejectsInvalidPublicKey2426=== PAUSE TestExternalSignerRejectsInvalidPublicKey2427=== RUN TestExternalSignerCancellation2428=== PAUSE TestExternalSignerCancellation2429=== RUN TestGenerateFingerprint2430=== PAUSE TestGenerateFingerprint2431=== RUN TestParseSigningKey2432=== PAUSE TestParseSigningKey2433=== RUN TestSign2434=== PAUSE TestSign2435=== RUN TestSignBatch2436=== PAUSE TestSignBatch2437=== RUN TestNilKeyPublicKey2438=== PAUSE TestNilKeyPublicKey2439=== RUN TestSignErrors2440=== PAUSE TestSignErrors2441=== CONT TestExternalSigner2442=== CONT TestExternalSignerCancellation2443=== CONT TestExternalSignerProgramErrorKeepsProcess2444=== CONT TestExternalSignerRejectsInvalidPublicKey2445=== RUN TestExternalSignerRejectsInvalidPublicKey/#002446=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002447=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2448=== CONT TestExternalSignerErrors2449=== RUN TestExternalSignerErrors/unrequested_key2450=== PAUSE TestExternalSignerErrors/unrequested_key2451=== RUN TestExternalSignerErrors/wrong_signature_name2452=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2453=== CONT TestExternalSignerWrongPublicKey2454=== CONT TestSignBatch2455=== CONT TestSignErrors2456=== CONT TestNilKeyPublicKey2457--- PASS: TestNilKeyPublicKey (0.00s)2458=== CONT TestParseSigningKey2459=== RUN TestParseSigningKey/valid_32-byte_key2460=== PAUSE TestParseSigningKey/valid_32-byte_key2461=== CONT TestSign2462=== CONT TestGenerateFingerprint2463=== CONT TestExternalSignerRestartsAfterCrash2464=== CONT TestExternalSignerClose2465=== PAUSE TestExternalSignerErrors/wrong_signature_name2466=== RUN TestExternalSignerErrors/wrong_shape2467=== PAUSE TestExternalSignerErrors/wrong_shape2468=== RUN TestExternalSignerErrors/missing_signatures2469=== PAUSE TestExternalSignerErrors/missing_signatures2470=== RUN TestGenerateFingerprint/basic_with_references2471=== PAUSE TestGenerateFingerprint/basic_with_references2472=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2473=== RUN TestExternalSignerErrors/null_signatures2474=== PAUSE TestExternalSignerErrors/null_signatures2475=== RUN TestExternalSignerErrors/too_few_signatures2476=== PAUSE TestExternalSignerErrors/too_few_signatures2477=== RUN TestExternalSignerErrors/wrong_signature_length2478=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2479=== RUN TestGenerateFingerprint/no_references2480=== PAUSE TestGenerateFingerprint/no_references2481=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2482=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2483=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2484=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2485=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2486=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2487=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2488=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2489=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2490=== PAUSE TestExternalSignerErrors/wrong_signature_length2491=== RUN TestExternalSignerErrors/null2492=== RUN TestGenerateFingerprint/invalid_nar_hash_length2493=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2494=== RUN TestGenerateFingerprint/invalid_store_path_prefix2495=== CONT TestExternalSignerRejectsInvalidPublicKey/#002496=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2497=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2498=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2499=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2500--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2501 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2502 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2503 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2504 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2505 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2506=== PAUSE TestExternalSignerErrors/null2507=== RUN TestExternalSignerErrors/invalid_signature_base642508=== PAUSE TestExternalSignerErrors/invalid_signature_base642509=== RUN TestExternalSignerErrors/program_error2510=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2511=== RUN TestParseSigningKey/no_colon2512=== PAUSE TestParseSigningKey/no_colon2513=== RUN TestParseSigningKey/empty_name2514=== PAUSE TestParseSigningKey/empty_name2515=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2516=== RUN TestGenerateFingerprint/invalid_reference_prefix2517=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2518=== CONT TestGenerateFingerprint/basic_with_references2519=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2520=== CONT TestGenerateFingerprint/invalid_nar_hash_length2521=== PAUSE TestExternalSignerErrors/program_error2522=== RUN TestExternalSignerErrors/exit_at_startup2523=== PAUSE TestExternalSignerErrors/exit_at_startup2524=== CONT TestGenerateFingerprint/no_references2525=== CONT TestGenerateFingerprint/invalid_store_path_prefix2526=== RUN TestParseSigningKey/invalid_base642527=== PAUSE TestParseSigningKey/invalid_base642528=== CONT TestGenerateFingerprint/invalid_reference_prefix2529=== RUN TestExternalSignerErrors/wrong_id2530=== PAUSE TestExternalSignerErrors/wrong_id2531=== RUN TestExternalSignerErrors/missing_signature_name2532=== PAUSE TestExternalSignerErrors/missing_signature_name2533=== RUN TestExternalSignerErrors/exit_on_request2534=== PAUSE TestExternalSignerErrors/exit_on_request2535=== RUN TestExternalSignerErrors/invalid_JSON2536=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2537=== PAUSE TestExternalSignerErrors/invalid_JSON2538--- PASS: TestGenerateFingerprint (0.00s)2539 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2540 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2541 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2542 --- PASS: TestGenerateFingerprint/no_references (0.00s)2543 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2544 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2545 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2546=== RUN TestParseSigningKey/wrong_length2547=== PAUSE TestParseSigningKey/wrong_length2548=== CONT TestParseSigningKey/valid_32-byte_key2549=== CONT TestParseSigningKey/invalid_base642550=== CONT TestParseSigningKey/empty_name2551=== CONT TestParseSigningKey/no_colon2552=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2553=== CONT TestParseSigningKey/wrong_length2554=== RUN TestExternalSignerErrors/wrong_signatures_shape2555=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2556=== CONT TestExternalSignerErrors/unrequested_key2557=== CONT TestExternalSignerErrors/null_signatures2558=== CONT TestExternalSignerErrors/wrong_id2559=== CONT TestExternalSignerErrors/wrong_signatures_shape2560=== CONT TestExternalSignerErrors/invalid_JSON2561=== CONT TestExternalSignerErrors/null2562=== CONT TestExternalSignerErrors/missing_signature_name2563=== CONT TestExternalSignerErrors/exit_at_startup2564=== CONT TestExternalSignerErrors/program_error2565--- PASS: TestParseSigningKey (0.00s)2566 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2567 --- PASS: TestParseSigningKey/empty_name (0.00s)2568 --- PASS: TestParseSigningKey/no_colon (0.00s)2569 --- PASS: TestParseSigningKey/wrong_length (0.00s)2570 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2571 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2572=== CONT TestExternalSignerErrors/wrong_signature_name2573=== CONT TestExternalSignerErrors/missing_signatures2574=== CONT TestExternalSignerErrors/wrong_signature_length2575=== CONT TestExternalSignerErrors/wrong_shape2576=== CONT TestExternalSignerErrors/exit_on_request2577=== RUN TestSignErrors/nil_key2578=== PAUSE TestSignErrors/nil_key2579=== CONT TestExternalSignerErrors/too_few_signatures2580--- PASS: TestSign (0.00s)2581=== CONT TestExternalSignerErrors/invalid_signature_base642582--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2583--- PASS: TestSignBatch (0.00s)2584=== RUN TestSignErrors/nil_narinfo2585=== PAUSE TestSignErrors/nil_narinfo2586=== RUN TestSignErrors/invalid_narinfo2587=== PAUSE TestSignErrors/invalid_narinfo2588=== RUN TestSignErrors/canceled2589=== PAUSE TestSignErrors/canceled2590=== CONT TestSignErrors/nil_key2591=== CONT TestSignErrors/nil_narinfo2592=== CONT TestSignErrors/canceled2593=== CONT TestSignErrors/invalid_narinfo2594--- PASS: TestSignErrors (0.01s)2595 --- PASS: TestSignErrors/nil_key (0.00s)2596 --- PASS: TestSignErrors/nil_narinfo (0.00s)2597 --- PASS: TestSignErrors/canceled (0.00s)2598 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2599--- PASS: TestExternalSignerWrongPublicKey (0.01s)2600--- PASS: TestExternalSignerClose (0.01s)2601--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2602--- PASS: TestExternalSigner (0.01s)2603--- PASS: TestExternalSignerErrors (0.00s)2604 --- PASS: TestExternalSignerErrors/null_signatures (0.00s)2605 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)2606 --- PASS: TestExternalSignerErrors/unrequested_key (0.00s)2607 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2608 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2609 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2610 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2611 --- PASS: TestExternalSignerErrors/null (0.01s)2612 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2613 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2614 --- PASS: TestExternalSignerErrors/program_error (0.01s)2615 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2616 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2617 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2618 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2619 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.00s)2620--- PASS: TestExternalSignerCancellation (0.02s)2621PASS2622Running OpenBao signer tests...2623=== RUN TestSign2624=== PAUSE TestSign2625=== RUN TestSignErrors2626=== PAUSE TestSignErrors2627=== RUN TestServe2628=== PAUSE TestServe2629=== RUN TestServeRejectsGarbage2630=== PAUSE TestServeRejectsGarbage2631=== CONT TestSign2632=== CONT TestSignErrors2633=== CONT TestServe2634=== RUN TestSignErrors/http_error2635=== CONT TestServeRejectsGarbage2636--- PASS: TestServeRejectsGarbage (0.00s)2637=== PAUSE TestSignErrors/http_error2638=== RUN TestSignErrors/invalid_json2639=== PAUSE TestSignErrors/invalid_json2640=== RUN TestSignErrors/no_prefix2641=== PAUSE TestSignErrors/no_prefix2642=== RUN TestSignErrors/invalid_base642643=== PAUSE TestSignErrors/invalid_base642644=== CONT TestSignErrors/http_error2645=== CONT TestSignErrors/no_prefix2646--- PASS: TestServe (0.00s)2647=== CONT TestSignErrors/invalid_base642648=== CONT TestSignErrors/invalid_json2649--- PASS: TestSign (0.00s)2650--- PASS: TestSignErrors (0.00s)2651 --- PASS: TestSignErrors/invalid_base64 (0.00s)2652 --- PASS: TestSignErrors/invalid_json (0.00s)2653 --- PASS: TestSignErrors/http_error (0.00s)2654 --- PASS: TestSignErrors/no_prefix (0.00s)2655PASS