niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #406
· 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 TestRetryTimeoutOutlastsMaxRetries56=== PAUSE TestRetryTimeoutOutlastsMaxRetries57=== RUN TestShellSplit58=== PAUSE TestShellSplit59=== RUN TestShellSplitErrors60=== PAUSE TestShellSplitErrors61=== RUN TestStreamPushReportsEveryPath62=== PAUSE TestStreamPushReportsEveryPath63=== RUN TestStreamPushBatchesUnderLoad64=== PAUSE TestStreamPushBatchesUnderLoad65=== RUN TestStreamPushIsolatesFailures66=== PAUSE TestStreamPushIsolatesFailures67=== RUN TestStreamPushGivesUpOnDeadServer68=== PAUSE TestStreamPushGivesUpOnDeadServer69=== RUN TestStreamPushRequestLine70=== PAUSE TestStreamPushRequestLine71=== RUN TestStreamPushReportsSignatures72=== PAUSE TestStreamPushReportsSignatures73=== RUN TestStreamPushReportsSkippedPaths74=== PAUSE TestStreamPushReportsSkippedPaths75=== RUN TestClientSignaturesByStorePath76=== PAUSE TestClientSignaturesByStorePath77=== RUN TestStreamPushStopsWhenCanceled78=== PAUSE TestStreamPushStopsWhenCanceled79=== RUN TestSetClientTLS80=== PAUSE TestSetClientTLS81=== RUN TestSetClientTLSDoesNotMutateDefaultTransport82=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport83=== RUN TestSetClientTLSErrors84=== PAUSE TestSetClientTLSErrors85=== RUN TestStaticToken86=== PAUSE TestStaticToken87=== RUN TestFileTokenReadsAndCaches88=== PAUSE TestFileTokenReadsAndCaches89=== RUN TestFileTokenMissing90=== PAUSE TestFileTokenMissing91=== RUN TestFileTokenEmpty92=== PAUSE TestFileTokenEmpty93=== RUN TestScriptTokenNoExpiryRerunsEveryCall94=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall95=== RUN TestScriptTokenCachesUntilRefresh96=== PAUSE TestScriptTokenCachesUntilRefresh97=== RUN TestScriptTokenEmptyToken98=== PAUSE TestScriptTokenEmptyToken99=== RUN TestScriptTokenBadJSON100=== PAUSE TestScriptTokenBadJSON101=== RUN TestScriptTokenScriptFails102=== PAUSE TestScriptTokenScriptFails103=== RUN TestScriptTokenEmptyCommand104=== PAUSE TestScriptTokenEmptyCommand105=== CONT TestScriptTokenEmptyCommand106--- PASS: TestScriptTokenEmptyCommand (0.00s)107=== CONT TestPathInfoCACompatibility108=== CONT TestDoServerRequestAttachesToken109=== CONT TestDoWithRetry_BodyReplayedViaGetBody110=== CONT TestResolveStorePath111=== CONT TestRetryTimeoutOutlastsMaxRetries112=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess113=== CONT TestRateLimiterFeedback114=== RUN TestRateLimiterFeedback/429_enables_limiter115=== PAUSE TestRateLimiterFeedback/429_enables_limiter116=== RUN TestRateLimiterFeedback/503_enables_limiter117=== PAUSE TestRateLimiterFeedback/503_enables_limiter118=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter119=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter120=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter121=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter122=== CONT TestScriptTokenScriptFails1232026/10/10 19:01:42 WARN Rate limiter enabled after throttle name=server-test rate=5124--- PASS: TestResolveStorePath (0.00s)125=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun126=== CONT TestStreamPushBatchesUnderLoad127=== CONT TestDumpPathMatchesNix128--- PASS: TestScriptTokenScriptFails (0.00s)129=== CONT TestScriptTokenBadJSON130=== CONT TestScriptTokenEmptyToken131=== CONT TestScriptTokenCachesUntilRefresh132=== CONT TestScriptTokenNoExpiryRerunsEveryCall133=== CONT TestFileTokenEmpty134=== CONT TestStreamPushReportsSignatures135=== CONT TestUploadMultipart_SupersededByPeer136=== CONT TestPartSizeForNAR137=== CONT TestStreamPushRequestLine138=== CONT TestUploadMultipart_PartsInParallel139=== CONT TestStreamPushGivesUpOnDeadServer140=== CONT TestFilterOversizedClosures141=== CONT TestDumpPathSingleFile142=== CONT TestStreamPushIsolatesFailures143=== CONT TestCaseHackSuffix144=== RUN TestPathInfoCACompatibility/null_ca_field145=== CONT TestParsePathInfoJSONMultiplePaths146=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths147=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths148=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths149=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths150=== PAUSE TestPathInfoCACompatibility/null_ca_field151=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica1522026/10/10 19:01:42 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:447111532026/10/10 19:01:42 WARN Rate limiter enabled after throttle name=server-test rate=51542026/10/10 19:01:42 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:34947155=== RUN TestUploadMultipart_SupersededByPeer/exists156=== RUN TestPathInfoCACompatibility/old_string_format_-_text157=== PAUSE TestUploadMultipart_SupersededByPeer/exists158=== RUN TestPartSizeForNAR/zero_stays_at_minimum159=== RUN TestUploadMultipart_SupersededByPeer/missing160--- PASS: TestFileTokenEmpty (0.00s)161=== CONT TestParsePathInfoJSON162=== RUN TestParsePathInfoJSON/Nix_format163=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum164=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text165=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive166=== RUN TestFilterOversizedClosures/no_limit_keeps_everything167=== PAUSE TestUploadMultipart_SupersededByPeer/missing1682026/10/10 19:01:42 ERROR Upload failed error="connection refused" count=20169=== RUN TestPartSizeForNAR/small_stays_at_minimum1702026/10/10 19:01:42 ERROR Server seems unavailable, giving up on batch untried=17171=== PAUSE TestParsePathInfoJSON/Nix_format1722026/10/10 19:01:42 ERROR Upload failed error="bad path" count=3173=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive1742026/10/10 19:01:42 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:44711175=== RUN TestPathInfoCACompatibility/new_structured_format_-_text176=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything177=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text178=== CONT TestRegisterUploadedObjectReusesConnections179=== CONT TestGetStorePathHash180=== RUN TestGetStorePathHash/valid_store_path1812026/10/10 19:01:42 ERROR Upload failed error=boom count=1182=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped1832026/10/10 19:01:42 INFO Garbage collection started184=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped185=== CONT TestPathInfoHashCompatibility186=== RUN TestFilterOversizedClosures/all_closures_skipped187=== PAUSE TestFilterOversizedClosures/all_closures_skipped188=== PAUSE TestPartSizeForNAR/small_stays_at_minimum1892026/10/10 19:01:42 ERROR Upload failed error=boom count=11902026/10/10 19:01:42 WARN Rate limiter backed off name=server-test rate=5191=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)192--- PASS: TestStreamPushIsolatesFailures (0.01s)193=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum194=== CONT TestStreamPushReportsEveryPath195=== RUN TestParsePathInfoJSON/Lix_format196=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method197=== CONT TestShellSplitErrors198--- PASS: TestScriptTokenEmptyToken (0.01s)1992026/10/10 19:01:42 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:349472002026/10/10 19:01:42 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:44711201=== PAUSE TestGetStorePathHash/valid_store_path202=== CONT TestEncodeNixBase32203=== RUN TestGetStorePathHash/basename_without_hyphen_should_error204=== RUN TestEncodeNixBase32/test_string_hash205=== PAUSE TestEncodeNixBase32/test_string_hash206=== RUN TestEncodeNixBase32/empty_input207=== PAUSE TestEncodeNixBase32/empty_input208=== CONT TestSetClientTLSErrors2092026/10/10 19:01:42 INFO Garbage collection started210=== CONT TestStaticToken211=== CONT TestDumpPathWriterError212=== CONT TestSetClientTLS213=== CONT TestSetClientTLSDoesNotMutateDefaultTransport214=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error215=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error216=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error217=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error218=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error219=== CONT TestShellSplit2202026/10/10 19:01:42 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:44711221=== CONT TestClientSignaturesByStorePath222=== CONT TestFileTokenMissing223=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)224=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon225=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon226=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI227=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI228=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512229=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512230=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum231=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts232=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts233=== RUN TestPartSizeForNAR/1_TiB2342026/10/10 19:01:42 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=0235=== PAUSE TestPartSizeForNAR/1_TiB236=== RUN TestPartSizeForNAR/5_TiB_S3_max_object237=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object238=== RUN TestPartSizeForNAR/capped_at_5_GiB239=== PAUSE TestPartSizeForNAR/capped_at_5_GiB240=== CONT TestStreamPushReportsSkippedPaths241=== CONT TestConvertHashToNix32242=== RUN TestConvertHashToNix32/SRI_format_to_Nix32243=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32244=== RUN TestConvertHashToNix32/already_Nix32_format245=== PAUSE TestConvertHashToNix32/already_Nix32_format246=== CONT TestRateLimiterFeedback/429_enables_limiter247=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter248=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter249=== RUN TestConvertHashToNix32/invalid_format250=== PAUSE TestConvertHashToNix32/invalid_format251=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths252=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method253--- PASS: TestScriptTokenBadJSON (0.01s)254=== CONT TestStreamPushStopsWhenCanceled2552026/10/10 19:01:42 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:44711256=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2572026/10/10 19:01:42 WARN Rate limiter enabled after throttle name=server-test rate=52582026/10/10 19:01:42 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:34051259=== CONT TestUploadMultipart_SupersededByPeer/missing260=== CONT TestFilterOversizedClosures/no_limit_keeps_everything261=== CONT TestFilterOversizedClosures/all_closures_skipped2622026/10/10 19:01:42 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=50263=== CONT TestEncodeNixBase32/test_string_hash2642026/10/10 19:01:42 WARN Rate limiter backed off name=server-test rate=5265=== CONT TestEncodeNixBase32/empty_input266=== CONT TestGetStorePathHash/valid_store_path267=== CONT TestEncodeNixBase32WithRealHash268--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)269--- PASS: TestStreamPushReportsSignatures (0.03s)270--- PASS: TestShellSplitErrors (0.00s)271--- PASS: TestDoServerRequestAttachesToken (0.03s)272=== PAUSE TestParsePathInfoJSON/Lix_format273=== RUN TestParsePathInfoJSON/empty_input274=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error275=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error276=== CONT TestGetStorePathHash/basename_without_hyphen_should_error277=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI278=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon279=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts280=== CONT TestPartSizeForNAR/5_TiB_S3_max_object2812026/10/10 19:01:42 WARN Garbage collection finished on another replica. Its statistics are not available here282=== CONT TestPartSizeForNAR/1_TiB283=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512284=== RUN TestSetClientTLSErrors/missing_cert_file285=== CONT TestPartSizeForNAR/small_stays_at_minimum286=== CONT TestConvertHashToNix32/invalid_format287=== CONT TestConvertHashToNix32/already_Nix32_format288=== CONT TestPathInfoCACompatibility/null_ca_field289=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method290=== PAUSE TestSetClientTLSErrors/missing_cert_file291=== CONT TestPathInfoCACompatibility/new_structured_format_-_text292=== RUN TestSetClientTLSErrors/missing_key_file293=== PAUSE TestSetClientTLSErrors/missing_key_file294=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive295=== CONT TestPathInfoCACompatibility/old_string_format_-_text296=== CONT TestUploadMultipart_SupersededByPeer/exists297=== CONT TestConvertHashToNix32/SRI_format_to_Nix32298=== RUN TestSetClientTLSErrors/missing_ca_file299=== PAUSE TestSetClientTLSErrors/missing_ca_file300=== RUN TestSetClientTLSErrors/invalid_ca_file301=== PAUSE TestSetClientTLSErrors/invalid_ca_file3022026/10/10 19:01:42 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:44711303=== CONT TestSetClientTLSErrors/missing_cert_file304=== CONT TestPartSizeForNAR/capped_at_5_GiB305=== PAUSE TestParsePathInfoJSON/empty_input306=== RUN TestParsePathInfoJSON/whitespace_only307=== PAUSE TestParsePathInfoJSON/whitespace_only308=== RUN TestParsePathInfoJSON/invalid_JSON309=== PAUSE TestParsePathInfoJSON/invalid_JSON310=== CONT TestParsePathInfoJSON/Nix_format311=== CONT TestSetClientTLSErrors/missing_key_file312=== CONT TestParsePathInfoJSON/invalid_JSON313=== CONT TestRateLimiterFeedback/503_enables_limiter314=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped315=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)316=== RUN TestSetClientTLS/rejects_connection_without_client_cert317--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)318=== CONT TestPartSizeForNAR/zero_stays_at_minimum319=== CONT TestFileTokenReadsAndCaches320=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum3212026/10/10 19:01:42 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=2000322=== CONT TestSetClientTLSErrors/invalid_ca_file323--- PASS: TestStreamPushReportsEveryPath (0.00s)324--- PASS: TestStaticToken (0.00s)325--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.03s)326--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)327--- PASS: TestShellSplit (0.00s)328--- PASS: TestClientSignaturesByStorePath (0.00s)329--- PASS: TestFileTokenMissing (0.00s)330--- PASS: TestStreamPushReportsSkippedPaths (0.00s)331--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)332--- PASS: TestStreamPushStopsWhenCanceled (0.00s)333--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)334 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)335 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)336=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert337=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA338=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA339=== RUN TestSetClientTLS/preserves_debug_logging_transport340=== PAUSE TestSetClientTLS/preserves_debug_logging_transport341=== CONT TestSetClientTLS/rejects_connection_without_client_cert342=== CONT TestSetClientTLSErrors/missing_ca_file3432026/10/10 19:01:42 WARN Rate limiter enabled after throttle name=server-test rate=5344--- PASS: TestEncodeNixBase32 (0.00s)345 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)346 --- PASS: TestEncodeNixBase32/empty_input (0.00s)3472026/10/10 19:01:42 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:44025348--- PASS: TestEncodeNixBase32WithRealHash (0.00s)349--- PASS: TestGetStorePathHash (0.02s)350 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)351 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)352 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)353 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)354--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)355--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.03s)356=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA3572026/10/10 19:01:42 WARN Rate limiter backed off name=server-test rate=5358=== CONT TestParsePathInfoJSON/empty_input359--- PASS: TestPathInfoHashCompatibility (0.02s)360 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)361 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)362 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)363 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)364=== CONT TestParsePathInfoJSON/whitespace_only365=== CONT TestParsePathInfoJSON/Lix_format3662026/10/10 19:01:42 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:44711367--- PASS: TestPathInfoCACompatibility (0.04s)368 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)369 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)370 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)371 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)372 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)373--- PASS: TestConvertHashToNix32 (0.00s)374 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)375 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)376 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)377--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)378 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)379 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)380=== CONT TestSetClientTLS/preserves_debug_logging_transport381--- PASS: TestFilterOversizedClosures (0.00s)382 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)383 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)384 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)385--- PASS: TestDumpPathSingleFile (0.03s)386--- PASS: TestPartSizeForNAR (0.03s)387 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)388 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)389 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)390 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)391 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)392 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)393 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)394--- PASS: TestRateLimiterFeedback (0.00s)395 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)396 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)397 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)398 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)399--- PASS: TestParsePathInfoJSON (0.03s)400 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)401 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)402 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)403 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)404 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)405--- PASS: TestFileTokenReadsAndCaches (0.00s)406--- PASS: TestSetClientTLSErrors (0.00s)407 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)408 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)409 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)410 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)4112026/10/10 19:01:42 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:447114122026/10/10 19:01:42 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:447114132026/10/10 19:01:42 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:447114142026/10/10 19:01:42 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:447114152026/10/10 19:01:42 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:447114162026/10/10 19:01:42 http: TLS handshake error from 127.0.0.1:48858: remote error: tls: bad certificate417--- PASS: TestSetClientTLS (0.00s)418 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)419 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)420 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)4212026/10/10 19:01:42 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:447114222026/10/10 19:01:42 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:44711423--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)4242026/10/10 19:01:42 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:447114252026/10/10 19:01:42 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:447114262026/10/10 19:01:42 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:44711427--- PASS: TestCaseHackSuffix (0.05s)4282026/10/10 19:01:42 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:44711429--- PASS: TestStreamPushRequestLine (0.05s)4302026/10/10 19:01:42 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:44711431--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.06s)432--- PASS: TestDumpPathWriterError (0.03s)433--- PASS: TestStreamPushBatchesUnderLoad (0.10s)434--- PASS: TestDumpPathMatchesNix (0.10s)435--- PASS: TestUploadMultipart_PartsInParallel (0.64s)436--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)437PASS438Running server tests...439The files belonging to this database system will be owned by user "nixbld".440This user must also own the server process.441442The database cluster will be initialized with locale "C".443The default database encoding has accordingly been set to "SQL_ASCII".444The default text search configuration will be set to "english".445446Data page checksums are enabled.447448creating directory /build/postgres995771894/data ... ok449creating subdirectories ... ok450selecting dynamic shared memory implementation ... posix451selecting default "max_connections" ... 100452selecting default "shared_buffers" ... 128MB453selecting default time zone ... UTC454creating configuration files ... ok455running bootstrap script ... ok456performing post-bootstrap initialization ... ok457syncing data to disk ... ok458459initdb: warning: enabling "trust" authentication for local connections460initdb: 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.461462Success. You can now start the database server using:463464 pg_ctl -D /build/postgres995771894/data -l logfile start465466/build/postgres995771894:5432 - no response4672026-10-10 19:01:44.357 UTC [128] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4682026-10-10 19:01:44.358 UTC [128] LOG: listening on Unix socket "/build/postgres995771894/.s.PGSQL.5432"4692026-10-10 19:01:44.362 UTC [135] LOG: database system was shut down at 2026-10-10 19:01:44 UTC4702026-10-10 19:01:44.365 UTC [128] LOG: database system is ready to accept connections471/build/postgres995771894:5432 - accepting connections472=== RUN TestService_AuthMiddleware473=== PAUSE TestService_AuthMiddleware474=== RUN TestService_AuthMiddleware_MTLSProxyHeader475=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader476=== RUN TestService_AuthMiddleware_MTLSBoundSubjects477=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects478=== RUN TestService_ReadAuthMiddleware479=== PAUSE TestService_ReadAuthMiddleware480=== RUN TestService_AuthMiddleware_OIDC481=== PAUSE TestService_AuthMiddleware_OIDC482=== RUN TestService_RequireScope_OIDC483=== PAUSE TestService_RequireScope_OIDC484=== RUN TestService_ReadScope_PublicByDefault485=== PAUSE TestService_ReadScope_PublicByDefault486=== RUN TestCacheConfigHandler487=== PAUSE TestCacheConfigHandler488=== RUN TestCacheStatsHandler489=== PAUSE TestCacheStatsHandler490=== RUN TestClientCADerivations491=== PAUSE TestClientCADerivations492=== RUN TestClientErrorHandling493=== PAUSE TestClientErrorHandling494=== RUN TestClientIntegration495=== PAUSE TestClientIntegration496=== RUN TestClientMultipleUploads497=== PAUSE TestClientMultipleUploads498=== RUN TestClientWithDependencies499=== PAUSE TestClientWithDependencies500=== RUN TestClientSharedPathCommittedMidPush501=== PAUSE TestClientSharedPathCommittedMidPush502=== RUN TestPinProtectsFromGC503=== PAUSE TestPinProtectsFromGC504=== RUN TestClientPushesUseOnePush505=== PAUSE TestClientPushesUseOnePush506=== RUN TestClientFallsBackToClosures507=== PAUSE TestClientFallsBackToClosures508=== RUN TestDeleteClosuresRacingPins509=== PAUSE TestDeleteClosuresRacingPins510=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock511=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock512=== RUN TestResolveDBConnectionString513=== PAUSE TestResolveDBConnectionString514=== RUN TestConnectWaitsForAPeerMigration515=== PAUSE TestConnectWaitsForAPeerMigration516=== RUN TestLeadElectsOneAndHandsOver517=== PAUSE TestLeadElectsOneAndHandsOver518=== RUN TestLeadIncumbentWinsAfterRestart5192026/10/10 19:01:44 INFO lead: acquired remote=192.0.2.1:12345202026/10/10 19:01:45 INFO lead: released remote=192.0.2.1:12345212026/10/10 19:01:45 INFO lead: acquired remote=192.0.2.1:12345222026/10/10 19:01:46 INFO lead: released remote=192.0.2.1:1234523--- PASS: TestLeadIncumbentWinsAfterRestart (1.87s)524=== RUN TestLeadIncumbentAnnouncesAtOnce525=== PAUSE TestLeadIncumbentAnnouncesAtOnce526=== RUN TestLeadEndsOnShutdown527=== PAUSE TestLeadEndsOnShutdown528=== RUN TestLeadEndsWhenItsConnectionHangs5292026/10/10 19:01:46 INFO lead: acquired remote=192.0.2.1:12345302026-10-10 19:01:48.034 UTC [380] FATAL: terminating connection due to administrator command5312026/10/10 19:01:48 INFO lead: acquired remote=192.0.2.1:12345322026/10/10 19:01:49 WARN lead: lock connection lost error="timeout: context deadline exceeded"5332026/10/10 19:01:49 INFO lead: released remote=192.0.2.1:12345342026/10/10 19:01:49 INFO lead: released remote=192.0.2.1:1234535--- PASS: TestLeadEndsWhenItsConnectionHangs (2.90s)536=== RUN TestGCAdvisoryLockBlocksConcurrentRun537=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun538=== RUN TestGCBugBareHashReferences539=== PAUSE TestGCBugBareHashReferences540=== RUN TestGCMetrics541=== PAUSE TestGCMetrics542=== RUN TestPushDedupSurvivesConcurrentGC543=== PAUSE TestPushDedupSurvivesConcurrentGC544=== RUN TestDeduplicatedObjectsRecordedAsPending545=== PAUSE TestDeduplicatedObjectsRecordedAsPending546=== RUN TestGCSweepSkipsPendingObjects547=== PAUSE TestGCSweepSkipsPendingObjects548=== RUN TestTombstonedObjectOfferedWithoutWaiting549=== PAUSE TestTombstonedObjectOfferedWithoutWaiting550=== RUN TestGCSweepDeliversEachKeyOnce551=== PAUSE TestGCSweepDeliversEachKeyOnce552=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection553=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection554=== RUN TestForceGCDuringPushOffersSweptObject555=== PAUSE TestForceGCDuringPushOffersSweptObject556=== RUN TestFailedS3DeleteKeepsTombstone557=== PAUSE TestFailedS3DeleteKeepsTombstone558=== RUN TestSweepSkipsRowsLockedByPush559=== PAUSE TestSweepSkipsRowsLockedByPush560=== RUN TestRegisterCompletedObjectNeedsPendingRow561=== PAUSE TestRegisterCompletedObjectNeedsPendingRow562=== RUN TestGetExistingObjectsLocksRows563=== PAUSE TestGetExistingObjectsLocksRows564=== RUN TestSweepRechecksPendingAfterLocking565=== PAUSE TestSweepRechecksPendingAfterLocking566=== RUN TestPushWaitsForSweepHoldingRow567=== PAUSE TestPushWaitsForSweepHoldingRow568=== RUN TestCommitRacingPendingCleanupKeepsObjects569=== PAUSE TestCommitRacingPendingCleanupKeepsObjects570=== RUN TestGCEndsOnShutdown571=== PAUSE TestGCEndsOnShutdown572=== RUN TestGCTaskStore_StartNew573=== PAUSE TestGCTaskStore_StartNew574=== RUN TestGCTaskStore_DeduplicateSameParams575=== PAUSE TestGCTaskStore_DeduplicateSameParams576=== RUN TestGCTaskStore_ConflictDifferentParams577=== PAUSE TestGCTaskStore_ConflictDifferentParams578=== RUN TestGCTaskStore_GetEmpty579=== PAUSE TestGCTaskStore_GetEmpty580=== RUN TestGCTaskStore_GetReturnsLatest581=== PAUSE TestGCTaskStore_GetReturnsLatest582=== RUN TestGCTaskStore_CompletedAllowsNewTask583=== PAUSE TestGCTaskStore_CompletedAllowsNewTask584=== RUN TestGCTaskStore_PhaseUpdates585=== PAUSE TestGCTaskStore_PhaseUpdates586=== RUN TestGCTaskStore_Fail587=== PAUSE TestGCTaskStore_Fail588=== RUN TestGracefulShutdownDrainsInflight589=== PAUSE TestGracefulShutdownDrainsInflight590=== RUN TestService_healthCheckHandler591=== PAUSE TestService_healthCheckHandler592=== RUN TestService_readinessHandler593=== PAUSE TestService_readinessHandler594=== RUN TestGenerateLandingPage595=== PAUSE TestGenerateLandingPage596=== RUN TestCacheConfigHandlerMaxNarSize597=== PAUSE TestCacheConfigHandlerMaxNarSize598=== RUN TestCreatePendingClosureRejectsOversizedNAR599=== PAUSE TestCreatePendingClosureRejectsOversizedNAR600=== RUN TestNARDeduplicationMetadataUploadBug601=== PAUSE TestNARDeduplicationMetadataUploadBug602=== RUN TestMetricsInventory603=== PAUSE TestMetricsInventory604=== RUN TestMetricsCommit605=== PAUSE TestMetricsCommit606=== RUN TestService_NativeMTLS607=== PAUSE TestService_NativeMTLS608=== RUN TestServerTLSConfig609=== PAUSE TestServerTLSConfig610=== RUN TestMultipartCleanup611=== PAUSE TestMultipartCleanup612=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded613=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded614=== RUN TestPendingCleanupUsesOneCutoff615=== PAUSE TestPendingCleanupUsesOneCutoff616=== RUN TestObjectStatsTrigger617=== PAUSE TestObjectStatsTrigger618=== RUN TestObjectStatsLargeCommit619=== PAUSE TestObjectStatsLargeCommit620=== RUN TestOrphanedObjectsGC621=== PAUSE TestOrphanedObjectsGC622=== RUN TestOrphanedObjectsGCStressTest623=== PAUSE TestOrphanedObjectsGCStressTest624=== RUN TestCreatePin_ReservedPins625=== PAUSE TestCreatePin_ReservedPins626=== RUN TestPresentReportsOnlyClosureRoots627=== PAUSE TestPresentReportsOnlyClosureRoots628=== RUN TestPresentRefreshesOnlyStaleClosures629=== PAUSE TestPresentRefreshesOnlyStaleClosures630=== RUN TestPresentNotReportedWhileGCDeletesClosure631=== PAUSE TestPresentNotReportedWhileGCDeletesClosure632=== RUN TestParseSingleRange633=== PAUSE TestParseSingleRange634=== RUN TestProxyHeadersOnlyTrustedOnSocket6352026/10/10 19:01:49 INFO Starting HTTP server address=127.0.0.1:370236362026/10/10 19:01:49 INFO Starting HTTP server address=proxy.sock6372026/10/10 19:01:49 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6382026/10/10 19:01:49 INFO Shutdown signal received, draining in-flight requests timeout=10s639--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.10s)640=== RUN TestIsValidCachePath641=== PAUSE TestIsValidCachePath642=== RUN TestReadProxyNarinfo643=== PAUSE TestReadProxyNarinfo644=== RUN TestReadProxyNarinfoAlreadyDecompressed645=== PAUSE TestReadProxyNarinfoAlreadyDecompressed646=== RUN TestReadProxyContentNegotiation647=== PAUSE TestReadProxyContentNegotiation648=== RUN TestReadProxyNarStreaming649=== PAUSE TestReadProxyNarStreaming650=== RUN TestReadProxy404651=== PAUSE TestReadProxy404652=== RUN TestReadProxyInvalidPath653=== PAUSE TestReadProxyInvalidPath654=== RUN TestReadProxyHead655=== PAUSE TestReadProxyHead656=== RUN TestReadProxyOutlastsServerWriteTimeout657=== PAUSE TestReadProxyOutlastsServerWriteTimeout658=== RUN TestReadProxyConditionalGet659=== PAUSE TestReadProxyConditionalGet660=== RUN TestReadProxyRootRedirectsToIndexHTML661=== PAUSE TestReadProxyRootRedirectsToIndexHTML662=== RUN TestReadProxyDisabled663=== PAUSE TestReadProxyDisabled664=== RUN TestReadRedirectNar665=== PAUSE TestReadRedirectNar666=== RUN TestReadRedirectKeepsNarinfoProxied667=== PAUSE TestReadRedirectKeepsNarinfoProxied668=== RUN TestReadProxyRangeRequest669=== PAUSE TestReadProxyRangeRequest670=== RUN TestReadRedirectUsesPublicS3URL671=== PAUSE TestReadRedirectUsesPublicS3URL672=== RUN TestPush_OverlappingRootsStoreOneRowPerKey673=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey674=== RUN TestPush_CompleteCommitsEveryRoot675=== PAUSE TestPush_CompleteCommitsEveryRoot676=== RUN TestPush_RepeatedRootCommitsOnce677=== PAUSE TestPush_RepeatedRootCommitsOnce678=== RUN TestPush_CompleteWaitsForCleanupOfThePush679=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush680=== RUN TestPush_RootsAreLockedInByteOrder681=== PAUSE TestPush_RootsAreLockedInByteOrder682=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit683=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit684=== RUN TestPush_RejectsBadRequests685=== PAUSE TestPush_RejectsBadRequests686=== RUN TestPush_SignsNarinfosOfItsPendingObjects687=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects688=== RUN TestRedundantMultipartUpload689=== PAUSE TestRedundantMultipartUpload690=== RUN TestCompleteMultipartUpload_ErrorButObjectExists691=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists692=== RUN TestCompletedNarNotReofferedAcrossClosures693=== PAUSE TestCompletedNarNotReofferedAcrossClosures694=== RUN TestPresignedUploadRegisteredBeforeCommit695=== PAUSE TestPresignedUploadRegisteredBeforeCommit696=== RUN TestService_Rustfstest697=== PAUSE TestService_Rustfstest698=== RUN TestParseSize699=== PAUSE TestParseSize700=== RUN TestSkippedUploadsHandler701=== PAUSE TestSkippedUploadsHandler702=== RUN TestSystemdListenerNotActivated703--- PASS: TestSystemdListenerNotActivated (0.00s)704=== RUN TestWatchdogBeatsWhenHealthy705--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)706=== RUN TestWatchdogSkipsWhenUnhealthy7072026/10/10 19:01:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7082026/10/10 19:01:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7092026/10/10 19:01:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7102026/10/10 19:01:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7112026/10/10 19:01:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7122026/10/10 19:01:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7132026/10/10 19:01:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7142026/10/10 19:01:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7152026/10/10 19:01:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7162026/10/10 19:01:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"717--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)718=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle719=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle720=== RUN TestProxyWriteTimeout721=== PAUSE TestProxyWriteTimeout722=== RUN TestPendingClosureWriteTimeout723=== PAUSE TestPendingClosureWriteTimeout724=== RUN TestIsValidUploadKey725=== PAUSE TestIsValidUploadKey726=== RUN TestUploadHandlersRejectInvalidKeys727=== PAUSE TestUploadHandlersRejectInvalidKeys728=== RUN TestUploadHandlersRejectOversizedBody729=== PAUSE TestUploadHandlersRejectOversizedBody730=== RUN TestService_cleanupPendingClosuresHandler731=== PAUSE TestService_cleanupPendingClosuresHandler732=== RUN TestService_createPendingClosureHandler733=== PAUSE TestService_createPendingClosureHandler734=== RUN TestService_verifyS3Integrity735=== PAUSE TestService_verifyS3Integrity736=== RUN TestCompleteMultipartUnregistered737=== PAUSE TestCompleteMultipartUnregistered738=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT739=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT740=== CONT TestSkippedUploadsHandler741=== CONT TestService_Rustfstest742=== CONT TestGracefulShutdownDrainsInflight743=== CONT TestGCTaskStore_PhaseUpdates744=== CONT TestClientPushesUseOnePush745=== CONT TestUploadHandlersRejectOversizedBody746=== CONT TestClientWithDependencies7472026/10/10 19:01:49 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000748--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)7492026/10/10 19:01:49 INFO Starting HTTP server address=127.0.0.1:42753750=== CONT TestGCBugBareHashReferences751=== CONT TestGCTaskStore_Fail752--- PASS: TestGCTaskStore_Fail (0.00s)753=== CONT TestGCTaskStore_DeduplicateSameParams754--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)755=== CONT TestGCAdvisoryLockBlocksConcurrentRun756=== CONT TestLeadEndsOnShutdown757=== CONT TestLeadIncumbentAnnouncesAtOnce7582026/10/10 19:01:49 INFO Shutdown signal received, draining in-flight requests timeout=10s759=== CONT TestLeadElectsOneAndHandsOver760=== CONT TestConnectWaitsForAPeerMigration761=== CONT TestResolveDBConnectionString762=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock763=== CONT TestDeleteClosuresRacingPins764=== CONT TestClientFallsBackToClosures765=== CONT TestGCTaskStore_CompletedAllowsNewTask766=== CONT TestGCTaskStore_GetReturnsLatest767=== CONT TestGCTaskStore_GetEmpty768=== CONT TestGCTaskStore_ConflictDifferentParams769=== CONT TestPendingClosureWriteTimeout770=== CONT TestService_AuthMiddleware771=== CONT TestParseSize772=== CONT TestGCTaskStore_StartNew773--- PASS: TestGCTaskStore_StartNew (0.00s)774--- PASS: TestGracefulShutdownDrainsInflight (0.07s)775=== CONT TestClientSharedPathCommittedMidPush776=== RUN TestResolveDBConnectionString/flag_wins777=== PAUSE TestResolveDBConnectionString/flag_wins778=== RUN TestResolveDBConnectionString/file_when_flag_empty779=== PAUSE TestResolveDBConnectionString/file_when_flag_empty780=== RUN TestResolveDBConnectionString/missing_file_is_an_error781=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error782=== RUN TestResolveDBConnectionString/PGHOST_allows_empty783=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty784=== RUN TestResolveDBConnectionString/nothing_configured785=== PAUSE TestResolveDBConnectionString/nothing_configured786=== CONT TestGCEndsOnShutdown787=== RUN TestGCEndsOnShutdown/before_the_run788=== PAUSE TestGCEndsOnShutdown/before_the_run789=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete790=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete791=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark792=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark793=== CONT TestCommitRacingPendingCleanupKeepsObjects794--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)795=== CONT TestPushWaitsForSweepHoldingRow796--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)797=== CONT TestReadProxyContentNegotiation798--- PASS: TestGCTaskStore_GetEmpty (0.00s)799=== CONT TestSweepRechecksPendingAfterLocking800--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)801=== CONT TestPresignedUploadRegisteredBeforeCommit802=== RUN TestPendingClosureWriteTimeout/empty803=== PAUSE TestPendingClosureWriteTimeout/empty804=== RUN TestPendingClosureWriteTimeout/400_objects805=== PAUSE TestPendingClosureWriteTimeout/400_objects806=== RUN TestPendingClosureWriteTimeout/670k_objects807=== PAUSE TestPendingClosureWriteTimeout/670k_objects808=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline809=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline810=== CONT TestGetExistingObjectsLocksRows811--- PASS: TestSkippedUploadsHandler (0.08s)812=== CONT TestCompletedNarNotReofferedAcrossClosures813--- PASS: TestParseSize (0.00s)814=== CONT TestRegisterCompletedObjectNeedsPendingRow815=== CONT TestPinProtectsFromGC816=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure817=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure818=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart819=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart820=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts821=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts822=== CONT TestCompleteMultipartUpload_ErrorButObjectExists8232026/10/10 19:01:50 INFO lead: acquired remote=192.0.2.1:12348242026/10/10 19:01:50 INFO lead: acquired remote=192.0.2.1:12348252026/10/10 19:01:50 INFO lead: released remote=192.0.2.1:1234826--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.31s)827=== CONT TestSweepSkipsRowsLockedByPush828--- PASS: TestService_Rustfstest (0.36s)829=== CONT TestRedundantMultipartUpload8302026/10/10 19:01:50 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"831--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.40s)832=== CONT TestFailedS3DeleteKeepsTombstone8332026/10/10 19:01:50 INFO lead: acquired remote=192.0.2.1:1234834=== NAME TestClientWithDependencies835 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies3461261332/001/store/ldbdbwi51h00wrjcgfa6y28v8wrqdywy-test-script8362026/10/10 19:01:50 INFO Received uploads request method=POST path=/api/pending_closures837 client_integration_test.go:615: Found 1 dependencies (including self)8382026/10/10 19:01:50 INFO Received push request method=POST path=/api/pushes8392026/10/10 19:01:50 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)8402026/10/10 19:01:50 INFO Uploading bihzjaks98fjhh6mwgmqcgmf9x8qqd1a-b (216B)8412026/10/10 19:01:50 INFO Uploading h95qyc9gckwkd1l4vvc7rfw4d9wbqnd8-shared-dep (136B)8422026/10/10 19:01:50 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"8432026/10/10 19:01:50 WARN Failed to register uploaded object key=nar/01h9b00fav0i6cqhpsm4yfxivnx0800yxw8i3izp1xnjyccmyw8h.nar.zst error="server returned 404: 404 page not found\n"8442026/10/10 19:01:50 WARN Failed to register uploaded object key=1yhs219awaq52ir8mmz4fcb0mhq4zyjk.ls error="server returned 404: 404 page not found\n"8452026/10/10 19:01:50 WARN Failed to register uploaded object key=h95qyc9gckwkd1l4vvc7rfw4d9wbqnd8.ls error="server returned 404: 404 page not found\n"8462026/10/10 19:01:50 WARN Failed to register uploaded object key=bihzjaks98fjhh6mwgmqcgmf9x8qqd1a.ls error="server returned 404: 404 page not found\n"8472026/10/10 19:01:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8482026/10/10 19:01:50 INFO Signed narinfos id=1 count=38492026/10/10 19:01:50 INFO Uploading 3 narinfos8502026/10/10 19:01:50 INFO Received complete push request method=POST path=/api/pushes/1/complete8512026/10/10 19:01:50 WARN Failed to register uploaded object key=1yhs219awaq52ir8mmz4fcb0mhq4zyjk.narinfo error="server returned 404: 404 page not found\n"8522026/10/10 19:01:50 WARN Failed to register uploaded object key=h95qyc9gckwkd1l4vvc7rfw4d9wbqnd8.narinfo error="server returned 404: 404 page not found\n"8532026/10/10 19:01:50 WARN Failed to register uploaded object key=bihzjaks98fjhh6mwgmqcgmf9x8qqd1a.narinfo error="server returned 404: 404 page not found\n"8542026/10/10 19:01:50 INFO Completed push id=1 objects=8 duration=11.014055ms8552026/10/10 19:01:50 INFO Upload complete. (63ms)856=== NAME TestClientPushesUseOnePush857 client_pushes_test.go:97: Retrieved narinfo from S3:858 StorePath: /build/TestClientPushesUseOnePush2067325014/001/store/h95qyc9gckwkd1l4vvc7rfw4d9wbqnd8-shared-dep859 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst860 Compression: zstd861 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82862 NarSize: 136863 References: 864 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n865 client_pushes_test.go:97: Retrieved narinfo from S3:866 StorePath: /build/TestClientPushesUseOnePush2067325014/001/store/1yhs219awaq52ir8mmz4fcb0mhq4zyjk-a867 URL: nar/01h9b00fav0i6cqhpsm4yfxivnx0800yxw8i3izp1xnjyccmyw8h.nar.zst868 Compression: zstd869 NarHash: sha256:01h9b00fav0i6cqhpsm4yfxivnx0800yxw8i3izp1xnjyccmyw8h870 NarSize: 216871 References: /build/TestClientPushesUseOnePush2067325014/001/store/h95qyc9gckwkd1l4vvc7rfw4d9wbqnd8-shared-dep872 CA: text:sha256:1bcgpq02alwmv7mk6dfl8y6i6h4bbs1wgwjg1ib7d50scq8k1pxf873 client_pushes_test.go:97: Retrieved narinfo from S3:874 StorePath: /build/TestClientPushesUseOnePush2067325014/001/store/bihzjaks98fjhh6mwgmqcgmf9x8qqd1a-b875 URL: nar/01h9b00fav0i6cqhpsm4yfxivnx0800yxw8i3izp1xnjyccmyw8h.nar.zst876 Compression: zstd877 NarHash: sha256:01h9b00fav0i6cqhpsm4yfxivnx0800yxw8i3izp1xnjyccmyw8h878 NarSize: 216879 References: /build/TestClientPushesUseOnePush2067325014/001/store/h95qyc9gckwkd1l4vvc7rfw4d9wbqnd8-shared-dep880 CA: text:sha256:1bcgpq02alwmv7mk6dfl8y6i6h4bbs1wgwjg1ib7d50scq8k1pxf881--- PASS: TestClientPushesUseOnePush (0.54s)882=== CONT TestPush_SignsNarinfosOfItsPendingObjects883--- PASS: TestGetExistingObjectsLocksRows (0.46s)884=== CONT TestForceGCDuringPushOffersSweptObject885=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows886=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows887=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check888=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check889=== CONT TestPush_RejectsBadRequests890--- PASS: TestReadProxyContentNegotiation (0.47s)891=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection8922026/10/10 19:01:50 INFO Aborted multipart uploads count=0 kept=08932026/10/10 19:01:50 INFO Received push request method=POST path=/api/pushes8942026/10/10 19:01:50 INFO Received uploads request method=POST path=/api/pending_closures8952026/10/10 19:01:50 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8962026/10/10 19:01:50 INFO Uploading ldbdbwi51h00wrjcgfa6y28v8wrqdywy-test-script (136B)8972026/10/10 19:01:50 WARN Force mode enabled - objects will be deleted immediately without grace period898--- PASS: TestGCBugBareHashReferences (0.56s)899=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit9002026/10/10 19:01:50 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"9012026/10/10 19:01:50 WARN Failed to register uploaded object key=ldbdbwi51h00wrjcgfa6y28v8wrqdywy.ls error="server returned 404: 404 page not found\n"9022026/10/10 19:01:50 WARN Failed to register uploaded object key=log/dv1yy9js0myjxwxfinmhg55bryypkqcf-test-script.drv error="server returned 404: 404 page not found\n"9032026/10/10 19:01:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9042026/10/10 19:01:50 INFO Signed narinfos id=1 count=19052026/10/10 19:01:50 INFO Uploading 1 narinfos9062026/10/10 19:01:50 WARN Failed to register uploaded object key=ldbdbwi51h00wrjcgfa6y28v8wrqdywy.narinfo error="server returned 404: 404 page not found\n"9072026/10/10 19:01:50 INFO Received complete push request method=POST path=/api/pushes/1/complete9082026/10/10 19:01:50 INFO Completed push id=1 objects=4 duration=6.101713ms9092026/10/10 19:01:50 INFO Upload complete. (59ms)9102026/10/10 19:01:50 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=0911=== NAME TestClientWithDependencies912 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3461261332/001/store) requires matching store prefix9132026/10/10 19:01:50 INFO Received uploads request method=POST path=/api/pending_closures9142026/10/10 19:01:50 INFO Vacuumed table table=pending_closures915--- PASS: TestClientWithDependencies (0.58s)916=== CONT TestGCSweepDeliversEachKeyOnce9172026/10/10 19:01:50 INFO Vacuumed table table=pending_objects9182026/10/10 19:01:50 INFO Vacuumed table table=multipart_uploads9192026/10/10 19:01:50 INFO Vacuumed table table=closures9202026/10/10 19:01:50 INFO Vacuumed table table=objects921--- PASS: TestSweepRechecksPendingAfterLocking (0.51s)922=== CONT TestPush_RootsAreLockedInByteOrder9232026/10/10 19:01:50 INFO Received push request method=POST path=/api/pushes9242026/10/10 19:01:50 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9252026/10/10 19:01:50 INFO Received uploads request method=POST path=/api/pending_closures9262026/10/10 19:01:50 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)9272026/10/10 19:01:50 INFO Uploading pr9vqnc6rar1yhqc7v904jhm6rjjjpfj-top (224B)9282026/10/10 19:01:50 INFO Uploading 9ryw1vbm5p5kkkiachqaiqkn0iar13b3-shared-dep (136B)929--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.53s)930=== CONT TestTombstonedObjectOfferedWithoutWaiting9312026/10/10 19:01:50 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"9322026/10/10 19:01:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9332026/10/10 19:01:50 WARN Failed to register uploaded object key=nar/1gzw5gizj0bqlzvi2srip1vk50j7hvwss3a7crrniyxwyyh9kz7q.nar.zst error="server returned 404: 404 page not found\n"9342026/10/10 19:01:50 WARN Failed to register uploaded object key=9ryw1vbm5p5kkkiachqaiqkn0iar13b3.ls error="server returned 404: 404 page not found\n"9352026/10/10 19:01:50 WARN Failed to register uploaded object key=pr9vqnc6rar1yhqc7v904jhm6rjjjpfj.ls error="server returned 404: 404 page not found\n"9362026/10/10 19:01:50 INFO Signed narinfos id=1 count=29372026/10/10 19:01:50 INFO Uploading 2 narinfos9382026/10/10 19:01:50 INFO Received uploads request method=POST path=/api/pending_closures9392026/10/10 19:01:50 WARN Failed to register uploaded object key=pr9vqnc6rar1yhqc7v904jhm6rjjjpfj.narinfo error="server returned 404: 404 page not found\n"9402026/10/10 19:01:50 INFO Received complete push request method=POST path=/api/pushes/1/complete9412026/10/10 19:01:50 WARN Failed to register uploaded object key=9ryw1vbm5p5kkkiachqaiqkn0iar13b3.narinfo error="server returned 404: 404 page not found\n"9422026/10/10 19:01:50 INFO Received uploads request method=POST path=/api/pending_closures9432026/10/10 19:01:50 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)9442026/10/10 19:01:50 INFO Uploading vr0pca6b71y2dbzck4qgj3spkqhzylpi-a (216B)9452026/10/10 19:01:50 INFO Uploading d0m47733gkcca6l219qsskph05g1dr1f-shared-dep (136B)9462026/10/10 19:01:50 INFO Completed push id=1 objects=6 duration=8.322272ms9472026/10/10 19:01:50 INFO Upload complete. (63ms)948--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.55s)949=== CONT TestPush_CompleteWaitsForCleanupOfThePush950=== NAME TestClientSharedPathCommittedMidPush951 client_integration_test.go:680: Retrieved narinfo from S3:952 StorePath: /build/TestClientSharedPathCommittedMidPush418312321/001/store/9ryw1vbm5p5kkkiachqaiqkn0iar13b3-shared-dep953 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst954 Compression: zstd955 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82956 NarSize: 136957 References: 958 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n9592026/10/10 19:01:50 WARN Failed to register uploaded object key=vb8z0f5lvjxkpf0ixzv3lhg21lv7fiz4.ls error="server returned 404: 404 page not found\n"9602026/10/10 19:01:50 WARN Failed to register uploaded object key=nar/1hpacdl45ns8h9fp5f2avbn04vb051bifsmy70a7i2xdd7bmv66w.nar.zst error="server returned 404: 404 page not found\n"9612026/10/10 19:01:50 WARN Failed to register uploaded object key=vr0pca6b71y2dbzck4qgj3spkqhzylpi.ls error="server returned 404: 404 page not found\n"9622026/10/10 19:01:50 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"9632026/10/10 19:01:50 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9642026/10/10 19:01:50 WARN Failed to register uploaded object key=d0m47733gkcca6l219qsskph05g1dr1f.ls error="server returned 404: 404 page not found\n"965 client_integration_test.go:680: Retrieved narinfo from S3:966 StorePath: /build/TestClientSharedPathCommittedMidPush418312321/001/store/pr9vqnc6rar1yhqc7v904jhm6rjjjpfj-top967 URL: nar/1gzw5gizj0bqlzvi2srip1vk50j7hvwss3a7crrniyxwyyh9kz7q.nar.zst968 Compression: zstd969 NarHash: sha256:1gzw5gizj0bqlzvi2srip1vk50j7hvwss3a7crrniyxwyyh9kz7q970 NarSize: 224971 References: /build/TestClientSharedPathCommittedMidPush418312321/001/store/9ryw1vbm5p5kkkiachqaiqkn0iar13b3-shared-dep972 CA: text:sha256:0l4qvdym040ld3a28f32fnhlkjmsqw4ww1mkprjldmkgy8f7r81c9732026/10/10 19:01:50 INFO Signed narinfos id=1 count=29742026/10/10 19:01:50 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign9752026/10/10 19:01:50 INFO Signed narinfos id=2 count=29762026/10/10 19:01:50 INFO Uploading 4 narinfos977--- PASS: TestClientSharedPathCommittedMidPush (0.56s)978=== CONT TestGCSweepSkipsPendingObjects9792026/10/10 19:01:50 WARN Failed to register uploaded object key=vb8z0f5lvjxkpf0ixzv3lhg21lv7fiz4.narinfo error="server returned 404: 404 page not found\n"9802026/10/10 19:01:50 WARN Failed to register uploaded object key=d0m47733gkcca6l219qsskph05g1dr1f.narinfo error="server returned 404: 404 page not found\n"9812026/10/10 19:01:50 WARN Failed to register uploaded object key=vr0pca6b71y2dbzck4qgj3spkqhzylpi.narinfo error="server returned 404: 404 page not found\n"9822026/10/10 19:01:50 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9832026/10/10 19:01:50 WARN Failed to register uploaded object key=d0m47733gkcca6l219qsskph05g1dr1f.narinfo error="server returned 404: 404 page not found\n"9842026/10/10 19:01:50 INFO Completed upload id=1 objects=6 duration=6.327374ms9852026/10/10 19:01:50 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete9862026/10/10 19:01:50 INFO Completed upload id=2 objects=6 duration=13.284695ms9872026/10/10 19:01:50 INFO Upload complete. (84ms)988=== NAME TestClientFallsBackToClosures989 client_pushes_test.go:112: Retrieved narinfo from S3:990 StorePath: /build/TestClientFallsBackToClosures379671089/001/store/d0m47733gkcca6l219qsskph05g1dr1f-shared-dep991 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst992 Compression: zstd993 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82994 NarSize: 136995 References: 996 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n997 client_pushes_test.go:112: Retrieved narinfo from S3:998 StorePath: /build/TestClientFallsBackToClosures379671089/001/store/vr0pca6b71y2dbzck4qgj3spkqhzylpi-a999 URL: nar/1hpacdl45ns8h9fp5f2avbn04vb051bifsmy70a7i2xdd7bmv66w.nar.zst1000 Compression: zstd1001 NarHash: sha256:1hpacdl45ns8h9fp5f2avbn04vb051bifsmy70a7i2xdd7bmv66w1002 NarSize: 2161003 References: /build/TestClientFallsBackToClosures379671089/001/store/d0m47733gkcca6l219qsskph05g1dr1f-shared-dep1004 CA: text:sha256:1g9r506v0rlamfkihy0xx6gi1bfvgcwcd78mjvc0p47s4cj38h2d1005 client_pushes_test.go:112: Retrieved narinfo from S3:1006 StorePath: /build/TestClientFallsBackToClosures379671089/001/store/vb8z0f5lvjxkpf0ixzv3lhg21lv7fiz4-b1007 URL: nar/1hpacdl45ns8h9fp5f2avbn04vb051bifsmy70a7i2xdd7bmv66w.nar.zst1008 Compression: zstd1009 NarHash: sha256:1hpacdl45ns8h9fp5f2avbn04vb051bifsmy70a7i2xdd7bmv66w1010 NarSize: 2161011 References: /build/TestClientFallsBackToClosures379671089/001/store/d0m47733gkcca6l219qsskph05g1dr1f-shared-dep1012 CA: text:sha256:1g9r506v0rlamfkihy0xx6gi1bfvgcwcd78mjvc0p47s4cj38h2d1013--- PASS: TestClientFallsBackToClosures (0.60s)1014=== CONT TestPush_RepeatedRootCommitsOnce10152026/10/10 19:01:50 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1016--- PASS: TestService_AuthMiddleware (0.60s)1017=== CONT TestDeduplicatedObjectsRecordedAsPending1018=== NAME TestPinProtectsFromGC1019 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC1280971878/001/store/xgq5gbnaw5wwld0nladbfsi9dxw3dsnk-pinned-file.txt1020 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC1280971878/001/store/hlahkfrcjvrnpjx3g3clqkxlgr079a8y-unpinned-file.txt1021--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.62s)1022=== CONT TestPush_CompleteCommitsEveryRoot10232026/10/10 19:01:50 INFO Aborted multipart uploads count=0 kept=010242026/10/10 19:01:50 INFO Received uploads request method=POST path=/api/pending_closures10252026/10/10 19:01:50 WARN Force mode enabled - objects will be deleted immediately without grace period10262026/10/10 19:01:50 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010272026/10/10 19:01:50 INFO Vacuumed table table=pending_closures10282026/10/10 19:01:50 INFO Vacuumed table table=pending_objects10292026/10/10 19:01:50 INFO Vacuumed table table=multipart_uploads10302026/10/10 19:01:50 INFO Vacuumed table table=closures10312026/10/10 19:01:50 INFO Vacuumed table table=objects1032--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.65s)1033=== CONT TestPushDedupSurvivesConcurrentGC10342026/10/10 19:01:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10352026/10/10 19:01:50 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZDMwNDgzOWYtMWJkYi00OTVmLWE4NDAtZGEyNWViMzE4ZWMxLmM5YTY5NTYzLTgwODYtNDFlZC1iOGNjLTM0MjJjNzYzYzgzZngxNzkxNjU4OTEwNDcyMDU3MDcx10362026/10/10 19:01:50 INFO Received uploads request method=POST path=/api/pending_closures10372026/10/10 19:01:50 INFO Aborted multipart uploads count=0 kept=010382026/10/10 19:01:50 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZDMwNDgzOWYtMWJkYi00OTVmLWE4NDAtZGEyNWViMzE4ZWMxLmM5YTY5NTYzLTgwODYtNDFlZC1iOGNjLTM0MjJjNzYzYzgzZngxNzkxNjU4OTEwNDcyMDU3MDcx parts=11039--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.58s)1040=== CONT TestPush_OverlappingRootsStoreOneRowPerKey10412026/10/10 19:01:50 WARN Force mode enabled - objects will be deleted immediately without grace period10422026/10/10 19:01:50 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010432026/10/10 19:01:50 INFO Received push request method=POST path=/api/pushes10442026/10/10 19:01:50 INFO Vacuumed table table=pending_closures10452026/10/10 19:01:50 INFO Vacuumed table table=pending_objects10462026/10/10 19:01:50 INFO Vacuumed table table=multipart_uploads10472026/10/10 19:01:50 INFO Vacuumed table table=closures10482026/10/10 19:01:50 INFO Vacuumed table table=objects10492026/10/10 19:01:50 INFO Received uploads request method=POST path=/api/pending_closures10502026/10/10 19:01:50 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10512026/10/10 19:01:50 INFO Uploading xgq5gbnaw5wwld0nladbfsi9dxw3dsnk-pinned-file.txt (128B)10522026/10/10 19:01:50 INFO Aborted multipart uploads count=0 kept=010532026/10/10 19:01:50 INFO Received uploads request method=POST path=/api/pending_closures10542026/10/10 19:01:50 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"10552026/10/10 19:01:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10562026/10/10 19:01:50 WARN Failed to register uploaded object key=xgq5gbnaw5wwld0nladbfsi9dxw3dsnk.ls error="server returned 404: 404 page not found\n"10572026/10/10 19:01:50 INFO Signed narinfos id=1 count=110582026/10/10 19:01:50 INFO Uploading 1 narinfos10592026/10/10 19:01:50 INFO Received complete push request method=POST path=/api/pushes/1/complete10602026/10/10 19:01:50 WARN Failed to register uploaded object key=xgq5gbnaw5wwld0nladbfsi9dxw3dsnk.narinfo error="server returned 404: 404 page not found\n"10612026/10/10 19:01:50 WARN Force mode enabled - objects will be deleted immediately without grace period10622026/10/10 19:01:50 INFO Completed push id=1 objects=3 duration=7.286623ms10632026/10/10 19:01:50 INFO Upload complete. (62ms)10642026/10/10 19:01:50 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=1 objects-failed-to-delete=010652026/10/10 19:01:50 INFO Vacuumed table table=pending_closures10662026/10/10 19:01:50 INFO Vacuumed table table=pending_objects10672026/10/10 19:01:50 INFO Vacuumed table table=multipart_uploads10682026/10/10 19:01:50 INFO Vacuumed table table=closures10692026/10/10 19:01:50 INFO Vacuumed table table=objects1070--- PASS: TestSweepSkipsRowsLockedByPush (0.48s)1071=== CONT TestGCMetrics1072=== RUN TestPush_RejectsBadRequests/root_not_in_objects1073=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1074=== RUN TestPush_RejectsBadRequests/no_roots1075=== PAUSE TestPush_RejectsBadRequests/no_roots1076=== RUN TestPush_RejectsBadRequests/no_objects1077=== PAUSE TestPush_RejectsBadRequests/no_objects1078=== RUN TestPush_RejectsBadRequests/bad_root1079=== PAUSE TestPush_RejectsBadRequests/bad_root1080=== CONT TestReadRedirectUsesPublicS3URL10812026/10/10 19:01:50 INFO Received push request method=POST path=/api/pushes10822026/10/10 19:01:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10832026/10/10 19:01:50 INFO Signed narinfos id=1 count=110842026/10/10 19:01:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10852026/10/10 19:01:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10862026/10/10 19:01:50 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"10872026/10/10 19:01:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10882026/10/10 19:01:50 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"10892026/10/10 19:01:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10902026/10/10 19:01:50 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=110912026/10/10 19:01:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10922026/10/10 19:01:50 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1093--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.29s)1094=== CONT TestReadProxyRangeRequest10952026/10/10 19:01:50 INFO Received uploads request method=POST path=/api/pending_closures10962026/10/10 19:01:50 INFO Aborted multipart uploads count=0 kept=010972026/10/10 19:01:50 INFO Received push request method=POST path=/api/pushes10982026/10/10 19:01:50 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10992026/10/10 19:01:50 INFO Uploading hlahkfrcjvrnpjx3g3clqkxlgr079a8y-unpinned-file.txt (128B)11002026/10/10 19:01:50 WARN Force mode enabled - objects will be deleted immediately without grace period11012026/10/10 19:01:50 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"11022026/10/10 19:01:50 INFO Received push request method=POST path=/api/pushes11032026/10/10 19:01:50 WARN Failed to register uploaded object key=hlahkfrcjvrnpjx3g3clqkxlgr079a8y.ls error="server returned 404: 404 page not found\n"11042026/10/10 19:01:50 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11052026/10/10 19:01:50 INFO Signed narinfos id=2 count=111062026/10/10 19:01:50 INFO Uploading 1 narinfos11072026/10/10 19:01:50 INFO Received complete push request method=POST path=/api/pushes/2/complete11082026/10/10 19:01:50 WARN Failed to register uploaded object key=hlahkfrcjvrnpjx3g3clqkxlgr079a8y.narinfo error="server returned 404: 404 page not found\n"11092026/10/10 19:01:50 INFO Completed push id=2 objects=3 duration=2.043338ms11102026/10/10 19:01:50 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."11112026/10/10 19:01:50 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."11122026/10/10 19:01:50 INFO Upload complete. (50ms)1113--- PASS: TestFailedS3DeleteKeepsTombstone (0.47s)1114=== CONT TestPendingCleanupUsesOneCutoff11152026/10/10 19:01:50 INFO Received complete push request method=POST path=/api/pushes/1/complete11162026/10/10 19:01:50 INFO Completed push id=1 objects=4 duration=9.694544ms11172026/10/10 19:01:50 INFO Received push request method=POST path=/api/pushes11182026/10/10 19:01:50 INFO Received push request method=POST path=/api/pushes11192026/10/10 19:01:50 INFO Starting cleanup of old closures method=DELETE path=/api/closures11202026/10/10 19:01:50 INFO Garbage collection started11212026/10/10 19:01:50 INFO Aborted multipart uploads count=0 kept=011222026/10/10 19:01:50 WARN Force mode enabled - objects will be deleted immediately without grace period11232026/10/10 19:01:50 INFO Aborted multipart uploads count=0 kept=011242026/10/10 19:01:50 WARN Force mode enabled - objects will be deleted immediately without grace period11252026/10/10 19:01:50 INFO Received uploads request method=POST path=/api/pending_closures11262026/10/10 19:01:50 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=011272026/10/10 19:01:50 INFO Vacuumed table table=pending_closures11282026/10/10 19:01:50 INFO Vacuumed table table=pending_objects1129--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.32s)11302026/10/10 19:01:50 INFO Vacuumed table table=multipart_uploads1131=== CONT TestReadRedirectKeepsNarinfoProxied11322026/10/10 19:01:50 INFO Vacuumed table table=closures11332026/10/10 19:01:50 INFO Vacuumed table table=objects1134--- PASS: TestGCSweepDeliversEachKeyOnce (0.35s)1135=== CONT TestReadProxyNarinfoAlreadyDecompressed11362026/10/10 19:01:50 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=011372026/10/10 19:01:50 INFO Vacuumed table table=pending_closures11382026-10-10 19:01:50.694 UTC [1037] ERROR: could not obtain lock on row in relation "closures"11392026-10-10 19:01:50.694 UTC [1037] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11402026-10-10 19:01:50.694 UTC [1037] ERROR: could not obtain lock on row in relation "closures"11412026-10-10 19:01:50.694 UTC [1037] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11422026-10-10 19:01:50.695 UTC [1037] ERROR: could not obtain lock on row in relation "closures"11432026-10-10 19:01:50.695 UTC [1037] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11442026-10-10 19:01:50.695 UTC [1037] ERROR: could not obtain lock on row in relation "closures"11452026-10-10 19:01:50.695 UTC [1037] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11462026-10-10 19:01:50.695 UTC [1037] ERROR: could not obtain lock on row in relation "closures"11472026-10-10 19:01:50.695 UTC [1037] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11482026/10/10 19:01:50 INFO Vacuumed table table=pending_objects11492026/10/10 19:01:50 INFO Vacuumed table table=multipart_uploads11502026/10/10 19:01:50 INFO Vacuumed table table=closures11512026/10/10 19:01:50 INFO Received push request method=POST path=/api/pushes11522026/10/10 19:01:50 INFO Vacuumed table table=objects1153--- PASS: TestPush_RootsAreLockedInByteOrder (0.35s)1154=== CONT TestReadRedirectNar11552026/10/10 19:01:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11562026/10/10 19:01:50 INFO Aborted multipart uploads count=0 kept=011572026/10/10 19:01:50 WARN Force mode enabled - objects will be deleted immediately without grace period11582026/10/10 19:01:50 INFO Received uploads request method=POST path=/api/pending_closures11592026/10/10 19:01:50 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=011602026/10/10 19:01:50 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZDMwNDgzOWYtMWJkYi00OTVmLWE4NDAtZGEyNWViMzE4ZWMxLjg2ZDY3ZGQ0LTJkNDItNDkyNi05Y2VlLTc0YmQ0OTEzNGU1NXgxNzkxNjU4OTEwMzI3MjI3NzYz parts=1211612026/10/10 19:01:50 INFO Received uploads request method=POST path=/api/pending_closures11622026/10/10 19:01:50 INFO Vacuumed table table=pending_closures11632026/10/10 19:01:50 INFO Vacuumed table table=pending_objects1164--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.89s)1165=== CONT TestReadProxyNarinfo11662026/10/10 19:01:50 INFO Vacuumed table table=multipart_uploads11672026/10/10 19:01:50 INFO Vacuumed table table=closures11682026/10/10 19:01:50 INFO Vacuumed table table=objects1169--- PASS: TestPushWaitsForSweepHoldingRow (0.90s)1170=== CONT TestReadProxyDisabled11712026/10/10 19:01:50 INFO Received complete push request method=POST path=/api/pushes/2/complete11722026/10/10 19:01:50 INFO Completed push id=2 objects=4 duration=3.751473ms11732026/10/10 19:01:50 INFO Aborted multipart uploads count=0 kept=011742026/10/10 19:01:50 INFO Received push request method=POST path=/api/pushes1175--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.42s)1176=== CONT TestIsValidCachePath1177=== RUN TestIsValidCachePath/narinfo1178=== PAUSE TestIsValidCachePath/narinfo1179=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1180=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1181=== RUN TestIsValidCachePath/nar_zst1182=== PAUSE TestIsValidCachePath/nar_zst1183=== RUN TestIsValidCachePath/nar_xz1184=== PAUSE TestIsValidCachePath/nar_xz1185=== RUN TestIsValidCachePath/nar_bz21186=== PAUSE TestIsValidCachePath/nar_bz21187=== RUN TestIsValidCachePath/nar_uncompressed1188=== PAUSE TestIsValidCachePath/nar_uncompressed1189=== RUN TestIsValidCachePath/ls1190=== PAUSE TestIsValidCachePath/ls1191=== RUN TestIsValidCachePath/log1192=== PAUSE TestIsValidCachePath/log1193=== RUN TestIsValidCachePath/realisation1194=== PAUSE TestIsValidCachePath/realisation1195=== RUN TestIsValidCachePath/nix-cache-info1196=== PAUSE TestIsValidCachePath/nix-cache-info1197=== RUN TestIsValidCachePath/index.html1198=== PAUSE TestIsValidCachePath/index.html1199=== RUN TestIsValidCachePath/traversal_parent1200=== PAUSE TestIsValidCachePath/traversal_parent1201=== RUN TestIsValidCachePath/traversal_in_middle1202=== PAUSE TestIsValidCachePath/traversal_in_middle1203=== RUN TestIsValidCachePath/invalid_char_e1204=== PAUSE TestIsValidCachePath/invalid_char_e1205=== RUN TestIsValidCachePath/invalid_char_u1206=== PAUSE TestIsValidCachePath/invalid_char_u1207=== RUN TestIsValidCachePath/random_path1208=== PAUSE TestIsValidCachePath/random_path1209=== RUN TestIsValidCachePath/empty1210=== PAUSE TestIsValidCachePath/empty1211=== RUN TestIsValidCachePath/leading_slash1212=== PAUSE TestIsValidCachePath/leading_slash1213=== RUN TestIsValidCachePath/wrong_extension1214=== PAUSE TestIsValidCachePath/wrong_extension1215=== RUN TestIsValidCachePath/short_hash1216=== PAUSE TestIsValidCachePath/short_hash1217=== CONT TestReadProxyRootRedirectsToIndexHTML12182026/10/10 19:01:50 WARN Force mode enabled - objects will be deleted immediately without grace period12192026/10/10 19:01:50 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012202026/10/10 19:01:50 INFO Vacuumed table table=pending_closures12212026/10/10 19:01:50 INFO Vacuumed table table=pending_objects12222026/10/10 19:01:50 INFO Vacuumed table table=multipart_uploads12232026/10/10 19:01:50 INFO Vacuumed table table=closures12242026/10/10 19:01:50 INFO Received complete push request method=POST path=/api/pushes/1/complete12252026/10/10 19:01:50 INFO Vacuumed table table=objects1226--- PASS: TestGCSweepSkipsPendingObjects (0.38s)1227=== CONT TestParseSingleRange1228=== RUN TestParseSingleRange/none1229=== PAUSE TestParseSingleRange/none1230=== RUN TestParseSingleRange/unknown_unit1231=== PAUSE TestParseSingleRange/unknown_unit1232=== RUN TestParseSingleRange/multi-range_ignored1233=== PAUSE TestParseSingleRange/multi-range_ignored1234=== RUN TestParseSingleRange/malformed_no_dash1235=== PAUSE TestParseSingleRange/malformed_no_dash1236=== RUN TestParseSingleRange/malformed_both_empty1237=== PAUSE TestParseSingleRange/malformed_both_empty1238=== RUN TestParseSingleRange/malformed_end_before_start1239=== PAUSE TestParseSingleRange/malformed_end_before_start1240=== RUN TestParseSingleRange/closed1241=== PAUSE TestParseSingleRange/closed1242=== RUN TestParseSingleRange/open-ended1243=== PAUSE TestParseSingleRange/open-ended1244=== RUN TestParseSingleRange/end_clamped_to_size1245=== PAUSE TestParseSingleRange/end_clamped_to_size1246=== RUN TestParseSingleRange/suffix1247=== PAUSE TestParseSingleRange/suffix1248=== RUN TestParseSingleRange/suffix_exceeds_size1249=== PAUSE TestParseSingleRange/suffix_exceeds_size1250=== RUN TestParseSingleRange/single_byte1251=== PAUSE TestParseSingleRange/single_byte1252=== RUN TestParseSingleRange/start_past_EOF1253=== PAUSE TestParseSingleRange/start_past_EOF1254=== RUN TestParseSingleRange/start_far_past_EOF1255=== PAUSE TestParseSingleRange/start_far_past_EOF1256=== CONT TestReadProxyConditionalGet12572026/10/10 19:01:50 INFO Completed push id=1 objects=4 duration=14.209722ms12582026/10/10 19:01:50 INFO Received uploads request method=POST path=/api/pending_closures1259--- PASS: TestPush_RepeatedRootCommitsOnce (0.34s)1260=== CONT TestPresentNotReportedWhileGCDeletesClosure1261=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1262=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1263=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1264=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1265=== CONT TestReadProxyOutlastsServerWriteTimeout1266--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.35s)1267=== CONT TestPresentRefreshesOnlyStaleClosures12682026/10/10 19:01:50 INFO Received push request method=POST path=/api/pushes12692026/10/10 19:01:50 INFO Received complete push request method=POST path=/api/pushes/1/complete1270--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.50s)1271=== CONT TestReadProxyHead12722026/10/10 19:01:50 INFO Completed push id=1 objects=6 duration=13.031272ms1273--- PASS: TestPush_CompleteCommitsEveryRoot (0.37s)1274=== CONT TestPresentReportsOnlyClosureRoots12752026/10/10 19:01:50 INFO Received push request method=POST path=/api/pushes12762026/10/10 19:01:50 INFO Received uploads request method=POST path=/api/pending_closures1277--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.34s)1278=== CONT TestReadProxyInvalidPath1279--- PASS: TestReadRedirectUsesPublicS3URL (0.32s)1280=== CONT TestCreatePin_ReservedPins12812026/10/10 19:01:50 INFO Aborted multipart uploads count=0 kept=012822026/10/10 19:01:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12832026/10/10 19:01:50 WARN Force mode enabled - objects will be deleted immediately without grace period12842026/10/10 19:01:50 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012852026/10/10 19:01:50 INFO Vacuumed table table=pending_closures12862026/10/10 19:01:50 INFO Vacuumed table table=pending_objects12872026/10/10 19:01:50 INFO Vacuumed table table=multipart_uploads12882026/10/10 19:01:50 INFO Vacuumed table table=closures12892026/10/10 19:01:50 INFO Vacuumed table table=objects12902026/10/10 19:01:50 INFO Aborted multipart uploads count=0 kept=01291--- PASS: TestGCMetrics (0.35s)1292=== CONT TestReadProxy40412932026/10/10 19:01:50 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZDMwNDgzOWYtMWJkYi00OTVmLWE4NDAtZGEyNWViMzE4ZWMxLjNjNTI1ODc1LWE1NjAtNDY2MC1hMWRkLWQyMTNmMGJlNzdkMHgxNzkxNjU4OTEwNTExODk1NzM1 parts=1212942026/10/10 19:01:50 INFO Received uploads request method=POST path=/api/pending_closures1295--- PASS: TestReadProxyRangeRequest (0.32s)1296=== CONT TestOrphanedObjectsGCStressTest12972026/10/10 19:01:50 INFO Received uploads request method=POST path=/api/pending_closures12982026/10/10 19:01:50 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=012992026/10/10 19:01:50 INFO Vacuumed table table=pending_closures13002026/10/10 19:01:50 INFO Vacuumed table table=pending_objects13012026/10/10 19:01:50 INFO Vacuumed table table=multipart_uploads13022026/10/10 19:01:50 INFO Received uploads request method=POST path=/api/pending_closures13032026/10/10 19:01:50 INFO Vacuumed table table=closures13042026/10/10 19:01:50 INFO Vacuumed table table=objects13052026/10/10 19:01:50 INFO Aborted multipart uploads count=0 kept=013062026/10/10 19:01:50 INFO Received uploads request method=POST path=/api/pending_closures13072026/10/10 19:01:50 WARN Force mode enabled - objects will be deleted immediately without grace period13082026/10/10 19:01:50 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013092026/10/10 19:01:50 INFO Vacuumed table table=pending_closures13102026/10/10 19:01:50 INFO Vacuumed table table=pending_objects13112026/10/10 19:01:50 INFO Vacuumed table table=multipart_uploads13122026/10/10 19:01:50 INFO Received cleanup request method=DELETE path=/api/pending_closures13132026/10/10 19:01:50 INFO Vacuumed table table=closures13142026/10/10 19:01:50 INFO Vacuumed table table=objects1315--- PASS: TestPushDedupSurvivesConcurrentGC (0.45s)1316=== CONT TestOrphanedObjectsGC1317--- PASS: TestReadRedirectKeepsNarinfoProxied (0.27s)1318=== CONT TestReadProxyNarStreaming1319--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.28s)1320=== CONT TestObjectStatsLargeCommit1321--- PASS: TestReadRedirectNar (0.29s)1322=== CONT TestObjectStatsTrigger1323--- PASS: TestReadProxyDisabled (0.27s)1324=== CONT TestCacheConfigHandler1325=== RUN TestCacheConfigHandler/full_config,_no_issuer1326=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1327=== RUN TestCacheConfigHandler/no_cache_url_configured1328=== PAUSE TestCacheConfigHandler/no_cache_url_configured1329=== RUN TestCacheConfigHandler/no_signing_keys1330=== PAUSE TestCacheConfigHandler/no_signing_keys1331=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1332=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1333=== CONT TestClientMultipleUploads13342026-10-10 19:01:51.013 UTC [1061] ERROR: Push does not exist: id=113352026-10-10 19:01:51.013 UTC [1061] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE13362026-10-10 19:01:51.013 UTC [1061] STATEMENT: SELECT commit_push($1)1337--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.63s)1338=== CONT TestService_verifyS3Integrity1339--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.31s)1340=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT13412026/10/10 19:01:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37359/oidc1342--- PASS: TestReadProxyConditionalGet (0.33s)1343=== CONT TestClientIntegration13442026/10/10 19:01:51 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1345--- PASS: TestReadProxyNarinfo (0.39s)1346=== CONT TestCompleteMultipartUnregistered1347--- PASS: TestPresentRefreshesOnlyStaleClosures (0.35s)1348=== CONT TestClientErrorHandling1349=== RUN TestClientErrorHandling/InvalidStorePath1350=== PAUSE TestClientErrorHandling/InvalidStorePath1351=== RUN TestClientErrorHandling/InvalidAuthToken1352=== PAUSE TestClientErrorHandling/InvalidAuthToken1353=== RUN TestClientErrorHandling/ServerNotAvailable1354=== PAUSE TestClientErrorHandling/ServerNotAvailable1355=== CONT TestMetricsInventory13562026/10/10 19:01:51 INFO lead: released remote=192.0.2.1:12341357--- PASS: TestLeadEndsOnShutdown (1.39s)1358=== CONT TestClientCADerivations1359--- PASS: TestReadProxyHead (0.34s)1360=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1361--- PASS: TestPresentReportsOnlyClosureRoots (0.36s)1362=== CONT TestCacheStatsHandler1363--- PASS: TestReadProxyInvalidPath (0.34s)1364=== CONT TestMultipartCleanup1365--- PASS: TestReadProxy404 (0.32s)1366=== CONT TestServerTLSConfig1367=== RUN TestServerTLSConfig/no_client_CA1368=== PAUSE TestServerTLSConfig/no_client_CA1369=== RUN TestServerTLSConfig/missing_CA_file1370=== PAUSE TestServerTLSConfig/missing_CA_file1371=== RUN TestServerTLSConfig/not_a_PEM_file1372=== PAUSE TestServerTLSConfig/not_a_PEM_file1373=== CONT TestIsValidUploadKey1374=== RUN TestIsValidUploadKey/narinfo1375=== PAUSE TestIsValidUploadKey/narinfo1376=== RUN TestIsValidUploadKey/nar_zst1377=== PAUSE TestIsValidUploadKey/nar_zst1378=== RUN TestIsValidUploadKey/nar_xz1379=== PAUSE TestIsValidUploadKey/nar_xz1380=== RUN TestIsValidUploadKey/nar_plain1381=== PAUSE TestIsValidUploadKey/nar_plain1382=== RUN TestIsValidUploadKey/listing1383=== PAUSE TestIsValidUploadKey/listing1384=== RUN TestIsValidUploadKey/build_log1385=== PAUSE TestIsValidUploadKey/build_log1386=== RUN TestIsValidUploadKey/build_log_home-manager_file1387=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1388=== RUN TestIsValidUploadKey/build_log_plus_in_name1389=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1390=== RUN TestIsValidUploadKey/build_log_question_mark1391=== PAUSE TestIsValidUploadKey/build_log_question_mark1392=== RUN TestIsValidUploadKey/build_log_equals1393=== PAUSE TestIsValidUploadKey/build_log_equals1394=== RUN TestIsValidUploadKey/realisation1395=== PAUSE TestIsValidUploadKey/realisation1396=== RUN TestIsValidUploadKey/realisation_plus_in_output1397=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1398=== RUN TestIsValidUploadKey/nix-cache-info1399=== PAUSE TestIsValidUploadKey/nix-cache-info1400=== RUN TestIsValidUploadKey/index.html1401=== PAUSE TestIsValidUploadKey/index.html1402=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1403=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1404=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1405=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1406=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1407=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1408=== RUN TestIsValidUploadKey/traversal1409=== PAUSE TestIsValidUploadKey/traversal1410=== RUN TestIsValidUploadKey/traversal_nar1411=== PAUSE TestIsValidUploadKey/traversal_nar1412=== RUN TestIsValidUploadKey/absolute1413=== PAUSE TestIsValidUploadKey/absolute1414=== RUN TestIsValidUploadKey/empty_key1415=== PAUSE TestIsValidUploadKey/empty_key1416=== RUN TestIsValidUploadKey/unknown_type1417=== PAUSE TestIsValidUploadKey/unknown_type1418=== CONT TestService_NativeMTLS14192026/10/10 19:01:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1420--- PASS: TestReadProxyNarStreaming (0.32s)1421=== CONT TestProxyWriteTimeout1422=== RUN TestProxyWriteTimeout/narinfo1423=== PAUSE TestProxyWriteTimeout/narinfo1424=== RUN TestProxyWriteTimeout/1_GiB_nar1425=== PAUSE TestProxyWriteTimeout/1_GiB_nar1426=== RUN TestProxyWriteTimeout/10_GiB_nar1427=== PAUSE TestProxyWriteTimeout/10_GiB_nar1428=== RUN TestProxyWriteTimeout/unknown_size1429=== PAUSE TestProxyWriteTimeout/unknown_size1430=== CONT TestMetricsCommit14312026/10/10 19:01:51 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZDMwNDgzOWYtMWJkYi00OTVmLWE4NDAtZGEyNWViMzE4ZWMxLjY0ODRjNTNkLTA4NDgtNGViZi05NjZlLThjMDJkNzdlYzBmYngxNzkxNjU4OTEwOTE0MzE5NTY1 error="Get \"http://127.0.0.1:1/bucket28/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"14322026/10/10 19:01:51 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZDMwNDgzOWYtMWJkYi00OTVmLWE4NDAtZGEyNWViMzE4ZWMxLmIzOTZkNjgzLTQ1NDktNDc0NS1hZGQ1LWM2ZWVlMDU2YmNmYXgxNzkxNjU4OTEwOTA5MjI2NDAx parts=1214332026/10/10 19:01:51 INFO Received cleanup request method=DELETE path=/api/pending_closures14342026/10/10 19:01:51 INFO Aborted multipart uploads count=1 kept=01435--- PASS: TestRedundantMultipartUpload (1.18s)1436=== CONT TestCacheConfigHandlerMaxNarSize1437--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1438=== CONT TestService_readinessHandler1439--- PASS: TestObjectStatsTrigger (0.33s)1440=== CONT TestNARDeduplicationMetadataUploadBug14412026/10/10 19:01:51 INFO Received uploads request method=POST path=/api/pending_closures14422026/10/10 19:01:51 INFO Received uploads request method=POST path=/api/pending_closures1443=== NAME TestClientMultipleUploads1444 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads3383831350/001/store/fqw528y2p8cxjgbn468zs2habs99zymd-test-file-0.txt1445--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.34s)1446=== CONT TestGenerateLandingPage1447--- PASS: TestGenerateLandingPage (0.00s)1448=== CONT TestCreatePendingClosureRejectsOversizedNAR14492026/10/10 19:01:51 INFO Received uploads request method=POST path=/api/pending_closures1450--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1451=== CONT TestService_createPendingClosureHandler14522026/10/10 19:01:51 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14532026/10/10 19:01:51 WARN Refused reserved pin name=worker-x86_64-linux14542026/10/10 19:01:51 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14552026/10/10 19:01:51 INFO Received create pin request method=POST path=/api/pins/my-app14562026/10/10 19:01:51 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1457--- PASS: TestCreatePin_ReservedPins (0.53s)1458=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1459=== NAME TestClientMultipleUploads1460 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads3383831350/001/store/pgzwr25rknx1v666a157ssnlp854g1y8-test-file-1.txt14612026/10/10 19:01:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14622026/10/10 19:01:51 INFO lead: released remote=192.0.2.1:123414632026/10/10 19:01:51 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1464--- PASS: TestCompleteMultipartUnregistered (0.32s)1465=== CONT TestService_healthCheckHandler1466=== NAME TestClientMultipleUploads1467 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads3383831350/001/store/r0qsbpaisybpldyqk2fr8ssa4j6wnmwv-test-file-2.txt1468=== NAME TestClientIntegration1469 client_integration_test.go:286: Created store path: /build/TestClientIntegration2033788409/002/store/3rhgl1hj50jsyrz6025257c9kc0bwcj4-test-file.txt1470--- PASS: TestMetricsInventory (0.35s)1471=== CONT TestService_cleanupPendingClosuresHandler14722026/10/10 19:01:51 INFO lead: acquired remote=192.0.2.1:123414732026/10/10 19:01:51 INFO Received uploads request method=POST path=/api/pending_closures14742026/10/10 19:01:51 INFO Received push request method=POST path=/api/pushes1475--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.37s)1476=== CONT TestService_AuthMiddleware_OIDC14772026/10/10 19:01:51 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)14782026/10/10 19:01:51 INFO Uploading pgzwr25rknx1v666a157ssnlp854g1y8-test-file-1.txt (160B)14792026/10/10 19:01:51 INFO Uploading r0qsbpaisybpldyqk2fr8ssa4j6wnmwv-test-file-2.txt (160B)14802026/10/10 19:01:51 INFO Uploading fqw528y2p8cxjgbn468zs2habs99zymd-test-file-0.txt (160B)14812026/10/10 19:01:51 WARN Failed to register uploaded object key=pgzwr25rknx1v666a157ssnlp854g1y8.ls error="server returned 404: 404 page not found\n"14822026/10/10 19:01:51 INFO Received push request method=POST path=/api/pushes14832026/10/10 19:01:51 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"14842026/10/10 19:01:51 WARN Failed to register uploaded object key=fqw528y2p8cxjgbn468zs2habs99zymd.ls error="server returned 404: 404 page not found\n"14852026/10/10 19:01:51 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"14862026/10/10 19:01:51 WARN Failed to register uploaded object key=r0qsbpaisybpldyqk2fr8ssa4j6wnmwv.ls error="server returned 404: 404 page not found\n"14872026/10/10 19:01:51 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14882026/10/10 19:01:51 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"14892026/10/10 19:01:51 INFO Signed narinfos id=1 count=314902026/10/10 19:01:51 INFO Uploading 3 narinfos14912026/10/10 19:01:51 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14922026/10/10 19:01:51 INFO Uploading 3rhgl1hj50jsyrz6025257c9kc0bwcj4-test-file.txt (152B)14932026/10/10 19:01:51 WARN Failed to register uploaded object key=r0qsbpaisybpldyqk2fr8ssa4j6wnmwv.narinfo error="server returned 404: 404 page not found\n"14942026/10/10 19:01:51 WARN Failed to register uploaded object key=pgzwr25rknx1v666a157ssnlp854g1y8.narinfo error="server returned 404: 404 page not found\n"14952026/10/10 19:01:51 INFO Received complete push request method=POST path=/api/pushes/1/complete14962026/10/10 19:01:51 WARN Failed to register uploaded object key=fqw528y2p8cxjgbn468zs2habs99zymd.narinfo error="server returned 404: 404 page not found\n"14972026/10/10 19:01:51 WARN Failed to register uploaded object key=3rhgl1hj50jsyrz6025257c9kc0bwcj4.ls error="server returned 404: 404 page not found\n"14982026/10/10 19:01:51 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14992026/10/10 19:01:51 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15002026/10/10 19:01:51 INFO Signed narinfos id=1 count=115012026/10/10 19:01:51 INFO Uploading 1 narinfos1502--- PASS: TestCacheStatsHandler (0.35s)1503=== CONT TestService_ReadScope_PublicByDefault15042026/10/10 19:01:51 INFO Completed push id=1 objects=9 duration=6.296475ms15052026/10/10 19:01:51 INFO Upload complete. (62ms)1506=== NAME TestClientMultipleUploads1507 client_integration_test.go:369: Uploaded 3 paths in 92.8178ms15082026/10/10 19:01:51 INFO Received complete push request method=POST path=/api/pushes/1/complete15092026/10/10 19:01:51 WARN Failed to register uploaded object key=3rhgl1hj50jsyrz6025257c9kc0bwcj4.narinfo error="server returned 404: 404 page not found\n"15102026/10/10 19:01:51 INFO Received uploads request method=POST path=/api/pending_closures1511--- PASS: TestClientMultipleUploads (0.54s)1512=== CONT TestService_RequireScope_OIDC15132026/10/10 19:01:51 INFO Completed push id=1 objects=3 duration=6.955179ms15142026/10/10 19:01:51 INFO Upload complete. (59ms)1515=== NAME TestClientCADerivations1516 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1785690448/001/store/f9l9b2ilngjmvra6s585r7ig7gwligi6-ca-test15172026/10/10 19:01:51 WARN mTLS auth: subject not in bound subjects subject="CN=reader"15182026/10/10 19:01:51 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1519--- PASS: TestService_NativeMTLS (0.33s)1520=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1521=== NAME TestOrphanedObjectsGC1522 orphaned_objects_gc_test.go:287: GC Test Summary:1523 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1524 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1525 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1526 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1527 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1528--- PASS: TestOrphanedObjectsGC (0.63s)1529=== CONT TestService_AuthMiddleware_MTLSProxyHeader15302026/10/10 19:01:51 INFO All 1 paths already cached1531=== NAME TestClientIntegration1532 client_integration_test.go:312: Retrieved narinfo from S3:1533 StorePath: /build/TestClientIntegration2033788409/002/store/3rhgl1hj50jsyrz6025257c9kc0bwcj4-test-file.txt1534 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1535 Compression: zstd1536 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11537 NarSize: 1521538 References: 1539 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk115402026/10/10 19:01:51 INFO Received push request method=POST path=/api/pushes1541 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1542 client_integration_test.go:313: Decompressed .ls content (64 bytes):1543 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1544 client_integration_test.go:316: Testing garbage collection...1545--- PASS: TestDeleteClosuresRacingPins (1.76s)1546=== CONT TestService_ReadAuthMiddleware1547=== NAME TestClientCADerivations1548 client_ca_test.go:139: Found 1 dependencies (including self)15492026/10/10 19:01:51 INFO Received complete push request method=POST path=/api/pushes/1/complete15502026/10/10 19:01:51 WARN readiness check failed error="closed pool"1551--- PASS: TestService_readinessHandler (0.31s)1552=== CONT TestUploadHandlersRejectInvalidKeys1553=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1554=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1555=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1556=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1557=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1558=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1559=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1560=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1561=== CONT TestResolveDBConnectionString/flag_wins1562=== CONT TestGCEndsOnShutdown/before_the_run15632026/10/10 19:01:51 INFO Completed push id=1 objects=4 duration=8.216031ms15642026/10/10 19:01:51 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15652026/10/10 19:01:51 INFO Completed upload id=2 objects=2 duration=1.479513ms1566--- PASS: TestMetricsCommit (0.34s)1567=== CONT TestResolveDBConnectionString/nothing_configured1568=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1569=== CONT TestResolveDBConnectionString/missing_file_is_an_error1570=== CONT TestResolveDBConnectionString/file_when_flag_empty1571=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1572--- PASS: TestResolveDBConnectionString (0.00s)1573 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1574 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1575 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1576 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1577 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)15782026/10/10 19:01:51 INFO Starting cleanup of old closures method=DELETE path=/api/closures15792026/10/10 19:01:51 INFO Garbage collection started15802026/10/10 19:01:51 INFO Aborted multipart uploads count=0 kept=015812026/10/10 19:01:51 WARN Force mode enabled - objects will be deleted immediately without grace period15822026/10/10 19:01:51 INFO Received uploads request method=POST path=/api/pending_closures15832026/10/10 19:01:51 INFO Received uploads request method=POST path=/api/pending_closures15842026/10/10 19:01:51 INFO Received uploads request method=POST path=/api/pending_closures15852026/10/10 19:01:51 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=015862026/10/10 19:01:51 INFO Received cleanup request method=DELETE path=/api/pending_closures15872026/10/10 19:01:51 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket76/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""15882026/10/10 19:01:51 INFO Aborted multipart uploads count=0 kept=115892026/10/10 19:01:51 INFO Vacuumed table table=pending_closures15902026/10/10 19:01:51 INFO Vacuumed table table=pending_objects15912026/10/10 19:01:51 INFO Received cleanup request method=DELETE path=/api/pending_closures15922026/10/10 19:01:51 INFO Vacuumed table table=multipart_uploads15932026/10/10 19:01:51 INFO Aborted multipart uploads count=1 kept=015942026/10/10 19:01:51 INFO Vacuumed table table=closures15952026/10/10 19:01:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15962026/10/10 19:01:51 INFO Vacuumed table table=objects1597--- PASS: TestMultipartCleanup (0.48s)1598=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1599=== NAME TestNARDeduplicationMetadataUploadBug1600 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1623184141/001/store/sd1yy7k98lwhvqxxp05csvyi98mr7n0n-file1.txt16012026/10/10 19:01:51 INFO Received uploads request method=POST path=/api/pending_closures16022026/10/10 19:01:51 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZDMwNDgzOWYtMWJkYi00OTVmLWE4NDAtZGEyNWViMzE4ZWMxLmQzNDhhZGFkLTM0MjAtNDUxZi05YzI1LTFjOGFhYzg5NGYxMHgxNzkxNjU4OTExMzU4MTcwMDUy parts=1016032026/10/10 19:01:51 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16042026/10/10 19:01:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34249/oidc16052026/10/10 19:01:51 INFO Completed upload id=1 objects=2 duration=3.375289ms16062026/10/10 19:01:51 INFO Received uploads request method=POST path=/api/pending_closures16072026/10/10 19:01:51 INFO Received uploads request method=POST path=/api/pending_closures16082026/10/10 19:01:51 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo16092026/10/10 19:01:51 WARN Found objects in DB but missing from S3, will re-upload count=11610--- PASS: TestService_verifyS3Integrity (0.68s)1611=== CONT TestPendingClosureWriteTimeout/empty1612=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1613--- PASS: TestService_healthCheckHandler (0.26s)1614=== CONT TestPendingClosureWriteTimeout/670k_objects1615=== CONT TestPendingClosureWriteTimeout/400_objects1616=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16172026/10/10 19:01:51 INFO Received uploads request method=POST path=/16182026/10/10 19:01:51 INFO Received push request method=POST path=/api/pushes16192026/10/10 19:01:51 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16202026/10/10 19:01:51 INFO Uploading f9l9b2ilngjmvra6s585r7ig7gwligi6-ca-test (144B)16212026/10/10 19:01:51 WARN Failed to register uploaded object key=log/2gcn3c105mfb9yn8rlk027ad7895vn32-ca-test.drv error="server returned 404: 404 page not found\n"16222026/10/10 19:01:51 WARN Failed to register uploaded object key=f9l9b2ilngjmvra6s585r7ig7gwligi6.ls error="server returned 404: 404 page not found\n"16232026/10/10 19:01:51 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16242026/10/10 19:01:51 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16252026/10/10 19:01:51 INFO Received cleanup request method=DELETE path=/api/pending_closures16262026/10/10 19:01:51 INFO Signed narinfos id=1 count=116272026/10/10 19:01:51 INFO Uploading 1 narinfos16282026/10/10 19:01:51 INFO Aborted multipart uploads count=0 kept=016292026/10/10 19:01:51 INFO Received complete push request method=POST path=/api/pushes/1/complete16302026/10/10 19:01:51 INFO Received uploads request method=POST path=/api/pending_closures16312026/10/10 19:01:51 WARN Failed to register uploaded object key=f9l9b2ilngjmvra6s585r7ig7gwligi6.narinfo error="server returned 404: 404 page not found\n"16322026/10/10 19:01:51 INFO Completed push id=1 objects=4 duration=6.210154ms16332026/10/10 19:01:51 INFO Upload complete. (101ms)16342026/10/10 19:01:51 INFO Received cleanup request method=DELETE path=/api/pending_closures1635=== NAME TestClientCADerivations1636 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1785690448/001/store/f9l9b2ilngjmvra6s585r7ig7gwligi6-ca-test1637 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1638 Compression: zstd1639 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1640 NarSize: 1441641 References: 1642 Deriver: /build/TestClientCADerivations1785690448/001/store/2gcn3c105mfb9yn8rlk027ad7895vn32-ca-test.drv1643 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1644 client_ca_test.go:185: Checking for realisation files in S3...16452026/10/10 19:01:51 INFO Aborted multipart uploads count=1 kept=01646 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1647 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache16482026/10/10 19:01:51 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16492026-10-10 19:01:51.735 UTC [1359] ERROR: Closure does not exist: id=116502026-10-10 19:01:51.735 UTC [1359] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE16512026-10-10 19:01:51.735 UTC [1359] STATEMENT: -- name: CommitPendingClosure :one1652 SELECT commit_pending_closure($1::bigint)::bigint1653 1654--- PASS: TestService_cleanupPendingClosuresHandler (0.26s)1655=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16562026/10/10 19:01:51 INFO Received request for more parts method=POST path=/16572026/10/10 19:01:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37413/oidc1658--- PASS: TestService_ReadScope_PublicByDefault (0.21s)1659=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16602026/10/10 19:01:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16612026/10/10 19:01:51 INFO Received complete multipart upload request method=POST path=/16622026/10/10 19:01:51 INFO Received push request method=POST path=/api/pushes16632026/10/10 19:01:51 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16642026/10/10 19:01:51 INFO Uploading sd1yy7k98lwhvqxxp05csvyi98mr7n0n-file1.txt (160B)16652026/10/10 19:01:51 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16662026/10/10 19:01:51 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"16672026/10/10 19:01:51 WARN Failed to register uploaded object key=sd1yy7k98lwhvqxxp05csvyi98mr7n0n.ls error="server returned 404: 404 page not found\n"16682026/10/10 19:01:51 INFO Signed narinfos id=1 count=116692026/10/10 19:01:51 INFO Uploading 1 narinfos16702026/10/10 19:01:51 INFO Received complete push request method=POST path=/api/pushes/1/complete16712026/10/10 19:01:51 WARN Failed to register uploaded object key=sd1yy7k98lwhvqxxp05csvyi98mr7n0n.narinfo error="server returned 404: 404 page not found\n"16722026/10/10 19:01:51 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16732026/10/10 19:01:51 WARN mTLS auth: bound subjects configured but subject DN unavailable16742026/10/10 19:01:51 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1675--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.20s)1676=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows16772026/10/10 19:01:51 INFO Completed push id=1 objects=3 duration=6.633857ms16782026/10/10 19:01:51 INFO Upload complete. (61ms)1679=== NAME TestNARDeduplicationMetadataUploadBug1680 metadata_upload_test.go:54: Retrieved narinfo from S3:1681 StorePath: /build/TestNARDeduplicationMetadataUploadBug1623184141/001/store/sd1yy7k98lwhvqxxp05csvyi98mr7n0n-file1.txt1682 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1683 Compression: zstd1684 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1685 NarSize: 1601686 References: 1687 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1688 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1689 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1690 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1691--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.21s)1692=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1693--- PASS: TestService_ReadAuthMiddleware (0.21s)1694=== CONT TestPush_RejectsBadRequests/root_not_in_objects16952026/10/10 19:01:51 INFO Received push request method=POST path=/api/pushes1696=== CONT TestPush_RejectsBadRequests/no_objects16972026/10/10 19:01:51 INFO Received push request method=POST path=/api/pushes1698=== CONT TestPush_RejectsBadRequests/bad_root16992026/10/10 19:01:51 INFO Received push request method=POST path=/api/pushes1700=== CONT TestPush_RejectsBadRequests/no_roots17012026/10/10 19:01:51 INFO Received push request method=POST path=/api/pushes1702=== CONT TestIsValidCachePath/narinfo1703=== CONT TestIsValidCachePath/index.html1704=== CONT TestIsValidCachePath/short_hash1705--- PASS: TestPush_RejectsBadRequests (0.25s)1706 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1707 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1708 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1709 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1710=== CONT TestIsValidCachePath/wrong_extension1711=== CONT TestIsValidCachePath/leading_slash1712=== CONT TestIsValidCachePath/empty1713=== CONT TestIsValidCachePath/invalid_char_u1714=== CONT TestIsValidCachePath/invalid_char_e1715=== CONT TestIsValidCachePath/nar_uncompressed1716=== CONT TestIsValidCachePath/traversal_in_middle1717=== CONT TestIsValidCachePath/nix-cache-info1718=== CONT TestIsValidCachePath/traversal_parent1719=== CONT TestIsValidCachePath/realisation1720=== CONT TestIsValidCachePath/random_path1721=== CONT TestIsValidCachePath/ls1722=== CONT TestIsValidCachePath/nar_xz1723=== CONT TestIsValidCachePath/nar_bz21724=== CONT TestIsValidCachePath/nar_zst1725=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1726=== CONT TestIsValidCachePath/log1727--- PASS: TestIsValidCachePath (0.00s)1728 --- PASS: TestIsValidCachePath/narinfo (0.00s)1729 --- PASS: TestIsValidCachePath/index.html (0.00s)1730 --- PASS: TestIsValidCachePath/short_hash (0.00s)1731 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1732 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1733 --- PASS: TestIsValidCachePath/empty (0.00s)1734 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1735 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1736 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1737 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1738 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1739 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1740 --- PASS: TestIsValidCachePath/realisation (0.00s)1741 --- PASS: TestIsValidCachePath/random_path (0.00s)1742 --- PASS: TestIsValidCachePath/ls (0.00s)1743 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1744 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1745 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1746 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1747 --- PASS: TestIsValidCachePath/log (0.00s)1748=== CONT TestParseSingleRange/none1749=== CONT TestParseSingleRange/start_far_past_EOF1750=== CONT TestParseSingleRange/single_byte1751=== CONT TestParseSingleRange/suffix_exceeds_size1752=== CONT TestParseSingleRange/start_past_EOF1753=== CONT TestParseSingleRange/end_clamped_to_size1754=== CONT TestParseSingleRange/open-ended1755=== CONT TestParseSingleRange/closed1756=== CONT TestParseSingleRange/malformed_end_before_start1757=== CONT TestParseSingleRange/malformed_both_empty1758=== CONT TestParseSingleRange/malformed_no_dash1759=== CONT TestParseSingleRange/multi-range_ignored1760=== CONT TestParseSingleRange/unknown_unit1761=== CONT TestParseSingleRange/suffix1762--- PASS: TestParseSingleRange (0.00s)1763 --- PASS: TestParseSingleRange/none (0.00s)1764 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1765 --- PASS: TestParseSingleRange/single_byte (0.00s)1766 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1767 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1768 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1769 --- PASS: TestParseSingleRange/open-ended (0.00s)1770 --- PASS: TestParseSingleRange/closed (0.00s)1771 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1772 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1773 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1774 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1775 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1776 --- PASS: TestParseSingleRange/suffix (0.00s)1777=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1778=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1779=== NAME TestNARDeduplicationMetadataUploadBug1780 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1623184141/001/store/r9wfrdryavr8x3gn7k8hd1m34g3y0csn-file2.txt1781=== CONT TestCacheConfigHandler/full_config,_no_issuer1782=== CONT TestCacheConfigHandler/no_signing_keys1783=== CONT TestCacheConfigHandler/no_cache_url_configured1784=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1785--- PASS: TestCacheConfigHandler (0.00s)1786 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1787 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1788 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1789 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1790=== CONT TestClientErrorHandling/InvalidStorePath1791=== NAME TestClientCADerivations1792 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1793 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1794 error: binary cache 's3://bucket73?endpoint=http://localhost:45291®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1785690448/001/store'1795 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11796--- PASS: TestClientCADerivations (0.68s)1797=== CONT TestClientErrorHandling/InvalidAuthToken1798=== CONT TestClientErrorHandling/ServerNotAvailable17992026/10/10 19:01:51 INFO Aborted multipart uploads count=0 kept=018002026/10/10 19:01:51 INFO Received push request method=POST path=/api/pushes18012026/10/10 19:01:51 WARN Force mode enabled - objects will be deleted immediately without grace period18022026/10/10 19:01:51 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)18032026/10/10 19:01:51 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18042026/10/10 19:01:51 WARN Failed to register uploaded object key=r9wfrdryavr8x3gn7k8hd1m34g3y0csn.ls error="server returned 404: 404 page not found\n"18052026/10/10 19:01:51 INFO Signed narinfos id=2 count=118062026/10/10 19:01:51 INFO Uploading 1 narinfos18072026/10/10 19:01:51 INFO Aborted multipart uploads count=0 kept=018082026/10/10 19:01:51 INFO Received complete push request method=POST path=/api/pushes/2/complete18092026/10/10 19:01:51 WARN Failed to register uploaded object key=r9wfrdryavr8x3gn7k8hd1m34g3y0csn.narinfo error="server returned 404: 404 page not found\n"18102026/10/10 19:01:51 INFO Completed push id=2 objects=3 duration=4.352198ms18112026/10/10 19:01:51 WARN Force mode enabled - objects will be deleted immediately without grace period18122026/10/10 19:01:51 INFO Upload complete. (57ms)1813=== NAME TestNARDeduplicationMetadataUploadBug1814 metadata_upload_test.go:76: Retrieved narinfo from S3:1815 StorePath: /build/TestNARDeduplicationMetadataUploadBug1623184141/001/store/r9wfrdryavr8x3gn7k8hd1m34g3y0csn-file2.txt1816 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1817 Compression: zstd1818 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1819 NarSize: 1601820 References: 1821 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1822=== CONT TestServerTLSConfig/no_client_CA1823=== CONT TestServerTLSConfig/not_a_PEM_file1824=== NAME TestNARDeduplicationMetadataUploadBug1825 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1826=== CONT TestServerTLSConfig/missing_CA_file1827--- PASS: TestServerTLSConfig (0.00s)1828 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1829 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1830 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1831=== NAME TestNARDeduplicationMetadataUploadBug1832 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1833 {"version":1,"root":{"type":"regular","size":44}}1834=== CONT TestIsValidUploadKey/narinfo1835=== CONT TestIsValidUploadKey/realisation_plus_in_output1836=== CONT TestIsValidUploadKey/unknown_type1837=== CONT TestIsValidUploadKey/empty_key1838=== CONT TestIsValidUploadKey/absolute1839=== CONT TestIsValidUploadKey/traversal_nar1840=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1841=== CONT TestIsValidUploadKey/index.html1842=== CONT TestIsValidUploadKey/nix-cache-info1843=== CONT TestIsValidUploadKey/traversal1844=== CONT TestIsValidUploadKey/build_log_home-manager_file1845=== CONT TestIsValidUploadKey/realisation1846=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1847=== CONT TestIsValidUploadKey/build_log_equals1848=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1849=== CONT TestIsValidUploadKey/build_log_question_mark1850=== CONT TestIsValidUploadKey/build_log_plus_in_name1851=== CONT TestIsValidUploadKey/nar_plain1852=== CONT TestIsValidUploadKey/nar_xz1853=== CONT TestIsValidUploadKey/build_log1854=== CONT TestIsValidUploadKey/listing1855=== CONT TestIsValidUploadKey/nar_zst1856--- PASS: TestIsValidUploadKey (0.00s)1857 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1858 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1859 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1860 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1861 --- PASS: TestIsValidUploadKey/absolute (0.00s)1862 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1863 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1864 --- PASS: TestIsValidUploadKey/index.html (0.00s)1865 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1866 --- PASS: TestIsValidUploadKey/traversal (0.00s)1867 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1868 --- PASS: TestIsValidUploadKey/realisation (0.00s)1869 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1870 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1871 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1872 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1873 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1874 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1875 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1876 --- PASS: TestIsValidUploadKey/build_log (0.00s)1877 --- PASS: TestIsValidUploadKey/listing (0.00s)1878 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1879=== CONT TestProxyWriteTimeout/narinfo1880=== CONT TestProxyWriteTimeout/unknown_size1881=== CONT TestProxyWriteTimeout/10_GiB_nar1882=== CONT TestProxyWriteTimeout/1_GiB_nar1883--- PASS: TestProxyWriteTimeout (0.00s)1884 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1885 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1886 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1887 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1888=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18892026/10/10 19:01:51 INFO Received uploads request method=POST path=/1890=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18912026/10/10 19:01:51 INFO Received complete multipart upload request method=POST path=/1892=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18932026/10/10 19:01:51 INFO Received uploads request method=POST path=/1894=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18952026/10/10 19:01:51 INFO Received request for more parts method=POST path=/1896--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1897 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1898 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1899 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1900 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)19012026/10/10 19:01:51 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:45291/bucket91/?delete=\": context canceled"1902=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1903=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1904=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1905=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1906=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1907=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1908=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1909=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1910=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1911=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected1912--- PASS: TestGCEndsOnShutdown (0.00s)1913 --- PASS: TestGCEndsOnShutdown/before_the_run (0.22s)1914 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.28s)1915 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.23s)1916=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured19172026/10/10 19:01:51 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]1918=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1919--- PASS: TestNARDeduplicationMetadataUploadBug (0.58s)19202026/10/10 19:01:51 WARN Authentication failed token_preview=eyJhbGciOi...ZsPxhEGXWA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]19212026/10/10 19:01:51 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1922--- PASS: TestService_AuthMiddleware_OIDC (0.39s)1923 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1924 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1925 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1926 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)19272026/10/10 19:01:51 INFO Received uploads request method=POST path=/api/pending_closures19282026/10/10 19:01:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1929=== RUN TestService_RequireScope_OIDC/builder_may_write1930=== PAUSE TestService_RequireScope_OIDC/builder_may_write1931=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1932=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1933=== RUN TestService_RequireScope_OIDC/ops_may_admin1934=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1935=== RUN TestService_RequireScope_OIDC/ops_may_not_write1936=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1937=== RUN TestService_RequireScope_OIDC/reader_may_not_write1938=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1939=== RUN TestService_RequireScope_OIDC/static_token_may_admin1940=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1941=== RUN TestService_RequireScope_OIDC/static_token_may_write1942=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1943=== RUN TestService_RequireScope_OIDC/reader_may_read1944=== PAUSE TestService_RequireScope_OIDC/reader_may_read1945=== RUN TestService_RequireScope_OIDC/writer_implies_read1946=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1947=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1948=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1949=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1950=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1951=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1952=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1953=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1954=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1955=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1956=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1957=== CONT TestService_RequireScope_OIDC/builder_may_write1958=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1959=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1960=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1961=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1962=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1963=== CONT TestService_RequireScope_OIDC/writer_implies_read19642026/10/10 19:01:51 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]1965=== CONT TestService_RequireScope_OIDC/reader_may_read1966=== CONT TestService_RequireScope_OIDC/static_token_may_admin19672026/10/10 19:01:51 INFO Received uploads request method=POST path=/api/pending_closures1968=== CONT TestService_RequireScope_OIDC/static_token_may_write1969=== CONT TestService_RequireScope_OIDC/ops_may_not_write1970=== CONT TestService_RequireScope_OIDC/ops_may_admin1971=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1972=== CONT TestService_RequireScope_OIDC/reader_may_not_write19732026/10/10 19:01:51 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZDMwNDgzOWYtMWJkYi00OTVmLWE4NDAtZGEyNWViMzE4ZWMxLjEwNzY2ZDc1LTE3YjAtNDUyMS1iNmYzLTRmMDVlZmYwNDhjNHgxNzkxNjU4OTExNjU3MTk5Nzcx parts=1019742026/10/10 19:01:51 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1975--- PASS: TestService_RequireScope_OIDC (0.42s)1976 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1977 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1978 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1979 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1980 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1981 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1982 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1983 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1984 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1985 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1986 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1987 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1988 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1989 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)19902026/10/10 19:01:51 INFO Completed upload id=1 objects=2 duration=2.621783ms19912026/10/10 19:01:51 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000019922026/10/10 19:01:51 INFO Received uploads request method=POST path=/api/pending_closures19932026/10/10 19:01:51 INFO Aborted multipart uploads count=0 kept=019942026/10/10 19:01:51 INFO Starting cleanup of old closures method=DELETE path=/api/closures19952026/10/10 19:01:51 WARN Force mode enabled - objects will be deleted immediately without grace period19962026/10/10 19:01:51 INFO Aborted multipart uploads count=0 kept=019972026/10/10 19:01:51 INFO Received uploads request method=POST path=/api/pending_closures19982026/10/10 19:01:51 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=019992026/10/10 19:01:51 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=020002026/10/10 19:01:51 INFO Vacuumed table table=pending_closures20012026/10/10 19:01:51 INFO Vacuumed table table=pending_objects20022026/10/10 19:01:51 INFO Vacuumed table table=multipart_uploads20032026/10/10 19:01:51 INFO Vacuumed table table=closures20042026/10/10 19:01:51 INFO Vacuumed table table=pending_closures20052026/10/10 19:01:51 INFO Vacuumed table table=objects20062026/10/10 19:01:51 INFO Vacuumed table table=pending_objects20072026/10/10 19:01:51 INFO Vacuumed table table=multipart_uploads20082026/10/10 19:01:51 INFO Aborted multipart uploads count=0 kept=020092026/10/10 19:01:52 INFO Vacuumed table table=closures20102026/10/10 19:01:52 INFO Vacuumed table table=objects20112026/10/10 19:01:52 WARN Force mode enabled - objects will be deleted immediately without grace period20122026/10/10 19:01:52 WARN Request failed, retrying attempt=2 backoff=200.750159ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20132026/10/10 19:01:52 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=020142026/10/10 19:01:52 INFO Vacuumed table table=pending_closures20152026/10/10 19:01:52 INFO Vacuumed table table=pending_objects20162026/10/10 19:01:52 INFO Vacuumed table table=multipart_uploads20172026/10/10 19:01:52 INFO Vacuumed table table=closures20182026/10/10 19:01:52 INFO Vacuumed table table=objects2019--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2020 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.25s)2021 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.24s)20222026/10/10 19:01:52 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000002023--- PASS: TestService_createPendingClosureHandler (0.64s)20242026/10/10 19:01:52 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20252026/10/10 19:01:52 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2026--- PASS: TestObjectStatsLargeCommit (1.29s)20272026/10/10 19:01:52 WARN Request failed, retrying attempt=3 backoff=376.772298ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2028--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2029 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.70s)2030 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.73s)2031=== NAME TestOrphanedObjectsGCStressTest2032 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2033 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion20342026/10/10 19:01:52 INFO lead: released remote=192.0.2.1:12342035--- PASS: TestLeadElectsOneAndHandsOver (2.76s)20362026/10/10 19:01:52 WARN Request failed, retrying attempt=4 backoff=756.054629ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20372026/10/10 19:01:52 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020382026/10/10 19:01:52 INFO Received create pin request method=POST path=/api/pins/myapp20392026/10/10 19:01:52 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1280971878/001/store/xgq5gbnaw5wwld0nladbfsi9dxw3dsnk-pinned-file.txt narinfo_key=xgq5gbnaw5wwld0nladbfsi9dxw3dsnk.narinfo20402026/10/10 19:01:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures20412026/10/10 19:01:52 INFO Garbage collection started20422026/10/10 19:01:52 INFO Aborted multipart uploads count=0 kept=020432026/10/10 19:01:52 WARN Force mode enabled - objects will be deleted immediately without grace period20442026/10/10 19:01:52 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=020452026/10/10 19:01:52 INFO Vacuumed table table=pending_closures20462026/10/10 19:01:52 INFO Vacuumed table table=pending_objects20472026/10/10 19:01:52 INFO Vacuumed table table=multipart_uploads20482026/10/10 19:01:52 INFO Vacuumed table table=closures20492026/10/10 19:01:52 INFO Vacuumed table table=objects2050--- PASS: TestPendingClosureWriteTimeout (0.00s)2051 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2052 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2053 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2054 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.04s)2055=== NAME TestOrphanedObjectsGCStressTest2056 orphaned_objects_gc_test.go:503: Stress test completed successfully:2057 orphaned_objects_gc_test.go:504: - Active objects preserved: 202058 orphaned_objects_gc_test.go:505: - Objects deleted: 2102059 orphaned_objects_gc_test.go:506: - Total GC'd: 2102060--- PASS: TestOrphanedObjectsGCStressTest (1.86s)2061--- PASS: TestUploadHandlersRejectOversizedBody (0.17s)2062 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)2063 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)2064 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.14s)20652026/10/10 19:01:53 WARN Request failed, retrying attempt=5 backoff=1.500935802s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20662026/10/10 19:01:53 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02067=== NAME TestClientIntegration2068 client_integration_test.go:323: Objects in database after GC:2069 client_integration_test.go:323: Successfully deleted all objects with GC --force2070--- PASS: TestClientIntegration (2.52s)20712026/10/10 19:01:54 WARN Rate limiter enabled after throttle name=s3-test rate=520722026/10/10 19:01:54 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2073=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2074 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102075 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002076--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (3.00s)2077=== NAME TestPinProtectsFromGC2078 client_integration_test.go:840: Pin successfully protected closure from garbage collection2079--- PASS: TestPinProtectsFromGC (4.84s)20802026/10/10 19:01:54 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20812026/10/10 19:01:55 WARN Request failed, retrying attempt=2 backoff=198.716502ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2082--- PASS: TestConnectWaitsForAPeerMigration (5.29s)20832026/10/10 19:01:55 WARN Request failed, retrying attempt=3 backoff=416.507646ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2084--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.50s)20852026/10/10 19:01:55 WARN Request failed, retrying attempt=4 backoff=752.218948ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20862026/10/10 19:01:56 WARN Request failed, retrying attempt=5 backoff=1.483899095s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20872026/10/10 19:01:56 INFO Aborted multipart uploads count=1 kept=020882026/10/10 19:01:56 INFO Received cleanup request method=DELETE path=/api/pending_closures20892026/10/10 19:01:56 INFO Aborted multipart uploads count=1 kept=02090--- PASS: TestPendingCleanupUsesOneCutoff (6.33s)20912026/10/10 19:01:57 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"20922026/10/10 19:01:57 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20932026/10/10 19:01:57 WARN Request failed, retrying attempt=2 backoff=184.805401ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20942026/10/10 19:01:58 WARN Request failed, retrying attempt=3 backoff=422.777066ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20952026/10/10 19:01:58 WARN Request failed, retrying attempt=4 backoff=814.736031ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20962026/10/10 19:01:59 WARN Request failed, retrying attempt=5 backoff=1.664410228s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20972026/10/10 19:02:01 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20982026/10/10 19:02:01 WARN Request failed, retrying attempt=2 backoff=187.461016ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20992026/10/10 19:02:01 WARN Request failed, retrying attempt=3 backoff=399.612142ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21002026/10/10 19:02:01 WARN Request failed, retrying attempt=4 backoff=775.97605ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21012026/10/10 19:02:02 WARN Request failed, retrying attempt=5 backoff=1.475217739s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2102--- PASS: TestClientErrorHandling (0.00s)2103 --- PASS: TestClientErrorHandling/InvalidStorePath (0.24s)2104 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.31s)2105 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.20s)2106PASS21072026-10-10 19:02:04.289 UTC [128] LOG: received smart shutdown request21082026-10-10 19:02:04.293 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 121092026-10-10 19:02:04.306 UTC [133] LOG: shutting down21102026-10-10 19:02:04.307 UTC [133] LOG: checkpoint starting: shutdown immediate21112026-10-10 19:02:05.106 UTC [133] LOG: checkpoint complete: wrote 10955 buffers (66.9%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.178 s, sync=0.588 s, total=0.800 s; sync files=34046, longest=0.006 s, average=0.001 s; distance=531543 kB, estimate=531543 kB; lsn=0/21E7BAA0, redo lsn=0/21E7BAA021122026-10-10 19:02:05.185 UTC [128] LOG: database system is shut down2113Running OIDC tests...2114=== RUN TestAudienceForIssuer2115=== PAUSE TestAudienceForIssuer2116=== RUN TestGlobMatch2117=== PAUSE TestGlobMatch2118=== RUN TestValidateToken_ValidToken2119=== PAUSE TestValidateToken_ValidToken2120=== RUN TestValidateToken_WrongAudience2121=== PAUSE TestValidateToken_WrongAudience2122=== RUN TestValidateToken_Expired2123=== PAUSE TestValidateToken_Expired2124=== RUN TestValidateToken_BoundClaimsMismatch2125=== PAUSE TestValidateToken_BoundClaimsMismatch2126=== RUN TestValidateToken_BoundSubjectMismatch2127=== PAUSE TestValidateToken_BoundSubjectMismatch2128=== RUN TestValidateToken_MultipleProviders2129=== PAUSE TestValidateToken_MultipleProviders2130=== RUN TestValidateToken_NoMatchingProvider2131=== PAUSE TestValidateToken_NoMatchingProvider2132=== RUN TestValidateToken_KubernetesServiceAccount2133=== PAUSE TestValidateToken_KubernetesServiceAccount2134=== RUN TestNewValidator_KubernetesRequiresCA2135=== PAUSE TestNewValidator_KubernetesRequiresCA2136=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2137=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2138=== RUN TestPins_ReservedForMatchingRule2139=== PAUSE TestPins_ReservedForMatchingRule2140=== RUN TestPins_TopLevelShorthand2141=== PAUSE TestPins_TopLevelShorthand2142=== RUN TestPins_ConfigValidation2143=== PAUSE TestPins_ConfigValidation2144=== RUN TestScopes_LegacyProviderDefaultsToWrite2145=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2146=== RUN TestScopes_Rules2147=== PAUSE TestScopes_Rules2148=== RUN TestScopes_ConfigValidation2149=== PAUSE TestScopes_ConfigValidation2150=== CONT TestAudienceForIssuer2151=== CONT TestValidateToken_KubernetesServiceAccount2152--- PASS: TestAudienceForIssuer (0.00s)2153=== CONT TestValidateToken_BoundClaimsMismatch2154=== CONT TestValidateToken_Expired2155=== CONT TestScopes_ConfigValidation2156=== CONT TestScopes_Rules2157=== CONT TestScopes_LegacyProviderDefaultsToWrite2158=== CONT TestPins_TopLevelShorthand2159--- PASS: TestScopes_ConfigValidation (0.00s)2160=== CONT TestValidateToken_WrongAudience2161=== CONT TestValidateToken_ValidToken2162=== CONT TestGlobMatch2163=== RUN TestGlobMatch/foo_foo2164=== PAUSE TestGlobMatch/foo_foo2165=== RUN TestGlobMatch/foo_bar2166=== PAUSE TestGlobMatch/foo_bar2167=== RUN TestGlobMatch/*_2168=== PAUSE TestGlobMatch/*_2169=== RUN TestGlobMatch/*_anything2170=== PAUSE TestGlobMatch/*_anything2171=== RUN TestGlobMatch/foo*_foo2172=== PAUSE TestGlobMatch/foo*_foo2173=== CONT TestPins_ConfigValidation2174=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2175=== CONT TestNewValidator_KubernetesRequiresCA2176=== CONT TestValidateToken_MultipleProviders2177=== CONT TestValidateToken_NoMatchingProvider2178=== CONT TestValidateToken_BoundSubjectMismatch2179=== CONT TestPins_ReservedForMatchingRule2180=== RUN TestGlobMatch/foo*_foobar2181=== PAUSE TestGlobMatch/foo*_foobar2182=== RUN TestGlobMatch/foo*_bar2183=== PAUSE TestGlobMatch/foo*_bar2184=== RUN TestGlobMatch/*bar_bar2185=== PAUSE TestGlobMatch/*bar_bar2186=== RUN TestGlobMatch/*bar_foobar2187=== PAUSE TestGlobMatch/*bar_foobar2188=== RUN TestGlobMatch/*bar_foo2189=== PAUSE TestGlobMatch/*bar_foo2190=== RUN TestGlobMatch/foo*bar_foobar2191=== PAUSE TestGlobMatch/foo*bar_foobar2192=== RUN TestGlobMatch/foo*bar_foo123bar2193=== PAUSE TestGlobMatch/foo*bar_foo123bar2194=== RUN TestGlobMatch/foo*bar_foobarbaz2195=== PAUSE TestGlobMatch/foo*bar_foobarbaz2196=== RUN TestGlobMatch/*/*_foo/bar2197=== PAUSE TestGlobMatch/*/*_foo/bar2198=== RUN TestGlobMatch/*/*_foo2199=== PAUSE TestGlobMatch/*/*_foo2200=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2201=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2202=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02203=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02204=== RUN TestGlobMatch/refs/*/main_refs/heads/main2205=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2206=== RUN TestGlobMatch/fo?_foo2207=== PAUSE TestGlobMatch/fo?_foo2208=== RUN TestGlobMatch/fo?_fo2209=== PAUSE TestGlobMatch/fo?_fo2210=== RUN TestGlobMatch/fo?_fooo2211=== PAUSE TestGlobMatch/fo?_fooo2212=== RUN TestGlobMatch/?oo_foo2213=== PAUSE TestGlobMatch/?oo_foo2214=== RUN TestGlobMatch/?oo_boo2215=== PAUSE TestGlobMatch/?oo_boo2216=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2217=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2218=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2219=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2220=== CONT TestGlobMatch/foo_foo2221=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2222=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2223=== CONT TestGlobMatch/foo*bar_foo123bar2224=== CONT TestGlobMatch/foo*bar_foobar2225=== CONT TestGlobMatch/*bar_foo2226=== CONT TestGlobMatch/*bar_foobar2227=== CONT TestGlobMatch/*bar_bar2228=== CONT TestGlobMatch/foo*_bar2229=== CONT TestGlobMatch/foo*_foobar2230=== CONT TestGlobMatch/foo*_foo2231--- PASS: TestPins_ConfigValidation (0.00s)2232=== CONT TestGlobMatch/foo*bar_foobarbaz2233=== CONT TestGlobMatch/refs/*/main_refs/heads/main2234=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02235=== CONT TestGlobMatch/*/*_foo2236=== CONT TestGlobMatch/*/*_foo/bar2237=== CONT TestGlobMatch/*_anything2238=== CONT TestGlobMatch/*_2239=== CONT TestGlobMatch/foo_bar2240=== CONT TestGlobMatch/fo?_foo2241=== CONT TestGlobMatch/?oo_boo2242=== CONT TestGlobMatch/?oo_foo2243=== CONT TestGlobMatch/fo?_fooo2244=== CONT TestGlobMatch/fo?_fo2245=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2246--- PASS: TestGlobMatch (0.00s)2247 --- PASS: TestGlobMatch/foo_foo (0.00s)2248 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2249 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2250 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2251 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2252 --- PASS: TestGlobMatch/*bar_foo (0.00s)2253 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2254 --- PASS: TestGlobMatch/*bar_bar (0.00s)2255 --- PASS: TestGlobMatch/foo*_bar (0.00s)2256 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2257 --- PASS: TestGlobMatch/foo*_foo (0.00s)2258 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2259 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2260 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2261 --- PASS: TestGlobMatch/*/*_foo (0.00s)2262 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2263 --- PASS: TestGlobMatch/*_anything (0.00s)2264 --- PASS: TestGlobMatch/*_ (0.00s)2265 --- PASS: TestGlobMatch/foo_bar (0.00s)2266 --- PASS: TestGlobMatch/fo?_foo (0.00s)2267 --- PASS: TestGlobMatch/?oo_boo (0.00s)2268 --- PASS: TestGlobMatch/?oo_foo (0.00s)2269 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2270 --- PASS: TestGlobMatch/fo?_fo (0.00s)2271 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)22722026/10/10 19:02:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44471/oidc22732026/10/10 19:02:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34091/oidc2274--- PASS: TestPins_TopLevelShorthand (0.04s)2275--- PASS: TestValidateToken_BoundClaimsMismatch (0.04s)22762026/10/10 19:02:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36669/oidc2277--- PASS: TestValidateToken_WrongAudience (0.06s)22782026/10/10 19:02:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34327/oidc2279--- PASS: TestPins_ReservedForMatchingRule (0.08s)22802026/10/10 19:02:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35877/oidc2281--- PASS: TestValidateToken_Expired (0.12s)22822026/10/10 19:02:06 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232283--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.14s)22842026/10/10 19:02:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41597/oidc2285--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.16s)22862026/10/10 19:02:06 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:360852287--- PASS: TestValidateToken_KubernetesServiceAccount (0.18s)22882026/10/10 19:02:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34515/oidc2289--- PASS: TestValidateToken_ValidToken (0.21s)22902026/10/10 19:02:06 http: TLS handshake error from 127.0.0.1:49542: remote error: tls: bad certificate2291--- PASS: TestNewValidator_KubernetesRequiresCA (0.21s)22922026/10/10 19:02:06 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:44041/oidc22932026/10/10 19:02:06 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:35775/oidc22942026/10/10 19:02:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43343/oidc2295--- PASS: TestValidateToken_MultipleProviders (0.24s)2296--- PASS: TestScopes_Rules (0.25s)22972026/10/10 19:02:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42697/oidc2298--- PASS: TestValidateToken_BoundSubjectMismatch (0.26s)22992026/10/10 19:02:07 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:45389/oidc2300--- PASS: TestValidateToken_NoMatchingProvider (0.31s)2301PASS2302Running hook tests...2303=== RUN TestSendPathsEmpty2304=== PAUSE TestSendPathsEmpty2305=== RUN TestQueueEnqueueAndFetch2306=== PAUSE TestQueueEnqueueAndFetch2307=== RUN TestQueueDeduplication2308=== PAUSE TestQueueDeduplication2309=== RUN TestQueueRemove2310=== PAUSE TestQueueRemove2311=== RUN TestQueueFetchBatchLimit2312=== PAUSE TestQueueFetchBatchLimit2313=== RUN TestQueueRetryMovesToBack2314=== PAUSE TestQueueRetryMovesToBack2315=== RUN TestQueueFetchRemoveLifecycle2316=== PAUSE TestQueueFetchRemoveLifecycle2317=== RUN TestQueueConcurrentWriters2318=== PAUSE TestQueueConcurrentWriters2319=== RUN TestQueueRemoveLargeClosure2320=== PAUSE TestQueueRemoveLargeClosure2321=== RUN TestServerClientIntegration2322--- PASS: TestServerClientIntegration (0.00s)2323=== RUN TestServerQueueError23242026/10/10 19:02:07 ERROR Failed to queue paths error="permission denied" count=12325--- PASS: TestServerQueueError (0.00s)2326=== RUN TestGetListenerSocketActivation2327 server_test.go:219: === RUN TestGetListenerSocketActivation2328 --- PASS: TestGetListenerSocketActivation (0.00s)2329 PASS2330 2331--- PASS: TestGetListenerSocketActivation (0.00s)2332=== RUN TestDrainIsolatesPoisonPath2333=== PAUSE TestDrainIsolatesPoisonPath2334=== RUN TestRunNotBlockedByPoisonHead2335=== PAUSE TestRunNotBlockedByPoisonHead2336=== RUN TestDrainGivesUpWhenServerDown2337=== PAUSE TestDrainGivesUpWhenServerDown2338=== RUN TestFailedPathPrunedByLaterClosure2339=== PAUSE TestFailedPathPrunedByLaterClosure2340=== RUN TestWorkerUploadsAndRemoves2341=== PAUSE TestWorkerUploadsAndRemoves2342=== RUN TestWorkerSkipsGCdPaths2343=== PAUSE TestWorkerSkipsGCdPaths2344=== RUN TestWorkerPrunesClosureDeps2345=== PAUSE TestWorkerPrunesClosureDeps2346=== RUN TestDrainTimeout2347=== PAUSE TestDrainTimeout2348=== CONT TestSendPathsEmpty2349--- PASS: TestSendPathsEmpty (0.00s)2350=== CONT TestDrainGivesUpWhenServerDown2351=== CONT TestWorkerSkipsGCdPaths2352=== CONT TestQueueRetryMovesToBack2353=== CONT TestDrainTimeout2354=== CONT TestQueueFetchBatchLimit2355=== CONT TestWorkerPrunesClosureDeps2356=== CONT TestQueueEnqueueAndFetch2357=== CONT TestQueueRemove2358=== CONT TestWorkerUploadsAndRemoves2359=== CONT TestQueueDeduplication2360=== CONT TestQueueRemoveLargeClosure2361=== CONT TestDrainIsolatesPoisonPath2362=== CONT TestRunNotBlockedByPoisonHead2363=== CONT TestQueueConcurrentWriters2364=== CONT TestFailedPathPrunedByLaterClosure2365=== CONT TestQueueFetchRemoveLifecycle23662026/10/10 19:02:07 INFO Upload queue status pending=223672026/10/10 19:02:07 INFO Uploading batch count=223682026/10/10 19:02:07 INFO Uploading batch count=123692026/10/10 19:02:07 ERROR Upload failed error="upload failed" count=123702026/10/10 19:02:07 INFO Uploading batch count=123712026/10/10 19:02:07 INFO Uploading batch count=223722026/10/10 19:02:07 ERROR Upload failed error="upload failed" count=223732026/10/10 19:02:07 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4281483550/002/a23742026/10/10 19:02:07 INFO Uploading batch count=123752026/10/10 19:02:07 INFO Upload queue status pending=22376--- PASS: TestQueueFetchRemoveLifecycle (0.01s)23772026/10/10 19:02:07 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4281483550/002/b23782026/10/10 19:02:07 INFO Uploading batch count=423792026/10/10 19:02:07 ERROR Upload failed error="upload failed" count=423802026/10/10 19:02:07 INFO Uploading batch count=123812026/10/10 19:02:07 INFO Uploading batch count=223822026/10/10 19:02:07 ERROR Upload failed error="upload failed" count=223832026/10/10 19:02:07 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4281483550/002/c23842026/10/10 19:02:07 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3457330747/002/bbb2385--- PASS: TestQueueFetchBatchLimit (0.01s)23862026/10/10 19:02:07 INFO Uploading batch count=22387--- PASS: TestQueueRetryMovesToBack (0.01s)23882026/10/10 19:02:07 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4281483550/002/d2389--- PASS: TestQueueDeduplication (0.01s)23902026/10/10 19:02:07 INFO Upload queue status pending=323912026/10/10 19:02:07 INFO Upload queue status pending=223922026/10/10 19:02:07 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2702615194/002/nonexistent23932026/10/10 19:02:07 INFO Uploading batch count=123942026/10/10 19:02:07 ERROR Upload failed error="upload failed" count=123952026/10/10 19:02:07 INFO Uploading batch count=22396--- PASS: TestQueueRemove (0.01s)23972026/10/10 19:02:07 ERROR Upload failed error="upload failed" count=22398--- PASS: TestQueueEnqueueAndFetch (0.01s)23992026/10/10 19:02:07 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4281483550/002/e24002026/10/10 19:02:07 INFO Uploading batch count=124012026/10/10 19:02:07 ERROR Upload failed error="upload failed" count=124022026/10/10 19:02:07 INFO Uploading batch count=12403--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)24042026/10/10 19:02:07 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4281483550/002/f24052026/10/10 19:02:07 INFO Uploading batch count=124062026/10/10 19:02:07 ERROR Upload failed error="upload failed" count=12407--- PASS: TestWorkerPrunesClosureDeps (0.02s)24082026/10/10 19:02:07 ERROR Drain finished with paths left in queue remaining=1024092026/10/10 19:02:07 INFO Uploading batch count=124102026/10/10 19:02:07 ERROR Upload failed error="upload failed" count=124112026/10/10 19:02:07 ERROR Drain finished with paths left in queue remaining=12412--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2413--- PASS: TestDrainIsolatesPoisonPath (0.02s)2414--- PASS: TestWorkerUploadsAndRemoves (0.03s)2415--- PASS: TestWorkerSkipsGCdPaths (0.03s)2416--- PASS: TestQueueRemoveLargeClosure (0.10s)2417--- PASS: TestQueueConcurrentWriters (0.15s)24182026/10/10 19:02:07 ERROR Upload failed error="context deadline exceeded" count=224192026/10/10 19:02:07 ERROR Drain finished with paths left in queue remaining=42420--- PASS: TestDrainTimeout (0.21s)24212026/10/10 19:02:08 INFO Uploading batch count=124222026/10/10 19:02:08 INFO Uploading batch count=124232026/10/10 19:02:08 INFO Uploading batch count=124242026/10/10 19:02:08 ERROR Upload failed error="upload failed" count=124252026/10/10 19:02:08 INFO Uploading batch count=124262026/10/10 19:02:08 ERROR Upload failed error="upload failed" count=124272026/10/10 19:02:08 INFO Uploading batch count=124282026/10/10 19:02:08 ERROR Upload failed error="upload failed" count=124292026/10/10 19:02:08 INFO Uploading batch count=124302026/10/10 19:02:08 ERROR Upload failed error="upload failed" count=124312026/10/10 19:02:08 ERROR Drain finished with paths left in queue remaining=12432--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2433PASS2434Running signing tests...2435=== RUN TestExternalSigner2436=== PAUSE TestExternalSigner2437=== RUN TestExternalSignerWrongPublicKey2438=== PAUSE TestExternalSignerWrongPublicKey2439=== RUN TestExternalSignerErrors2440=== PAUSE TestExternalSignerErrors2441=== RUN TestExternalSignerRestartsAfterCrash2442=== PAUSE TestExternalSignerRestartsAfterCrash2443=== RUN TestExternalSignerProgramErrorKeepsProcess2444=== PAUSE TestExternalSignerProgramErrorKeepsProcess2445=== RUN TestExternalSignerClose2446=== PAUSE TestExternalSignerClose2447=== RUN TestExternalSignerRejectsInvalidPublicKey2448=== PAUSE TestExternalSignerRejectsInvalidPublicKey2449=== RUN TestExternalSignerCancellation2450=== PAUSE TestExternalSignerCancellation2451=== RUN TestGenerateFingerprint2452=== PAUSE TestGenerateFingerprint2453=== RUN TestParseSigningKey2454=== PAUSE TestParseSigningKey2455=== RUN TestSign2456=== PAUSE TestSign2457=== RUN TestSignBatch2458=== PAUSE TestSignBatch2459=== RUN TestNilKeyPublicKey2460=== PAUSE TestNilKeyPublicKey2461=== RUN TestSignErrors2462=== PAUSE TestSignErrors2463=== CONT TestExternalSigner2464=== CONT TestExternalSignerCancellation2465=== CONT TestSignBatch2466=== CONT TestSignErrors2467=== CONT TestSign2468=== CONT TestParseSigningKey2469=== RUN TestParseSigningKey/valid_32-byte_key2470=== CONT TestGenerateFingerprint2471=== RUN TestGenerateFingerprint/basic_with_references2472=== CONT TestExternalSignerProgramErrorKeepsProcess2473=== CONT TestExternalSignerRejectsInvalidPublicKey2474=== RUN TestExternalSignerRejectsInvalidPublicKey/#002475=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002476=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2477=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2478=== CONT TestExternalSignerClose2479=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2480=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2481=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2482=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2483=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2484=== CONT TestExternalSignerErrors2485=== CONT TestExternalSignerRestartsAfterCrash2486=== CONT TestExternalSignerWrongPublicKey2487=== CONT TestNilKeyPublicKey2488=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2489=== RUN TestExternalSignerErrors/null_signatures2490=== PAUSE TestExternalSignerErrors/null_signatures2491=== PAUSE TestGenerateFingerprint/basic_with_references2492--- PASS: TestNilKeyPublicKey (0.00s)2493=== PAUSE TestParseSigningKey/valid_32-byte_key2494=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2495=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2496=== RUN TestExternalSignerErrors/missing_signature_name2497=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2498=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2499=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2500=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2501=== RUN TestGenerateFingerprint/no_references2502=== PAUSE TestGenerateFingerprint/no_references2503=== CONT TestExternalSignerRejectsInvalidPublicKey/#002504=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2505=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2506=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2507=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2508=== RUN TestGenerateFingerprint/invalid_nar_hash_length2509=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2510=== RUN TestGenerateFingerprint/invalid_store_path_prefix2511--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2512 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2513 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2514 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2515 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2516 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2517=== PAUSE TestExternalSignerErrors/missing_signature_name2518=== RUN TestParseSigningKey/no_colon2519=== RUN TestExternalSignerErrors/exit_on_request2520=== PAUSE TestParseSigningKey/no_colon2521=== RUN TestParseSigningKey/empty_name2522=== PAUSE TestParseSigningKey/empty_name2523=== RUN TestParseSigningKey/invalid_base642524=== PAUSE TestParseSigningKey/invalid_base642525=== RUN TestParseSigningKey/wrong_length2526=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2527=== RUN TestGenerateFingerprint/invalid_reference_prefix2528=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2529=== CONT TestGenerateFingerprint/basic_with_references2530=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2531=== PAUSE TestExternalSignerErrors/exit_on_request2532=== CONT TestGenerateFingerprint/invalid_reference_prefix2533=== PAUSE TestParseSigningKey/wrong_length2534=== CONT TestParseSigningKey/valid_32-byte_key2535=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2536=== CONT TestGenerateFingerprint/invalid_nar_hash_length2537=== CONT TestGenerateFingerprint/no_references2538=== CONT TestGenerateFingerprint/invalid_store_path_prefix2539--- PASS: TestGenerateFingerprint (0.00s)2540 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2541 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2542 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2543 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2544 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2545 --- PASS: TestGenerateFingerprint/no_references (0.00s)2546 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2547=== RUN TestExternalSignerErrors/invalid_JSON2548=== PAUSE TestExternalSignerErrors/invalid_JSON2549=== CONT TestParseSigningKey/empty_name2550=== CONT TestParseSigningKey/invalid_base642551=== CONT TestParseSigningKey/no_colon2552=== CONT TestParseSigningKey/wrong_length2553=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2554=== RUN TestExternalSignerErrors/missing_signatures2555=== PAUSE TestExternalSignerErrors/missing_signatures2556=== RUN TestExternalSignerErrors/too_few_signatures2557=== PAUSE TestExternalSignerErrors/too_few_signatures2558=== RUN TestExternalSignerErrors/wrong_id2559=== PAUSE TestExternalSignerErrors/wrong_id2560=== RUN TestExternalSignerErrors/wrong_signatures_shape2561=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2562=== RUN TestExternalSignerErrors/wrong_signature_name2563=== PAUSE TestExternalSignerErrors/wrong_signature_name2564=== RUN TestExternalSignerErrors/invalid_signature_base642565=== PAUSE TestExternalSignerErrors/invalid_signature_base642566=== RUN TestExternalSignerErrors/wrong_signature_length2567=== PAUSE TestExternalSignerErrors/wrong_signature_length2568=== RUN TestExternalSignerErrors/program_error2569=== PAUSE TestExternalSignerErrors/program_error2570=== RUN TestExternalSignerErrors/null2571=== PAUSE TestExternalSignerErrors/null2572=== RUN TestExternalSignerErrors/unrequested_key2573=== PAUSE TestExternalSignerErrors/unrequested_key2574=== RUN TestExternalSignerErrors/exit_at_startup2575=== PAUSE TestExternalSignerErrors/exit_at_startup2576=== RUN TestExternalSignerErrors/wrong_shape2577=== PAUSE TestExternalSignerErrors/wrong_shape2578=== CONT TestExternalSignerErrors/null_signatures2579=== CONT TestExternalSignerErrors/invalid_signature_base642580=== CONT TestExternalSignerErrors/exit_at_startup2581=== CONT TestExternalSignerErrors/too_few_signatures2582--- PASS: TestParseSigningKey (0.00s)2583 --- PASS: TestParseSigningKey/empty_name (0.00s)2584 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2585 --- PASS: TestParseSigningKey/no_colon (0.00s)2586 --- PASS: TestParseSigningKey/wrong_length (0.00s)2587 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2588 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2589--- PASS: TestSign (0.00s)2590=== CONT TestExternalSignerErrors/missing_signature_name2591=== CONT TestExternalSignerErrors/wrong_signatures_shape2592=== CONT TestExternalSignerErrors/wrong_id2593=== CONT TestExternalSignerErrors/unrequested_key2594--- PASS: TestSignBatch (0.00s)2595=== RUN TestSignErrors/nil_key2596=== CONT TestExternalSignerErrors/wrong_shape2597=== CONT TestExternalSignerErrors/program_error2598=== CONT TestExternalSignerErrors/null2599=== CONT TestExternalSignerErrors/invalid_JSON2600=== CONT TestExternalSignerErrors/wrong_signature_length2601=== CONT TestExternalSignerErrors/missing_signatures2602=== CONT TestExternalSignerErrors/exit_on_request2603=== CONT TestExternalSignerErrors/wrong_signature_name2604=== PAUSE TestSignErrors/nil_key2605--- PASS: TestExternalSignerWrongPublicKey (0.01s)2606--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.01s)2607=== RUN TestSignErrors/nil_narinfo2608=== PAUSE TestSignErrors/nil_narinfo2609=== RUN TestSignErrors/invalid_narinfo2610=== PAUSE TestSignErrors/invalid_narinfo2611=== RUN TestSignErrors/canceled2612=== PAUSE TestSignErrors/canceled2613=== CONT TestSignErrors/nil_key2614=== CONT TestSignErrors/canceled2615=== CONT TestSignErrors/invalid_narinfo2616=== CONT TestSignErrors/nil_narinfo2617--- PASS: TestSignErrors (0.01s)2618 --- PASS: TestSignErrors/nil_key (0.00s)2619 --- PASS: TestSignErrors/canceled (0.00s)2620 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2621 --- PASS: TestSignErrors/nil_narinfo (0.00s)2622--- PASS: TestExternalSignerClose (0.01s)2623--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2624--- PASS: TestExternalSignerErrors (0.00s)2625 --- PASS: TestExternalSignerErrors/too_few_signatures (0.00s)2626 --- PASS: TestExternalSignerErrors/null_signatures (0.00s)2627 --- PASS: TestExternalSignerErrors/wrong_id (0.00s)2628 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)2629 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2630 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2631 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2632 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2633 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2634 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2635 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2636 --- PASS: TestExternalSignerErrors/null (0.01s)2637 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2638 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2639 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.00s)2640 --- PASS: TestExternalSignerErrors/program_error (0.01s)2641--- PASS: TestExternalSigner (0.01s)2642--- PASS: TestExternalSignerCancellation (0.02s)2643PASS2644Running OpenBao signer tests...2645=== RUN TestSign2646=== PAUSE TestSign2647=== RUN TestSignErrors2648=== PAUSE TestSignErrors2649=== RUN TestServe2650=== PAUSE TestServe2651=== RUN TestServeRejectsGarbage2652=== PAUSE TestServeRejectsGarbage2653=== CONT TestSign2654=== CONT TestSignErrors2655=== CONT TestServe2656=== RUN TestSignErrors/no_prefix2657=== PAUSE TestSignErrors/no_prefix2658=== RUN TestSignErrors/invalid_base642659=== PAUSE TestSignErrors/invalid_base642660=== RUN TestSignErrors/http_error2661=== PAUSE TestSignErrors/http_error2662=== RUN TestSignErrors/invalid_json2663=== PAUSE TestSignErrors/invalid_json2664=== CONT TestSignErrors/no_prefix2665=== CONT TestServeRejectsGarbage2666=== CONT TestSignErrors/invalid_json2667=== CONT TestSignErrors/http_error2668=== CONT TestSignErrors/invalid_base642669--- PASS: TestServe (0.00s)2670--- PASS: TestServeRejectsGarbage (0.00s)2671--- PASS: TestSign (0.01s)2672--- PASS: TestSignErrors (0.00s)2673 --- PASS: TestSignErrors/invalid_base64 (0.00s)2674 --- PASS: TestSignErrors/http_error (0.01s)2675 --- PASS: TestSignErrors/no_prefix (0.01s)2676 --- PASS: TestSignErrors/invalid_json (0.01s)2677PASS