niks3-go-unit-tests log

succeeded `niks3-go-unit-tests` `checks.aarch64-linux.go-unit-tests` · build #395 · 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.04s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestDumpPathMatchesNix26=== PAUSE TestDumpPathMatchesNix27=== RUN TestDumpPathSingleFile28=== PAUSE TestDumpPathSingleFile29=== RUN TestDumpPathWriterError30=== PAUSE TestDumpPathWriterError31=== RUN TestEncodeNixBase3232=== PAUSE TestEncodeNixBase3233=== RUN TestEncodeNixBase32WithRealHash34=== PAUSE TestEncodeNixBase32WithRealHash35=== RUN TestConvertHashToNix3236=== PAUSE TestConvertHashToNix3237=== RUN TestGetStorePathHash38=== PAUSE TestGetStorePathHash39=== RUN TestPathInfoHashCompatibility40=== PAUSE TestPathInfoHashCompatibility41=== RUN TestParsePathInfoJSON42=== PAUSE TestParsePathInfoJSON43=== RUN TestParsePathInfoJSONMultiplePaths44=== PAUSE TestParsePathInfoJSONMultiplePaths45=== RUN TestPathInfoCACompatibility46=== PAUSE TestPathInfoCACompatibility47=== RUN TestRateLimiterFeedback48=== PAUSE TestRateLimiterFeedback49=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess51=== RUN TestResolveStorePath52=== PAUSE TestResolveStorePath53=== RUN TestDoWithRetry_BodyReplayedViaGetBody54=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody55=== RUN TestShellSplit56=== PAUSE TestShellSplit57=== RUN TestShellSplitErrors58=== PAUSE TestShellSplitErrors59=== RUN TestStreamPushReportsEveryPath60=== PAUSE TestStreamPushReportsEveryPath61=== RUN TestStreamPushBatchesUnderLoad62=== PAUSE TestStreamPushBatchesUnderLoad63=== RUN TestStreamPushIsolatesFailures64=== PAUSE TestStreamPushIsolatesFailures65=== RUN TestStreamPushGivesUpOnDeadServer66=== PAUSE TestStreamPushGivesUpOnDeadServer67=== RUN TestStreamPushRequestLine68=== PAUSE TestStreamPushRequestLine69=== RUN TestStreamPushReportsSignatures70=== PAUSE TestStreamPushReportsSignatures71=== RUN TestClientSignaturesByStorePath72=== PAUSE TestClientSignaturesByStorePath73=== RUN TestSetClientTLS74=== PAUSE TestSetClientTLS75=== RUN TestSetClientTLSDoesNotMutateDefaultTransport76=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport77=== RUN TestSetClientTLSErrors78=== PAUSE TestSetClientTLSErrors79=== RUN TestStaticToken80=== PAUSE TestStaticToken81=== RUN TestFileTokenReadsAndCaches82=== PAUSE TestFileTokenReadsAndCaches83=== RUN TestFileTokenMissing84=== PAUSE TestFileTokenMissing85=== RUN TestFileTokenEmpty86=== PAUSE TestFileTokenEmpty87=== RUN TestScriptTokenNoExpiryRerunsEveryCall88=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall89=== RUN TestScriptTokenCachesUntilRefresh90=== PAUSE TestScriptTokenCachesUntilRefresh91=== RUN TestScriptTokenEmptyToken92=== PAUSE TestScriptTokenEmptyToken93=== RUN TestScriptTokenBadJSON94=== PAUSE TestScriptTokenBadJSON95=== RUN TestScriptTokenScriptFails96=== PAUSE TestScriptTokenScriptFails97=== RUN TestScriptTokenEmptyCommand98=== PAUSE TestScriptTokenEmptyCommand99=== CONT TestDoServerRequestAttachesToken100=== CONT TestScriptTokenBadJSON101=== CONT TestScriptTokenEmptyCommand102--- PASS: TestScriptTokenEmptyCommand (0.00s)103=== CONT TestShellSplitErrors104--- PASS: TestShellSplitErrors (0.00s)105=== CONT TestShellSplit106=== CONT TestResolveStorePath107--- PASS: TestShellSplit (0.00s)108=== CONT TestDoWithRetry_BodyReplayedViaGetBody109=== CONT TestScriptTokenEmptyToken110=== CONT TestScriptTokenCachesUntilRefresh111=== CONT TestScriptTokenNoExpiryRerunsEveryCall112=== CONT TestFileTokenEmpty113=== CONT TestFileTokenMissing114=== CONT TestFileTokenReadsAndCaches115=== CONT TestStaticToken116=== CONT TestRateLimiterFeedback117=== CONT TestPathInfoHashCompatibility118=== RUN TestRateLimiterFeedback/429_enables_limiter119=== PAUSE TestRateLimiterFeedback/429_enables_limiter120=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)121=== CONT TestGetStorePathHash122=== CONT TestSetClientTLSDoesNotMutateDefaultTransport123=== CONT TestPathInfoCACompatibility124=== RUN TestPathInfoCACompatibility/null_ca_field125=== PAUSE TestPathInfoCACompatibility/null_ca_field126=== RUN TestPathInfoCACompatibility/old_string_format_-_text127=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text128=== CONT TestSetClientTLS129=== CONT TestClientSignaturesByStorePath130=== CONT TestStreamPushReportsSignatures131=== CONT TestStreamPushRequestLine132=== CONT TestStreamPushGivesUpOnDeadServer133=== CONT TestScriptTokenScriptFails134=== CONT TestStreamPushIsolatesFailures135=== CONT TestStreamPushBatchesUnderLoad136=== CONT TestDumpPathWriterError137=== CONT TestStreamPushReportsEveryPath138=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess139--- PASS: TestResolveStorePath (0.00s)140--- PASS: TestStaticToken (0.00s)141--- PASS: TestScriptTokenBadJSON (0.00s)142--- PASS: TestFileTokenMissing (0.00s)143--- PASS: TestClientSignaturesByStorePath (0.00s)144=== CONT TestConvertHashToNix32145=== CONT TestSetClientTLSErrors146--- PASS: TestFileTokenEmpty (0.00s)1472026/10/07 07:42:44 WARN Rate limiter enabled after throttle name=server-test rate=51482026/10/07 07:42:44 ERROR Upload failed error="connection refused" count=201492026/10/07 07:42:44 ERROR Server seems unavailable, giving up on batch untried=171502026/10/07 07:42:44 WARN Rate limiter enabled after throttle name=server-test rate=51512026/10/07 07:42:44 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:415771522026/10/07 07:42:44 ERROR Upload failed error=boom count=11532026/10/07 07:42:44 ERROR Upload failed error="bad path" count=3154=== RUN TestRateLimiterFeedback/503_enables_limiter1552026/10/07 07:42:44 ERROR Upload failed error=boom count=1156=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun157=== CONT TestDumpPathSingleFile158=== PAUSE TestRateLimiterFeedback/503_enables_limiter159=== RUN TestGetStorePathHash/valid_store_path160=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive161=== PAUSE TestGetStorePathHash/valid_store_path162=== RUN TestGetStorePathHash/basename_without_hyphen_should_error1632026/10/07 07:42:44 WARN Rate limiter backed off name=server-test rate=5164=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive1652026/10/07 07:42:44 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:41577166=== RUN TestPathInfoCACompatibility/new_structured_format_-_text167=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text168=== CONT TestPartSizeForNAR169--- PASS: TestFileTokenReadsAndCaches (0.00s)170=== CONT TestEncodeNixBase32WithRealHash171=== CONT TestParsePathInfoJSON172=== CONT TestEncodeNixBase32173=== CONT TestParsePathInfoJSONMultiplePaths174=== CONT TestUploadMultipart_PartsInParallel175=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)176=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter177=== CONT TestFilterOversizedClosures178=== RUN TestSetClientTLSErrors/missing_cert_file179=== RUN TestConvertHashToNix32/SRI_format_to_Nix32180=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error181=== CONT TestCaseHackSuffix182=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method183=== RUN TestPartSizeForNAR/zero_stays_at_minimum184--- PASS: TestStreamPushReportsEveryPath (0.00s)185--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)186--- PASS: TestScriptTokenEmptyToken (0.01s)187--- PASS: TestStreamPushIsolatesFailures (0.00s)188--- PASS: TestStreamPushReportsSignatures (0.00s)189--- PASS: TestScriptTokenScriptFails (0.00s)190--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)191--- PASS: TestDoServerRequestAttachesToken (0.01s)192=== CONT TestDumpPathMatchesNix193--- PASS: TestEncodeNixBase32WithRealHash (0.00s)194=== RUN TestParsePathInfoJSON/Nix_format195--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)196=== PAUSE TestParsePathInfoJSON/Nix_format197=== RUN TestSetClientTLS/rejects_connection_without_client_cert1982026/10/07 07:42:44 INFO Garbage collection started199=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths200=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon201=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon202=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter203=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32204=== RUN TestConvertHashToNix32/already_Nix32_format205=== PAUSE TestSetClientTLSErrors/missing_cert_file206=== RUN TestSetClientTLSErrors/missing_key_file207=== RUN TestFilterOversizedClosures/no_limit_keeps_everything208=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error209=== RUN TestEncodeNixBase32/test_string_hash210=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica211=== RUN TestParsePathInfoJSON/Lix_format212=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert213=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths214=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI215=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter216=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA217=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths218=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method219=== CONT TestRegisterUploadedObjectReusesConnections220=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum221--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.02s)222=== RUN TestPartSizeForNAR/small_stays_at_minimum223=== PAUSE TestPartSizeForNAR/small_stays_at_minimum224=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum225=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum226=== CONT TestUploadMultipart_SupersededByPeer227=== RUN TestUploadMultipart_SupersededByPeer/exists228=== CONT TestPathInfoCACompatibility/null_ca_field229=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts230=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything231=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error232=== PAUSE TestEncodeNixBase32/test_string_hash233=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts234=== RUN TestPartSizeForNAR/1_TiB235=== PAUSE TestPartSizeForNAR/1_TiB236=== RUN TestPartSizeForNAR/5_TiB_S3_max_object237=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object238=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped239=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped240=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter241=== RUN TestFilterOversizedClosures/all_closures_skipped242=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA243=== RUN TestPartSizeForNAR/capped_at_5_GiB244=== PAUSE TestParsePathInfoJSON/Lix_format245=== RUN TestParsePathInfoJSON/empty_input246=== PAUSE TestParsePathInfoJSON/empty_input247=== RUN TestParsePathInfoJSON/whitespace_only248=== PAUSE TestParsePathInfoJSON/whitespace_only249=== RUN TestParsePathInfoJSON/invalid_JSON250=== PAUSE TestParsePathInfoJSON/invalid_JSON251=== PAUSE TestPartSizeForNAR/capped_at_5_GiB252=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method253=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error254=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error255=== CONT TestRateLimiterFeedback/429_enables_limiter256=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter257=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths258=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI259=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512260=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512261=== PAUSE TestFilterOversizedClosures/all_closures_skipped262=== CONT TestRateLimiterFeedback/503_enables_limiter263=== RUN TestSetClientTLS/preserves_debug_logging_transport264=== PAUSE TestSetClientTLS/preserves_debug_logging_transport265=== PAUSE TestConvertHashToNix32/already_Nix32_format266=== RUN TestConvertHashToNix32/invalid_format267=== PAUSE TestConvertHashToNix32/invalid_format268=== CONT TestPathInfoCACompatibility/new_structured_format_-_text2692026/10/07 07:42:44 WARN Rate limiter enabled after throttle name=server-test rate=5270=== CONT TestParsePathInfoJSON/invalid_JSON271=== CONT TestPartSizeForNAR/zero_stays_at_minimum272=== CONT TestParsePathInfoJSON/empty_input273=== CONT TestPartSizeForNAR/capped_at_5_GiB2742026/10/07 07:42:44 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:43525275=== CONT TestParsePathInfoJSON/Lix_format276=== PAUSE TestSetClientTLSErrors/missing_key_file277=== CONT TestPartSizeForNAR/1_TiB278=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum279=== CONT TestPartSizeForNAR/small_stays_at_minimum280=== CONT TestGetStorePathHash/basename_without_hyphen_should_error281=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error282=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error283=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths2842026/10/07 07:42:44 WARN Rate limiter backed off name=server-test rate=52852026/10/07 07:42:44 INFO Garbage collection started286=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2872026/10/07 07:42:44 WARN Rate limiter enabled after throttle name=server-test rate=52882026/10/07 07:42:44 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:33513289=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)290=== CONT TestFilterOversizedClosures/no_limit_keeps_everything291=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI292=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512293=== CONT TestSetClientTLS/rejects_connection_without_client_cert2942026/10/07 07:42:44 WARN Rate limiter backed off name=server-test rate=5295=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon296=== CONT TestSetClientTLS/preserves_debug_logging_transport297=== CONT TestGetStorePathHash/valid_store_path298=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA299=== CONT TestFilterOversizedClosures/all_closures_skipped3002026/10/07 07:42:44 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=50301=== CONT TestConvertHashToNix32/SRI_format_to_Nix32302=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped303=== CONT TestPartSizeForNAR/5_TiB_S3_max_object3042026/10/07 07:42:44 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=2000305=== CONT TestConvertHashToNix32/already_Nix32_format306=== CONT TestConvertHashToNix32/invalid_format307=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts308--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.04s)309--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)310=== CONT TestPathInfoCACompatibility/old_string_format_-_text311=== RUN TestEncodeNixBase32/empty_input312=== PAUSE TestEncodeNixBase32/empty_input313=== CONT TestEncodeNixBase32/test_string_hash314=== CONT TestEncodeNixBase32/empty_input315--- PASS: TestEncodeNixBase32 (0.04s)316 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)317 --- PASS: TestEncodeNixBase32/empty_input (0.00s)318=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter319--- PASS: TestGetStorePathHash (0.04s)320 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)321 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)322 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)323 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)324--- PASS: TestParsePathInfoJSONMultiplePaths (0.04s)325 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)326 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)327=== CONT TestParsePathInfoJSON/Nix_format328=== CONT TestParsePathInfoJSON/whitespace_only329=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive330=== RUN TestSetClientTLSErrors/missing_ca_file331=== PAUSE TestUploadMultipart_SupersededByPeer/exists332=== RUN TestUploadMultipart_SupersededByPeer/missing333=== PAUSE TestUploadMultipart_SupersededByPeer/missing334=== CONT TestUploadMultipart_SupersededByPeer/exists335=== PAUSE TestSetClientTLSErrors/missing_ca_file336=== RUN TestSetClientTLSErrors/invalid_ca_file337=== PAUSE TestSetClientTLSErrors/invalid_ca_file338=== CONT TestSetClientTLSErrors/missing_cert_file339=== CONT TestSetClientTLSErrors/invalid_ca_file340=== CONT TestUploadMultipart_SupersededByPeer/missing341=== CONT TestSetClientTLSErrors/missing_ca_file342--- PASS: TestFilterOversizedClosures (0.04s)343 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)344 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)345 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)346=== CONT TestSetClientTLSErrors/missing_key_file347--- PASS: TestConvertHashToNix32 (0.04s)348 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)349 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)350 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)351--- PASS: TestPathInfoHashCompatibility (0.04s)352 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)353 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)354 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)355 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)356--- PASS: TestPathInfoCACompatibility (0.01s)357 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)358 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)359 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.03s)360 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)361 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)362--- PASS: TestPartSizeForNAR (0.04s)363 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)364 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)365 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)366 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)367 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)368 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)369 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)370--- PASS: TestParsePathInfoJSON (0.04s)371 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)372 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)373 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)374 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)375 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)376--- PASS: TestRateLimiterFeedback (0.04s)377 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)378 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)379 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)380 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)381--- PASS: TestUploadMultipart_SupersededByPeer (0.03s)382 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)383 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)384--- PASS: TestSetClientTLSErrors (0.05s)385 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)386 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)387 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)388 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)3892026/10/07 07:42:44 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=0390--- PASS: TestDumpPathSingleFile (0.05s)3912026/10/07 07:42:44 http: TLS handshake error from 127.0.0.1:59660: remote error: tls: bad certificate392--- PASS: TestSetClientTLS (0.04s)393 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)394 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)395 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)3962026/10/07 07:42:44 WARN Garbage collection finished on another replica. Its statistics are not available here397--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.05s)398--- PASS: TestCaseHackSuffix (0.06s)399--- PASS: TestRegisterUploadedObjectReusesConnections (0.06s)400--- PASS: TestStreamPushRequestLine (0.07s)401--- PASS: TestDumpPathWriterError (0.07s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestDumpPathMatchesNix (0.10s)404--- PASS: TestUploadMultipart_PartsInParallel (0.66s)405--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)406PASS407Running server tests...408The files belonging to this database system will be owned by user "nixbld".409This user must also own the server process.410411The database cluster will be initialized with locale "C".412The default database encoding has accordingly been set to "SQL_ASCII".413The default text search configuration will be set to "english".414415Data page checksums are enabled.416417creating directory /build/postgres2814872175/data ... ok418creating subdirectories ... ok419selecting dynamic shared memory implementation ... posix420selecting default "max_connections" ... 100421selecting default "shared_buffers" ... 128MB422selecting default time zone ... UTC423creating configuration files ... ok424running bootstrap script ... ok425performing post-bootstrap initialization ... ok426syncing data to disk ... ok427428initdb: warning: enabling "trust" authentication for local connections429initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.430431Success. You can now start the database server using:432433 pg_ctl -D /build/postgres2814872175/data -l logfile start434435/build/postgres2814872175:5432 - no response4362026-10-07 07:42:45.925 UTC [128] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-07 07:42:45.926 UTC [128] LOG: listening on Unix socket "/build/postgres2814872175/.s.PGSQL.5432"4382026-10-07 07:42:45.930 UTC [135] LOG: database system was shut down at 2026-10-07 07:42:45 UTC4392026-10-07 07:42:45.935 UTC [128] LOG: database system is ready to accept connections440/build/postgres2814872175:5432 - accepting connections441=== RUN TestService_AuthMiddleware442=== PAUSE TestService_AuthMiddleware443=== RUN TestService_AuthMiddleware_MTLSProxyHeader444=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader445=== RUN TestService_AuthMiddleware_MTLSBoundSubjects446=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects447=== RUN TestService_ReadAuthMiddleware448=== PAUSE TestService_ReadAuthMiddleware449=== RUN TestService_AuthMiddleware_OIDC450=== PAUSE TestService_AuthMiddleware_OIDC451=== RUN TestService_RequireScope_OIDC452=== PAUSE TestService_RequireScope_OIDC453=== RUN TestService_ReadScope_PublicByDefault454=== PAUSE TestService_ReadScope_PublicByDefault455=== RUN TestCacheConfigHandler456=== PAUSE TestCacheConfigHandler457=== RUN TestCacheStatsHandler458=== PAUSE TestCacheStatsHandler459=== RUN TestClientCADerivations460=== PAUSE TestClientCADerivations461=== RUN TestClientErrorHandling462=== PAUSE TestClientErrorHandling463=== RUN TestClientIntegration464=== PAUSE TestClientIntegration465=== RUN TestClientMultipleUploads466=== PAUSE TestClientMultipleUploads467=== RUN TestClientWithDependencies468=== PAUSE TestClientWithDependencies469=== RUN TestClientSharedPathCommittedMidPush470=== PAUSE TestClientSharedPathCommittedMidPush471=== RUN TestPinProtectsFromGC472=== PAUSE TestPinProtectsFromGC473=== RUN TestClientPushesUseOnePush474=== PAUSE TestClientPushesUseOnePush475=== RUN TestClientFallsBackToClosures476=== PAUSE TestClientFallsBackToClosures477=== RUN TestDeleteClosuresRacingPins478=== PAUSE TestDeleteClosuresRacingPins479=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock480=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock481=== RUN TestResolveDBConnectionString482=== PAUSE TestResolveDBConnectionString483=== RUN TestConnectWaitsForAPeerMigration484=== PAUSE TestConnectWaitsForAPeerMigration485=== RUN TestLeadElectsOneAndHandsOver486=== PAUSE TestLeadElectsOneAndHandsOver487=== RUN TestLeadIncumbentWinsAfterRestart4882026/10/07 07:42:46 INFO lead: acquired remote=192.0.2.1:12344892026/10/07 07:42:46 INFO lead: released remote=192.0.2.1:12344902026/10/07 07:42:47 INFO lead: acquired remote=192.0.2.1:12344912026/10/07 07:42:48 INFO lead: released remote=192.0.2.1:1234492--- PASS: TestLeadIncumbentWinsAfterRestart (1.83s)493=== RUN TestLeadIncumbentAnnouncesAtOnce494=== PAUSE TestLeadIncumbentAnnouncesAtOnce495=== RUN TestLeadEndsOnShutdown496=== PAUSE TestLeadEndsOnShutdown497=== RUN TestLeadEndsWhenItsConnectionHangs4982026/10/07 07:42:48 INFO lead: acquired remote=192.0.2.1:12344992026-10-07 07:42:49.578 UTC [384] FATAL: terminating connection due to administrator command5002026/10/07 07:42:49 INFO lead: acquired remote=192.0.2.1:12345012026/10/07 07:42:50 WARN lead: lock connection lost error="timeout: context deadline exceeded"5022026/10/07 07:42:50 INFO lead: released remote=192.0.2.1:12345032026/10/07 07:42:51 INFO lead: released remote=192.0.2.1:1234504--- PASS: TestLeadEndsWhenItsConnectionHangs (3.12s)505=== RUN TestGCAdvisoryLockBlocksConcurrentRun506=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun507=== RUN TestGCBugBareHashReferences508=== PAUSE TestGCBugBareHashReferences509=== RUN TestGCMetrics510=== PAUSE TestGCMetrics511=== RUN TestPushDedupSurvivesConcurrentGC512=== PAUSE TestPushDedupSurvivesConcurrentGC513=== RUN TestDeduplicatedObjectsRecordedAsPending514=== PAUSE TestDeduplicatedObjectsRecordedAsPending515=== RUN TestGCSweepSkipsPendingObjects516=== PAUSE TestGCSweepSkipsPendingObjects517=== RUN TestTombstonedObjectOfferedWithoutWaiting518=== PAUSE TestTombstonedObjectOfferedWithoutWaiting519=== RUN TestGCSweepDeliversEachKeyOnce520=== PAUSE TestGCSweepDeliversEachKeyOnce521=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection522=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== RUN TestForceGCDuringPushOffersSweptObject524=== PAUSE TestForceGCDuringPushOffersSweptObject525=== RUN TestFailedS3DeleteKeepsTombstone526=== PAUSE TestFailedS3DeleteKeepsTombstone527=== RUN TestSweepSkipsRowsLockedByPush528=== PAUSE TestSweepSkipsRowsLockedByPush529=== RUN TestRegisterCompletedObjectNeedsPendingRow530=== PAUSE TestRegisterCompletedObjectNeedsPendingRow531=== RUN TestGetExistingObjectsLocksRows532=== PAUSE TestGetExistingObjectsLocksRows533=== RUN TestSweepRechecksPendingAfterLocking534=== PAUSE TestSweepRechecksPendingAfterLocking535=== RUN TestPushWaitsForSweepHoldingRow536=== PAUSE TestPushWaitsForSweepHoldingRow537=== RUN TestCommitRacingPendingCleanupKeepsObjects538=== PAUSE TestCommitRacingPendingCleanupKeepsObjects539=== RUN TestGCEndsOnShutdown540=== PAUSE TestGCEndsOnShutdown541=== RUN TestGCTaskStore_StartNew542=== PAUSE TestGCTaskStore_StartNew543=== RUN TestGCTaskStore_DeduplicateSameParams544=== PAUSE TestGCTaskStore_DeduplicateSameParams545=== RUN TestGCTaskStore_ConflictDifferentParams546=== PAUSE TestGCTaskStore_ConflictDifferentParams547=== RUN TestGCTaskStore_GetEmpty548=== PAUSE TestGCTaskStore_GetEmpty549=== RUN TestGCTaskStore_GetReturnsLatest550=== PAUSE TestGCTaskStore_GetReturnsLatest551=== RUN TestGCTaskStore_CompletedAllowsNewTask552=== PAUSE TestGCTaskStore_CompletedAllowsNewTask553=== RUN TestGCTaskStore_PhaseUpdates554=== PAUSE TestGCTaskStore_PhaseUpdates555=== RUN TestGCTaskStore_Fail556=== PAUSE TestGCTaskStore_Fail557=== RUN TestGracefulShutdownDrainsInflight558=== PAUSE TestGracefulShutdownDrainsInflight559=== RUN TestService_healthCheckHandler560=== PAUSE TestService_healthCheckHandler561=== RUN TestService_readinessHandler562=== PAUSE TestService_readinessHandler563=== RUN TestGenerateLandingPage564=== PAUSE TestGenerateLandingPage565=== RUN TestCacheConfigHandlerMaxNarSize566=== PAUSE TestCacheConfigHandlerMaxNarSize567=== RUN TestCreatePendingClosureRejectsOversizedNAR568=== PAUSE TestCreatePendingClosureRejectsOversizedNAR569=== RUN TestNARDeduplicationMetadataUploadBug570=== PAUSE TestNARDeduplicationMetadataUploadBug571=== RUN TestMetricsInventory572=== PAUSE TestMetricsInventory573=== RUN TestMetricsCommit574=== PAUSE TestMetricsCommit575=== RUN TestService_NativeMTLS576=== PAUSE TestService_NativeMTLS577=== RUN TestServerTLSConfig578=== PAUSE TestServerTLSConfig579=== RUN TestMultipartCleanup580=== PAUSE TestMultipartCleanup581=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded582=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded583=== RUN TestPendingCleanupUsesOneCutoff584=== PAUSE TestPendingCleanupUsesOneCutoff585=== RUN TestObjectStatsTrigger586=== PAUSE TestObjectStatsTrigger587=== RUN TestObjectStatsLargeCommit588=== PAUSE TestObjectStatsLargeCommit589=== RUN TestOrphanedObjectsGC590=== PAUSE TestOrphanedObjectsGC591=== RUN TestOrphanedObjectsGCStressTest592=== PAUSE TestOrphanedObjectsGCStressTest593=== RUN TestCreatePin_ReservedPins594=== PAUSE TestCreatePin_ReservedPins595=== RUN TestPresentReportsOnlyClosureRoots596=== PAUSE TestPresentReportsOnlyClosureRoots597=== RUN TestPresentRefreshesOnlyStaleClosures598=== PAUSE TestPresentRefreshesOnlyStaleClosures599=== RUN TestPresentNotReportedWhileGCDeletesClosure600=== PAUSE TestPresentNotReportedWhileGCDeletesClosure601=== RUN TestParseSingleRange602=== PAUSE TestParseSingleRange603=== RUN TestProxyHeadersOnlyTrustedOnSocket6042026/10/07 07:42:51 INFO Starting HTTP server address=127.0.0.1:379876052026/10/07 07:42:51 INFO Starting HTTP server address=proxy.sock6062026/10/07 07:42:51 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6072026/10/07 07:42:51 INFO Shutdown signal received, draining in-flight requests timeout=10s608--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.11s)609=== RUN TestIsValidCachePath610=== PAUSE TestIsValidCachePath611=== RUN TestReadProxyNarinfo612=== PAUSE TestReadProxyNarinfo613=== RUN TestReadProxyNarinfoAlreadyDecompressed614=== PAUSE TestReadProxyNarinfoAlreadyDecompressed615=== RUN TestReadProxyContentNegotiation616=== PAUSE TestReadProxyContentNegotiation617=== RUN TestReadProxyNarStreaming618=== PAUSE TestReadProxyNarStreaming619=== RUN TestReadProxy404620=== PAUSE TestReadProxy404621=== RUN TestReadProxyInvalidPath622=== PAUSE TestReadProxyInvalidPath623=== RUN TestReadProxyHead624=== PAUSE TestReadProxyHead625=== RUN TestReadProxyOutlastsServerWriteTimeout626=== PAUSE TestReadProxyOutlastsServerWriteTimeout627=== RUN TestReadProxyConditionalGet628=== PAUSE TestReadProxyConditionalGet629=== RUN TestReadProxyRootRedirectsToIndexHTML630=== PAUSE TestReadProxyRootRedirectsToIndexHTML631=== RUN TestReadProxyDisabled632=== PAUSE TestReadProxyDisabled633=== RUN TestReadRedirectNar634=== PAUSE TestReadRedirectNar635=== RUN TestReadRedirectKeepsNarinfoProxied636=== PAUSE TestReadRedirectKeepsNarinfoProxied637=== RUN TestReadProxyRangeRequest638=== PAUSE TestReadProxyRangeRequest639=== RUN TestReadRedirectUsesPublicS3URL640=== PAUSE TestReadRedirectUsesPublicS3URL641=== RUN TestPush_OverlappingRootsStoreOneRowPerKey642=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey643=== RUN TestPush_CompleteCommitsEveryRoot644=== PAUSE TestPush_CompleteCommitsEveryRoot645=== RUN TestPush_RepeatedRootCommitsOnce646=== PAUSE TestPush_RepeatedRootCommitsOnce647=== RUN TestPush_CompleteWaitsForCleanupOfThePush648=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush649=== RUN TestPush_RootsAreLockedInByteOrder650=== PAUSE TestPush_RootsAreLockedInByteOrder651=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit652=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit653=== RUN TestPush_RejectsBadRequests654=== PAUSE TestPush_RejectsBadRequests655=== RUN TestPush_SignsNarinfosOfItsPendingObjects656=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects657=== RUN TestRedundantMultipartUpload658=== PAUSE TestRedundantMultipartUpload659=== RUN TestCompleteMultipartUpload_ErrorButObjectExists660=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists661=== RUN TestCompletedNarNotReofferedAcrossClosures662=== PAUSE TestCompletedNarNotReofferedAcrossClosures663=== RUN TestPresignedUploadRegisteredBeforeCommit664=== PAUSE TestPresignedUploadRegisteredBeforeCommit665=== RUN TestService_Rustfstest666=== PAUSE TestService_Rustfstest667=== RUN TestParseSize668=== PAUSE TestParseSize669=== RUN TestSkippedUploadsHandler670=== PAUSE TestSkippedUploadsHandler671=== RUN TestSystemdListenerNotActivated672--- PASS: TestSystemdListenerNotActivated (0.00s)673=== RUN TestWatchdogBeatsWhenHealthy674--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)675=== RUN TestWatchdogSkipsWhenUnhealthy6762026/10/07 07:42:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6772026/10/07 07:42:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6782026/10/07 07:42:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6792026/10/07 07:42:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6802026/10/07 07:42:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6812026/10/07 07:42:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6822026/10/07 07:42:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6832026/10/07 07:42:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6842026/10/07 07:42:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6852026/10/07 07:42:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"686--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)687=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle688=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle689=== RUN TestProxyWriteTimeout690=== PAUSE TestProxyWriteTimeout691=== RUN TestPendingClosureWriteTimeout692=== PAUSE TestPendingClosureWriteTimeout693=== RUN TestIsValidUploadKey694=== PAUSE TestIsValidUploadKey695=== RUN TestUploadHandlersRejectInvalidKeys696=== PAUSE TestUploadHandlersRejectInvalidKeys697=== RUN TestUploadHandlersRejectOversizedBody698=== PAUSE TestUploadHandlersRejectOversizedBody699=== RUN TestService_cleanupPendingClosuresHandler700=== PAUSE TestService_cleanupPendingClosuresHandler701=== RUN TestService_createPendingClosureHandler702=== PAUSE TestService_createPendingClosureHandler703=== RUN TestService_verifyS3Integrity704=== PAUSE TestService_verifyS3Integrity705=== RUN TestCompleteMultipartUnregistered706=== PAUSE TestCompleteMultipartUnregistered707=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT708=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT709=== CONT TestSkippedUploadsHandler710=== CONT TestPush_RepeatedRootCommitsOnce711=== CONT TestPushWaitsForSweepHoldingRow712=== CONT TestParseSize7132026/10/07 07:42:51 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000714--- PASS: TestParseSize (0.00s)715=== CONT TestService_Rustfstest716=== CONT TestSweepRechecksPendingAfterLocking717=== CONT TestPresignedUploadRegisteredBeforeCommit718=== CONT TestCompletedNarNotReofferedAcrossClosures719=== CONT TestCompleteMultipartUpload_ErrorButObjectExists720=== CONT TestRedundantMultipartUpload721=== CONT TestPush_SignsNarinfosOfItsPendingObjects722=== CONT TestGCTaskStore_CompletedAllowsNewTask723--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)724=== CONT TestGetExistingObjectsLocksRows725=== CONT TestGCTaskStore_GetReturnsLatest726--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)727=== CONT TestRegisterCompletedObjectNeedsPendingRow728=== CONT TestGCTaskStore_GetEmpty729--- PASS: TestGCTaskStore_GetEmpty (0.00s)730=== CONT TestSweepSkipsRowsLockedByPush731=== CONT TestGCTaskStore_ConflictDifferentParams732--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)733=== CONT TestFailedS3DeleteKeepsTombstone734=== CONT TestGCTaskStore_PhaseUpdates735--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)736=== CONT TestClientFallsBackToClosures737=== CONT TestGCTaskStore_DeduplicateSameParams738--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)739=== CONT TestClientPushesUseOnePush740=== CONT TestPush_RejectsBadRequests741=== CONT TestGCTaskStore_StartNew742--- PASS: TestGCTaskStore_StartNew (0.00s)743=== CONT TestPinProtectsFromGC744=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit745--- PASS: TestSkippedUploadsHandler (0.00s)746=== CONT TestClientSharedPathCommittedMidPush747=== CONT TestGCEndsOnShutdown748=== RUN TestGCEndsOnShutdown/before_the_run749=== PAUSE TestGCEndsOnShutdown/before_the_run750=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete751=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete752=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark753=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark754=== CONT TestClientWithDependencies755=== CONT TestPush_RootsAreLockedInByteOrder756=== CONT TestCommitRacingPendingCleanupKeepsObjects757=== CONT TestService_AuthMiddleware758=== CONT TestPush_CompleteWaitsForCleanupOfThePush7592026/10/07 07:42:51 INFO Received uploads request method=POST path=/api/pending_closures7602026/10/07 07:42:51 INFO Received uploads request method=POST path=/api/pending_closures7612026/10/07 07:42:51 INFO Aborted multipart uploads count=0 kept=07622026/10/07 07:42:51 WARN Force mode enabled - objects will be deleted immediately without grace period7632026/10/07 07:42:51 INFO Received uploads request method=POST path=/api/pending_closures7642026/10/07 07:42:51 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=0765--- PASS: TestService_Rustfstest (0.31s)766=== CONT TestClientMultipleUploads7672026/10/07 07:42:51 INFO Vacuumed table table=pending_closures7682026/10/07 07:42:51 INFO Vacuumed table table=pending_objects7692026/10/07 07:42:51 INFO Vacuumed table table=multipart_uploads7702026/10/07 07:42:51 INFO Vacuumed table table=closures7712026/10/07 07:42:51 INFO Vacuumed table table=objects772--- PASS: TestSweepRechecksPendingAfterLocking (0.32s)773=== CONT TestClientIntegration7742026/10/07 07:42:51 INFO Received push request method=POST path=/api/pushes7752026/10/07 07:42:51 INFO Received uploads request method=POST path=/api/pending_closures7762026/10/07 07:42:51 INFO Received complete push request method=POST path=/api/pushes/1/complete7772026/10/07 07:42:51 INFO Completed push id=1 objects=4 duration=9.613884ms778--- PASS: TestPush_RepeatedRootCommitsOnce (0.36s)779=== CONT TestClientErrorHandling780=== RUN TestClientErrorHandling/InvalidStorePath781=== PAUSE TestClientErrorHandling/InvalidStorePath782=== RUN TestClientErrorHandling/InvalidAuthToken783=== PAUSE TestClientErrorHandling/InvalidAuthToken784=== RUN TestClientErrorHandling/ServerNotAvailable785=== PAUSE TestClientErrorHandling/ServerNotAvailable786=== CONT TestClientCADerivations787--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.37s)788=== CONT TestCacheStatsHandler7892026/10/07 07:42:51 INFO Received push request method=POST path=/api/pushes7902026/10/07 07:42:51 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7912026/10/07 07:42:51 INFO Signed narinfos id=1 count=17922026/10/07 07:42:51 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7932026/10/07 07:42:51 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7942026/10/07 07:42:51 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"7952026/10/07 07:42:51 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7962026/10/07 07:42:51 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"7972026/10/07 07:42:51 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7982026/10/07 07:42:51 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=17992026/10/07 07:42:51 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8002026/10/07 07:42:51 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo801--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.41s)802=== CONT TestDeleteClosuresRacingPins8032026/10/07 07:42:51 INFO Received uploads request method=POST path=/api/pending_closures8042026/10/07 07:42:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8052026/10/07 07:42:51 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OWRkNzcyZjMtODVhNy00NzhlLWI0NTEtYTgwNjhkMmMzNGYwLjg1OTRmMTQzLTVmZTgtNDI4Mi1iMjhmLTYyMDZjNjViNzE1OXgxNzkxMzU4OTcxOTMzNzkyNDc2806--- PASS: TestGetExistingObjectsLocksRows (0.45s)807=== CONT TestForceGCDuringPushOffersSweptObject808=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows809=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows810=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check811=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check812=== CONT TestCacheConfigHandler813=== RUN TestCacheConfigHandler/full_config,_no_issuer814=== PAUSE TestCacheConfigHandler/full_config,_no_issuer815=== RUN TestCacheConfigHandler/no_cache_url_configured816=== PAUSE TestCacheConfigHandler/no_cache_url_configured817=== RUN TestCacheConfigHandler/no_signing_keys818=== PAUSE TestCacheConfigHandler/no_signing_keys819=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator820=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator821=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection8222026/10/07 07:42:51 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OWRkNzcyZjMtODVhNy00NzhlLWI0NTEtYTgwNjhkMmMzNGYwLjg1OTRmMTQzLTVmZTgtNDI4Mi1iMjhmLTYyMDZjNjViNzE1OXgxNzkxMzU4OTcxOTMzNzkyNDc2 parts=1823--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.45s)824=== CONT TestService_ReadScope_PublicByDefault825=== RUN TestPush_RejectsBadRequests/root_not_in_objects826=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects827=== RUN TestPush_RejectsBadRequests/no_roots828=== PAUSE TestPush_RejectsBadRequests/no_roots829=== RUN TestPush_RejectsBadRequests/no_objects830=== PAUSE TestPush_RejectsBadRequests/no_objects831=== RUN TestPush_RejectsBadRequests/bad_root832=== PAUSE TestPush_RejectsBadRequests/bad_root833=== CONT TestGCSweepDeliversEachKeyOnce8342026/10/07 07:42:52 INFO Aborted multipart uploads count=0 kept=08352026/10/07 07:42:52 WARN Force mode enabled - objects will be deleted immediately without grace period8362026/10/07 07:42: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=08372026/10/07 07:42:52 INFO Vacuumed table table=pending_closures8382026/10/07 07:42:52 INFO Vacuumed table table=pending_objects8392026/10/07 07:42:52 INFO Vacuumed table table=multipart_uploads8402026/10/07 07:42:52 INFO Vacuumed table table=closures8412026/10/07 07:42:52 INFO Vacuumed table table=objects8422026/10/07 07:42:52 INFO Aborted multipart uploads count=0 kept=08432026/10/07 07:42:52 WARN Force mode enabled - objects will be deleted immediately without grace period8442026/10/07 07:42:52 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=08452026/10/07 07:42:52 INFO Vacuumed table table=pending_closures8462026/10/07 07:42:52 INFO Vacuumed table table=pending_objects8472026/10/07 07:42:52 INFO Vacuumed table table=multipart_uploads8482026/10/07 07:42:52 INFO Vacuumed table table=closures8492026/10/07 07:42:52 INFO Vacuumed table table=objects850--- PASS: TestSweepSkipsRowsLockedByPush (0.54s)851=== CONT TestService_RequireScope_OIDC8522026/10/07 07:42:52 INFO Received push request method=POST path=/api/pushes853=== NAME TestClientWithDependencies854 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies281621646/001/store/3g3bfrp111gh5n6rrg2sf2zf707mv8h9-test-script8552026-10-07 07:42:52.137 UTC [663] ERROR: could not obtain lock on row in relation "closures"8562026-10-07 07:42:52.137 UTC [663] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8572026-10-07 07:42:52.138 UTC [663] ERROR: could not obtain lock on row in relation "closures"8582026-10-07 07:42:52.138 UTC [663] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8592026-10-07 07:42:52.138 UTC [663] ERROR: could not obtain lock on row in relation "closures"8602026-10-07 07:42:52.138 UTC [663] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8612026-10-07 07:42:52.138 UTC [663] ERROR: could not obtain lock on row in relation "closures"8622026-10-07 07:42:52.138 UTC [663] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8632026-10-07 07:42:52.138 UTC [663] ERROR: could not obtain lock on row in relation "closures"8642026-10-07 07:42:52.138 UTC [663] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT865--- PASS: TestPush_RootsAreLockedInByteOrder (0.62s)866=== CONT TestTombstonedObjectOfferedWithoutWaiting8672026/10/07 07:42:52 INFO Received uploads request method=POST path=/api/pending_closures868=== NAME TestClientWithDependencies869 client_integration_test.go:615: Found 1 dependencies (including self)8702026/10/07 07:42:52 INFO Received uploads request method=POST path=/api/pending_closures8712026/10/07 07:42:52 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)8722026/10/07 07:42:52 INFO Uploading ag89pzfh3rdkr8rfyf9cb08paxhml6nl-b (216B)8732026/10/07 07:42:52 INFO Uploading fcdia43hp4rmkzq14zais3fa62k09bls-shared-dep (136B)8742026/10/07 07:42:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8752026/10/07 07:42:52 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"876--- PASS: TestService_AuthMiddleware (0.65s)877=== CONT TestService_AuthMiddleware_OIDC8782026/10/07 07:42:52 INFO Aborted multipart uploads count=0 kept=08792026/10/07 07:42:52 WARN Failed to register uploaded object key=79l1mfl1rsjb95jzqf1jwf1pzpm5v5k6.ls error="server returned 404: 404 page not found\n"8802026/10/07 07:42:52 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"8812026/10/07 07:42:52 WARN Failed to register uploaded object key=nar/17frb3fpp6s15cqkv9cwkk8md0izapnniskhrc5bjfqincsvmq0i.nar.zst error="server returned 404: 404 page not found\n"8822026/10/07 07:42:52 WARN Failed to register uploaded object key=ag89pzfh3rdkr8rfyf9cb08paxhml6nl.ls error="server returned 404: 404 page not found\n"8832026/10/07 07:42:52 WARN Failed to register uploaded object key=fcdia43hp4rmkzq14zais3fa62k09bls.ls error="server returned 404: 404 page not found\n"8842026/10/07 07:42:52 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign8852026/10/07 07:42:52 INFO Signed narinfos id=2 count=28862026/10/07 07:42:52 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign8872026/10/07 07:42:52 INFO Signed narinfos id=1 count=28882026/10/07 07:42:52 INFO Uploading 4 narinfos8892026/10/07 07:42:52 WARN Force mode enabled - objects will be deleted immediately without grace period8902026/10/07 07:42:52 WARN Failed to register uploaded object key=79l1mfl1rsjb95jzqf1jwf1pzpm5v5k6.narinfo error="server returned 404: 404 page not found\n"8912026/10/07 07:42:52 WARN Failed to register uploaded object key=ag89pzfh3rdkr8rfyf9cb08paxhml6nl.narinfo error="server returned 404: 404 page not found\n"8922026/10/07 07:42:52 WARN Failed to register uploaded object key=fcdia43hp4rmkzq14zais3fa62k09bls.narinfo error="server returned 404: 404 page not found\n"8932026/10/07 07:42:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8942026/10/07 07:42:52 WARN Failed to register uploaded object key=fcdia43hp4rmkzq14zais3fa62k09bls.narinfo error="server returned 404: 404 page not found\n"8952026/10/07 07:42: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=08962026/10/07 07:42:52 INFO Vacuumed table table=pending_closures8972026/10/07 07:42:52 INFO Completed upload id=1 objects=6 duration=4.885583ms8982026/10/07 07:42:52 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete8992026/10/07 07:42:52 INFO Vacuumed table table=pending_objects9002026/10/07 07:42:52 INFO Vacuumed table table=multipart_uploads9012026/10/07 07:42:52 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=OWRkNzcyZjMtODVhNy00NzhlLWI0NTEtYTgwNjhkMmMzNGYwLmQwYzRkMTFkLTYyMDEtNGIyMy04OGY0LWIyMjM0MGM3OTZmN3gxNzkxMzU4OTcxNzgyMDU3NzUx parts=129022026/10/07 07:42:52 INFO Completed upload id=2 objects=6 duration=1.896357ms9032026/10/07 07:42:52 INFO Vacuumed table table=closures9042026/10/07 07:42:52 INFO Upload complete. (66ms)9052026/10/07 07:42:52 INFO Vacuumed table table=objects9062026/10/07 07:42:52 INFO Received uploads request method=POST path=/api/pending_closures907=== NAME TestClientFallsBackToClosures908 client_pushes_test.go:112: Retrieved narinfo from S3:909 StorePath: /build/TestClientFallsBackToClosures724514664/001/store/fcdia43hp4rmkzq14zais3fa62k09bls-shared-dep910 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst911 Compression: zstd912 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82913 NarSize: 136914 References: 915 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n9162026/10/07 07:42:52 INFO Received push request method=POST path=/api/pushes917 client_pushes_test.go:112: Retrieved narinfo from S3:918 StorePath: /build/TestClientFallsBackToClosures724514664/001/store/79l1mfl1rsjb95jzqf1jwf1pzpm5v5k6-a919 URL: nar/17frb3fpp6s15cqkv9cwkk8md0izapnniskhrc5bjfqincsvmq0i.nar.zst920 Compression: zstd921 NarHash: sha256:17frb3fpp6s15cqkv9cwkk8md0izapnniskhrc5bjfqincsvmq0i922 NarSize: 216923 References: /build/TestClientFallsBackToClosures724514664/001/store/fcdia43hp4rmkzq14zais3fa62k09bls-shared-dep924 CA: text:sha256:1nq641c38n2fwahjcm00vhrpa054vg0bi592nvdbj183xw7dw69v9252026/10/07 07:42:52 INFO Received uploads request method=POST path=/api/pending_closures926 client_pushes_test.go:112: Retrieved narinfo from S3:927 StorePath: /build/TestClientFallsBackToClosures724514664/001/store/ag89pzfh3rdkr8rfyf9cb08paxhml6nl-b928 URL: nar/17frb3fpp6s15cqkv9cwkk8md0izapnniskhrc5bjfqincsvmq0i.nar.zst929 Compression: zstd930 NarHash: sha256:17frb3fpp6s15cqkv9cwkk8md0izapnniskhrc5bjfqincsvmq0i931 NarSize: 216932 References: /build/TestClientFallsBackToClosures724514664/001/store/fcdia43hp4rmkzq14zais3fa62k09bls-shared-dep933 CA: text:sha256:1nq641c38n2fwahjcm00vhrpa054vg0bi592nvdbj183xw7dw69v9342026/10/07 07:42:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39047/oidc935--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.67s)936=== CONT TestGCSweepSkipsPendingObjects937--- PASS: TestClientFallsBackToClosures (0.67s)938=== CONT TestService_ReadAuthMiddleware9392026/10/07 07:42:52 INFO Received push request method=POST path=/api/pushes9402026/10/07 07:42:52 INFO Received uploads request method=POST path=/api/pending_closures9412026/10/07 07:42:52 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)9422026/10/07 07:42:52 INFO Uploading q0qn62znj19wk9dcf0p9rppyaqkxlyc8-top (224B)9432026/10/07 07:42:52 INFO Uploading p6y64sjcrfqxhzzmnzlv3dyll7zbz4ck-shared-dep (136B)9442026/10/07 07:42:52 WARN Failed to register uploaded object key=nar/1mskbzc7hcw9xl8krl3x5jvxliscnchark3d5ccmicns3hnnca0n.nar.zst error="server returned 404: 404 page not found\n"9452026/10/07 07:42:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9462026/10/07 07:42:52 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"9472026/10/07 07:42:52 WARN Failed to register uploaded object key=p6y64sjcrfqxhzzmnzlv3dyll7zbz4ck.ls error="server returned 404: 404 page not found\n"9482026/10/07 07:42:52 WARN Failed to register uploaded object key=q0qn62znj19wk9dcf0p9rppyaqkxlyc8.ls error="server returned 404: 404 page not found\n"9492026/10/07 07:42:52 INFO Signed narinfos id=1 count=29502026/10/07 07:42:52 INFO Uploading 2 narinfos9512026/10/07 07:42:52 WARN Failed to register uploaded object key=p6y64sjcrfqxhzzmnzlv3dyll7zbz4ck.narinfo error="server returned 404: 404 page not found\n"9522026/10/07 07:42:52 INFO Received complete push request method=POST path=/api/pushes/1/complete9532026/10/07 07:42:52 WARN Failed to register uploaded object key=q0qn62znj19wk9dcf0p9rppyaqkxlyc8.narinfo error="server returned 404: 404 page not found\n"954=== NAME TestPinProtectsFromGC955 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC3903751695/001/store/b9ww68gxiqvqhq7vrvlmq9z661qakwy6-pinned-file.txt956 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC3903751695/001/store/s60mgsfjajzrh72zvah50alw2bqid3rc-unpinned-file.txt9572026/10/07 07:42:52 INFO Received push request method=POST path=/api/pushes9582026/10/07 07:42:52 INFO Completed push id=1 objects=6 duration=6.133953ms9592026/10/07 07:42:52 INFO Upload complete. (62ms)960=== NAME TestClientSharedPathCommittedMidPush961 client_integration_test.go:680: Retrieved narinfo from S3:962 StorePath: /build/TestClientSharedPathCommittedMidPush3321593725/001/store/p6y64sjcrfqxhzzmnzlv3dyll7zbz4ck-shared-dep963 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst964 Compression: zstd965 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82966 NarSize: 136967 References: 968 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n9692026/10/07 07:42:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9702026/10/07 07:42:52 INFO Uploading 3g3bfrp111gh5n6rrg2sf2zf707mv8h9-test-script (136B)9712026/10/07 07:42:52 INFO Received push request method=POST path=/api/pushes972 client_integration_test.go:680: Retrieved narinfo from S3:973 StorePath: /build/TestClientSharedPathCommittedMidPush3321593725/001/store/q0qn62znj19wk9dcf0p9rppyaqkxlyc8-top974 URL: nar/1mskbzc7hcw9xl8krl3x5jvxliscnchark3d5ccmicns3hnnca0n.nar.zst975 Compression: zstd976 NarHash: sha256:1mskbzc7hcw9xl8krl3x5jvxliscnchark3d5ccmicns3hnnca0n977 NarSize: 224978 References: /build/TestClientSharedPathCommittedMidPush3321593725/001/store/p6y64sjcrfqxhzzmnzlv3dyll7zbz4ck-shared-dep979 CA: text:sha256:1qdg0cz40xvmyg9khn3b45mwbbmjy7qa0dpz3s0958qmp40rkfmy9802026/10/07 07:42:52 WARN Failed to register uploaded object key=3g3bfrp111gh5n6rrg2sf2zf707mv8h9.ls error="server returned 404: 404 page not found\n"9812026/10/07 07:42:52 WARN Failed to register uploaded object key=log/lbn4r7v8xfhx3dkh8l2glxwgalnyj11f-test-script.drv error="server returned 404: 404 page not found\n"9822026/10/07 07:42:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9832026/10/07 07:42:52 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"9842026/10/07 07:42:52 INFO Signed narinfos id=1 count=19852026/10/07 07:42:52 INFO Uploading 1 narinfos986--- PASS: TestClientSharedPathCommittedMidPush (0.72s)987=== CONT TestDeduplicatedObjectsRecordedAsPending9882026/10/07 07:42:52 INFO Received complete push request method=POST path=/api/pushes/1/complete9892026/10/07 07:42:52 WARN Failed to register uploaded object key=3g3bfrp111gh5n6rrg2sf2zf707mv8h9.narinfo error="server returned 404: 404 page not found\n"9902026/10/07 07:42:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9912026/10/07 07:42:52 INFO Received uploads request method=POST path=/api/pending_closures9922026/10/07 07:42:52 INFO Completed push id=1 objects=4 duration=15.887319ms9932026/10/07 07:42:52 INFO Upload complete. (68ms)9942026/10/07 07:42:52 INFO Received complete push request method=POST path=/api/pushes/1/complete995=== NAME TestClientWithDependencies996 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies281621646/001/store) requires matching store prefix997--- PASS: TestClientWithDependencies (0.74s)998=== CONT TestService_AuthMiddleware_MTLSBoundSubjects9992026/10/07 07:42:52 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=OWRkNzcyZjMtODVhNy00NzhlLWI0NTEtYTgwNjhkMmMzNGYwLmFlNTYzMDRkLWU1OGUtNDVlZi05ZDQwLWQ0NDIzZDk5NDY5YXgxNzkxMzU4OTcxODcyMjc3ODc5 parts=1210002026/10/07 07:42:52 INFO Received push request method=POST path=/api/pushes10012026/10/07 07:42:52 INFO Received uploads request method=POST path=/api/pending_closures10022026/10/07 07:42:52 INFO Completed push id=1 objects=4 duration=10.308791ms10032026/10/07 07:42:52 INFO Received push request method=POST path=/api/pushes10042026/10/07 07:42:52 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)1005--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.75s)10062026/10/07 07:42:52 INFO Uploading r6vkf1hjm5v0rgj69ax87l9jh5g26sa2-b (208B)1007=== CONT TestPushDedupSurvivesConcurrentGC10082026/10/07 07:42:52 INFO Uploading hqighk5xd2vq7sllqm4kn69qa7v77bak-shared-dep (136B)10092026/10/07 07:42:52 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10102026/10/07 07:42:52 INFO Received uploads request method=POST path=/api/pending_closures1011--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.75s)1012=== CONT TestService_AuthMiddleware_MTLSProxyHeader10132026/10/07 07:42:52 WARN Failed to register uploaded object key=nar/0pl7fbazz4ggb1wxv5lm8p2wjm15cnag0y4pwv3l90zwhg986jah.nar.zst error="server returned 404: 404 page not found\n"10142026/10/07 07:42:52 WARN Failed to register uploaded object key=r6vkf1hjm5v0rgj69ax87l9jh5g26sa2.ls error="server returned 404: 404 page not found\n"10152026/10/07 07:42:52 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10162026/10/07 07:42:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10172026/10/07 07:42:52 WARN Failed to register uploaded object key=g3ypjwy51halg9780596na1cm05zxb4m.ls error="server returned 404: 404 page not found\n"10182026/10/07 07:42:52 WARN Failed to register uploaded object key=hqighk5xd2vq7sllqm4kn69qa7v77bak.ls error="server returned 404: 404 page not found\n"10192026/10/07 07:42:52 INFO Signed narinfos id=1 count=310202026/10/07 07:42:52 INFO Uploading 3 narinfos10212026/10/07 07:42:52 WARN Failed to register uploaded object key=hqighk5xd2vq7sllqm4kn69qa7v77bak.narinfo error="server returned 404: 404 page not found\n"10222026/10/07 07:42:52 WARN Failed to register uploaded object key=r6vkf1hjm5v0rgj69ax87l9jh5g26sa2.narinfo error="server returned 404: 404 page not found\n"10232026/10/07 07:42:52 INFO Received complete push request method=POST path=/api/pushes/1/complete10242026/10/07 07:42:52 WARN Failed to register uploaded object key=g3ypjwy51halg9780596na1cm05zxb4m.narinfo error="server returned 404: 404 page not found\n"10252026/10/07 07:42:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37641/oidc10262026/10/07 07:42:52 INFO Completed push id=1 objects=8 duration=6.664798ms10272026/10/07 07:42:52 INFO Upload complete. (62ms)10282026/10/07 07:42:52 INFO Aborted multipart uploads count=0 kept=01029=== NAME TestClientPushesUseOnePush1030 client_pushes_test.go:97: Retrieved narinfo from S3:1031 StorePath: /build/TestClientPushesUseOnePush808256909/001/store/hqighk5xd2vq7sllqm4kn69qa7v77bak-shared-dep1032 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1033 Compression: zstd1034 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821035 NarSize: 1361036 References: 1037 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n10382026/10/07 07:42:52 INFO Received push request method=POST path=/api/pushes1039 client_pushes_test.go:97: Retrieved narinfo from S3:1040 StorePath: /build/TestClientPushesUseOnePush808256909/001/store/g3ypjwy51halg9780596na1cm05zxb4m-a1041 URL: nar/0pl7fbazz4ggb1wxv5lm8p2wjm15cnag0y4pwv3l90zwhg986jah.nar.zst1042 Compression: zstd1043 NarHash: sha256:0pl7fbazz4ggb1wxv5lm8p2wjm15cnag0y4pwv3l90zwhg986jah1044 NarSize: 2081045 References: /build/TestClientPushesUseOnePush808256909/001/store/hqighk5xd2vq7sllqm4kn69qa7v77bak-shared-dep1046 CA: text:sha256:1xw1lmf698nb7w3sapqcp2m87lp7sc43hgpg6g2ynrqmyh5r48ma1047 client_pushes_test.go:97: Retrieved narinfo from S3:1048 StorePath: /build/TestClientPushesUseOnePush808256909/001/store/r6vkf1hjm5v0rgj69ax87l9jh5g26sa2-b1049 URL: nar/0pl7fbazz4ggb1wxv5lm8p2wjm15cnag0y4pwv3l90zwhg986jah.nar.zst1050 Compression: zstd1051 NarHash: sha256:0pl7fbazz4ggb1wxv5lm8p2wjm15cnag0y4pwv3l90zwhg986jah1052 NarSize: 2081053 References: /build/TestClientPushesUseOnePush808256909/001/store/hqighk5xd2vq7sllqm4kn69qa7v77bak-shared-dep1054 CA: text:sha256:1xw1lmf698nb7w3sapqcp2m87lp7sc43hgpg6g2ynrqmyh5r48ma10552026/10/07 07:42:52 WARN Force mode enabled - objects will be deleted immediately without grace period10562026/10/07 07:42:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10572026/10/07 07:42:52 INFO Uploading b9ww68gxiqvqhq7vrvlmq9z661qakwy6-pinned-file.txt (128B)1058--- PASS: TestClientPushesUseOnePush (0.78s)1059=== CONT TestGCMetrics10602026/10/07 07:42:52 WARN Failed to register uploaded object key=b9ww68gxiqvqhq7vrvlmq9z661qakwy6.ls error="server returned 404: 404 page not found\n"10612026/10/07 07:42:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10622026/10/07 07:42:52 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"10632026/10/07 07:42:52 INFO Signed narinfos id=1 count=110642026/10/07 07:42:52 INFO Uploading 1 narinfos10652026/10/07 07:42:52 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."10662026/10/07 07:42:52 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."10672026/10/07 07:42:52 INFO Received complete push request method=POST path=/api/pushes/1/complete10682026/10/07 07:42:52 WARN Failed to register uploaded object key=b9ww68gxiqvqhq7vrvlmq9z661qakwy6.narinfo error="server returned 404: 404 page not found\n"1069--- PASS: TestFailedS3DeleteKeepsTombstone (0.79s)1070=== CONT TestLeadElectsOneAndHandsOver10712026/10/07 07:42:52 INFO Completed push id=1 objects=3 duration=6.296955ms10722026/10/07 07:42:52 INFO Upload complete. (60ms)1073=== NAME TestClientIntegration1074 client_integration_test.go:286: Created store path: /build/TestClientIntegration3465190198/002/store/dvf1m1x98j04y7crhbdl2r8bpmk57ir0-test-file.txt1075--- PASS: TestPushWaitsForSweepHoldingRow (0.81s)1076=== CONT TestLeadIncumbentAnnouncesAtOnce10772026/10/07 07:42:52 INFO Aborted multipart uploads count=0 kept=010782026/10/07 07:42:52 WARN Force mode enabled - objects will be deleted immediately without grace period10792026/10/07 07:42:52 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=01080=== NAME TestClientMultipleUploads1081 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads1604354126/001/store/lhzkxhm6zkid340g3bw3q0pi3ac7mcs6-test-file-0.txt10822026/10/07 07:42:52 INFO Vacuumed table table=pending_closures10832026/10/07 07:42:52 INFO Vacuumed table table=pending_objects10842026/10/07 07:42:52 INFO Vacuumed table table=multipart_uploads10852026/10/07 07:42:52 INFO Vacuumed table table=closures10862026/10/07 07:42:52 INFO Vacuumed table table=objects10872026/10/07 07:42:52 INFO Received complete push request method=POST path=/api/pushes/2/complete1088--- PASS: TestCacheStatsHandler (0.48s)1089=== CONT TestPresentRefreshesOnlyStaleClosures10902026/10/07 07:42:52 INFO Completed push id=2 objects=4 duration=4.58622ms1091--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.86s)1092=== CONT TestPush_CompleteCommitsEveryRoot10932026/10/07 07:42:52 INFO Received push request method=POST path=/api/pushes1094=== NAME TestClientMultipleUploads1095 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads1604354126/001/store/w5mqjsxzp69y1j1c4sh5f18pwl1x79p9-test-file-1.txt10962026/10/07 07:42:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10972026/10/07 07:42:52 INFO Uploading s60mgsfjajzrh72zvah50alw2bqid3rc-unpinned-file.txt (128B)10982026/10/07 07:42:52 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"10992026/10/07 07:42:52 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11002026/10/07 07:42:52 WARN Failed to register uploaded object key=s60mgsfjajzrh72zvah50alw2bqid3rc.ls error="server returned 404: 404 page not found\n"11012026/10/07 07:42:52 INFO Signed narinfos id=2 count=111022026/10/07 07:42:52 INFO Uploading 1 narinfos11032026/10/07 07:42:52 INFO Received complete push request method=POST path=/api/pushes/2/complete11042026/10/07 07:42:52 WARN Failed to register uploaded object key=s60mgsfjajzrh72zvah50alw2bqid3rc.narinfo error="server returned 404: 404 page not found\n"11052026/10/07 07:42:52 INFO Received push request method=POST path=/api/pushes11062026/10/07 07:42:52 INFO Completed push id=2 objects=3 duration=3.762413ms11072026/10/07 07:42:52 INFO Upload complete. (56ms)11082026/10/07 07:42:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11092026/10/07 07:42:52 INFO Uploading dvf1m1x98j04y7crhbdl2r8bpmk57ir0-test-file.txt (152B)11102026/10/07 07:42:52 INFO Received uploads request method=POST path=/api/pending_closures11112026/10/07 07:42:52 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"11122026/10/07 07:42:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11132026/10/07 07:42:52 WARN Failed to register uploaded object key=dvf1m1x98j04y7crhbdl2r8bpmk57ir0.ls error="server returned 404: 404 page not found\n"11142026/10/07 07:42:52 INFO Signed narinfos id=1 count=111152026/10/07 07:42:52 INFO Uploading 1 narinfos1116 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads1604354126/001/store/2n8ljnyvf34b9mcnynpn0rvz8svmz2p2-test-file-2.txt1117=== NAME TestClientCADerivations1118 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3076648269/001/store/4kfmji8p40jkxhsq9wirzfnln4kgjajk-ca-test11192026/10/07 07:42:52 INFO Received complete push request method=POST path=/api/pushes/1/complete11202026/10/07 07:42:52 WARN Failed to register uploaded object key=dvf1m1x98j04y7crhbdl2r8bpmk57ir0.narinfo error="server returned 404: 404 page not found\n"11212026/10/07 07:42:52 INFO Completed push id=1 objects=3 duration=13.103535ms11222026/10/07 07:42:52 INFO Upload complete. (77ms)11232026/10/07 07:42:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures11242026/10/07 07:42:52 INFO Garbage collection started1125--- PASS: TestService_ReadScope_PublicByDefault (0.47s)1126=== CONT TestConnectWaitsForAPeerMigration1127=== NAME TestClientCADerivations1128 client_ca_test.go:139: Found 1 dependencies (including self)11292026/10/07 07:42:52 INFO Aborted multipart uploads count=0 kept=011302026/10/07 07:42:52 WARN Force mode enabled - objects will be deleted immediately without grace period11312026/10/07 07:42:52 INFO All 1 paths already cached1132=== NAME TestClientIntegration1133 client_integration_test.go:312: Retrieved narinfo from S3:1134 StorePath: /build/TestClientIntegration3465190198/002/store/dvf1m1x98j04y7crhbdl2r8bpmk57ir0-test-file.txt1135 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1136 Compression: zstd1137 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11138 NarSize: 1521139 References: 1140 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk111412026/10/07 07:42:52 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=01142 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1143 client_integration_test.go:313: Decompressed .ls content (64 bytes):1144 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1145 client_integration_test.go:316: Testing garbage collection...11462026/10/07 07:42:52 INFO Vacuumed table table=pending_closures11472026/10/07 07:42:52 INFO Vacuumed table table=pending_objects11482026/10/07 07:42:52 INFO Vacuumed table table=multipart_uploads11492026/10/07 07:42:52 INFO Vacuumed table table=closures11502026/10/07 07:42:52 INFO Vacuumed table table=objects11512026/10/07 07:42:52 INFO Received push request method=POST path=/api/pushes11522026/10/07 07:42:52 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)11532026/10/07 07:42:52 INFO Uploading lhzkxhm6zkid340g3bw3q0pi3ac7mcs6-test-file-0.txt (160B)11542026/10/07 07:42:52 INFO Uploading 2n8ljnyvf34b9mcnynpn0rvz8svmz2p2-test-file-2.txt (160B)11552026/10/07 07:42:52 INFO Uploading w5mqjsxzp69y1j1c4sh5f18pwl1x79p9-test-file-1.txt (160B)11562026/10/07 07:42:52 INFO Received uploads request method=POST path=/api/pending_closures11572026/10/07 07:42:52 INFO Aborted multipart uploads count=0 kept=011582026-10-07 07:42:52.500 UTC [834] ERROR: Push does not exist: id=111592026-10-07 07:42:52.500 UTC [834] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE11602026-10-07 07:42:52.500 UTC [834] STATEMENT: SELECT commit_push($1)1161--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.98s)1162=== CONT TestPush_OverlappingRootsStoreOneRowPerKey11632026/10/07 07:42:52 WARN Failed to register uploaded object key=w5mqjsxzp69y1j1c4sh5f18pwl1x79p9.ls error="server returned 404: 404 page not found\n"11642026/10/07 07:42:52 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"11652026/10/07 07:42:52 WARN Failed to register uploaded object key=2n8ljnyvf34b9mcnynpn0rvz8svmz2p2.ls error="server returned 404: 404 page not found\n"11662026/10/07 07:42:52 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"11672026/10/07 07:42:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11682026/10/07 07:42:52 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"11692026/10/07 07:42:52 WARN Failed to register uploaded object key=lhzkxhm6zkid340g3bw3q0pi3ac7mcs6.ls error="server returned 404: 404 page not found\n"11702026/10/07 07:42:52 INFO Signed narinfos id=1 count=311712026/10/07 07:42:52 INFO Uploading 3 narinfos1172--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.36s)1173=== CONT TestGCAdvisoryLockBlocksConcurrentRun11742026/10/07 07:42:52 WARN Force mode enabled - objects will be deleted immediately without grace period11752026/10/07 07:42:52 INFO Received complete push request method=POST path=/api/pushes/1/complete11762026/10/07 07:42:52 WARN Failed to register uploaded object key=2n8ljnyvf34b9mcnynpn0rvz8svmz2p2.narinfo error="server returned 404: 404 page not found\n"11772026/10/07 07:42:52 WARN Failed to register uploaded object key=lhzkxhm6zkid340g3bw3q0pi3ac7mcs6.narinfo error="server returned 404: 404 page not found\n"11782026/10/07 07:42:52 WARN Failed to register uploaded object key=w5mqjsxzp69y1j1c4sh5f18pwl1x79p9.narinfo error="server returned 404: 404 page not found\n"11792026/10/07 07:42:52 INFO Completed push id=1 objects=9 duration=5.597909ms11802026/10/07 07:42:52 INFO Upload complete. (62ms)1181=== NAME TestClientMultipleUploads1182 client_integration_test.go:369: Uploaded 3 paths in 94.104902ms11832026/10/07 07:42:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures11842026/10/07 07:42:52 INFO Garbage collection started11852026/10/07 07:42:52 INFO Received uploads request method=POST path=/api/pending_closures11862026/10/07 07:42:52 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=011872026/10/07 07:42:52 INFO Vacuumed table table=pending_closures11882026/10/07 07:42:52 INFO Vacuumed table table=pending_objects11892026/10/07 07:42:52 INFO Vacuumed table table=multipart_uploads1190--- PASS: TestClientMultipleUploads (0.69s)11912026/10/07 07:42:52 INFO Vacuumed table table=closures1192=== CONT TestGCBugBareHashReferences11932026/10/07 07:42:52 INFO Aborted multipart uploads count=0 kept=011942026/10/07 07:42:52 INFO Vacuumed table table=objects1195--- PASS: TestGCSweepDeliversEachKeyOnce (0.51s)1196=== CONT TestLeadEndsOnShutdown11972026/10/07 07:42:52 WARN Force mode enabled - objects will be deleted immediately without grace period11982026/10/07 07:42:52 INFO Aborted multipart uploads count=0 kept=011992026/10/07 07:42:52 WARN Force mode enabled - objects will be deleted immediately without grace period12002026/10/07 07:42:52 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=012012026/10/07 07:42: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=012022026/10/07 07:42:52 INFO Vacuumed table table=pending_closures12032026/10/07 07:42:52 INFO Vacuumed table table=pending_closures12042026/10/07 07:42:52 INFO Vacuumed table table=pending_objects12052026/10/07 07:42:52 INFO Vacuumed table table=multipart_uploads12062026/10/07 07:42:52 INFO Vacuumed table table=closures12072026/10/07 07:42:52 INFO Vacuumed table table=pending_objects12082026/10/07 07:42:52 INFO Vacuumed table table=multipart_uploads12092026/10/07 07:42:52 INFO Vacuumed table table=objects12102026/10/07 07:42:52 INFO Received push request method=POST path=/api/pushes12112026/10/07 07:42:52 INFO Vacuumed table table=closures1212=== RUN TestService_RequireScope_OIDC/builder_may_write1213=== PAUSE TestService_RequireScope_OIDC/builder_may_write1214=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1215=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1216=== RUN TestService_RequireScope_OIDC/ops_may_admin1217=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1218=== RUN TestService_RequireScope_OIDC/ops_may_not_write1219=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1220=== RUN TestService_RequireScope_OIDC/reader_may_not_write1221=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1222=== RUN TestService_RequireScope_OIDC/static_token_may_admin1223=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1224=== RUN TestService_RequireScope_OIDC/static_token_may_write1225=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1226=== RUN TestService_RequireScope_OIDC/reader_may_read1227=== PAUSE TestService_RequireScope_OIDC/reader_may_read1228=== RUN TestService_RequireScope_OIDC/writer_implies_read1229=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1230=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1231=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1232=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1233=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1234=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1235=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1236=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1237=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1238=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1239=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1240=== CONT TestResolveDBConnectionString1241=== RUN TestResolveDBConnectionString/flag_wins1242=== PAUSE TestResolveDBConnectionString/flag_wins1243=== RUN TestResolveDBConnectionString/file_when_flag_empty1244=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1245=== RUN TestResolveDBConnectionString/missing_file_is_an_error1246=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1247=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1248=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1249=== RUN TestResolveDBConnectionString/nothing_configured1250=== PAUSE TestResolveDBConnectionString/nothing_configured1251=== CONT TestReadRedirectUsesPublicS3URL1252--- PASS: TestService_ReadAuthMiddleware (0.37s)1253=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock12542026/10/07 07:42:52 INFO Vacuumed table table=objects12552026/10/07 07:42:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1256--- PASS: TestGCSweepSkipsPendingObjects (0.38s)12572026/10/07 07:42:52 INFO Uploading 4kfmji8p40jkxhsq9wirzfnln4kgjajk-ca-test (144B)1258=== CONT TestReadProxyInvalidPath12592026/10/07 07:42:52 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"12602026/10/07 07:42:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12612026/10/07 07:42:52 WARN Failed to register uploaded object key=log/2vgbgk93f5qglz8apqlf0f4008x8k9f2-ca-test.drv error="server returned 404: 404 page not found\n"12622026/10/07 07:42:52 WARN Failed to register uploaded object key=4kfmji8p40jkxhsq9wirzfnln4kgjajk.ls error="server returned 404: 404 page not found\n"12632026/10/07 07:42:52 INFO Signed narinfos id=1 count=112642026/10/07 07:42:52 INFO Uploading 1 narinfos12652026/10/07 07:42:52 INFO Received complete push request method=POST path=/api/pushes/1/complete12662026/10/07 07:42:52 WARN Failed to register uploaded object key=4kfmji8p40jkxhsq9wirzfnln4kgjajk.narinfo error="server returned 404: 404 page not found\n"12672026/10/07 07:42:52 INFO Received uploads request method=POST path=/api/pending_closures12682026/10/07 07:42:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12692026/10/07 07:42:52 INFO Completed push id=1 objects=4 duration=6.951241ms12702026/10/07 07:42:52 INFO Upload complete. (107ms)1271=== NAME TestClientCADerivations1272 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3076648269/001/store/4kfmji8p40jkxhsq9wirzfnln4kgjajk-ca-test1273 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1274 Compression: zstd1275 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1276 NarSize: 1441277 References: 1278 Deriver: /build/TestClientCADerivations3076648269/001/store/2vgbgk93f5qglz8apqlf0f4008x8k9f2-ca-test.drv1279 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1280 client_ca_test.go:185: Checking for realisation files in S3...1281 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1282 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1283--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.37s)1284=== CONT TestReadProxy40412852026/10/07 07:42:52 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OWRkNzcyZjMtODVhNy00NzhlLWI0NTEtYTgwNjhkMmMzNGYwLjM0OGEzNzQ1LWJhYjEtNGVjNC1iNjgyLTdjMDg1OTFkYzA3NXgxNzkxMzU4OTcyMTkwOTU4ODYz error="Get \"http://127.0.0.1:1/bucket4/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"12862026/10/07 07:42:52 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OWRkNzcyZjMtODVhNy00NzhlLWI0NTEtYTgwNjhkMmMzNGYwLjA2MDVhNjg2LWZiMGYtNDZjNC04MmEwLTNmZmY2NWVkN2RmNHgxNzkxMzU4OTcyMTg0Njk2NjI5 parts=1212872026/10/07 07:42:52 INFO Received cleanup request method=DELETE path=/api/pending_closures12882026/10/07 07:42:52 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"12892026/10/07 07:42:52 WARN mTLS auth: bound subjects configured but subject DN unavailable12902026/10/07 07:42:52 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1291--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.35s)1292=== CONT TestUploadHandlersRejectOversizedBody12932026/10/07 07:42:52 INFO Aborted multipart uploads count=1 kept=01294--- PASS: TestRedundantMultipartUpload (1.10s)1295=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT1296--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.67s)1297=== CONT TestReadProxyRangeRequest1298--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.36s)1299=== CONT TestCompleteMultipartUnregistered1300=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1301=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1302=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1303=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1304=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1305=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1306=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1307=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1308=== CONT TestReadProxyNarStreaming13092026/10/07 07:42:52 INFO Received uploads request method=POST path=/api/pending_closures1310=== NAME TestClientCADerivations1311 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1312 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1313 error: binary cache 's3://bucket30?endpoint=http://localhost:43437&region=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3076648269/001/store'1314 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11315--- PASS: TestClientCADerivations (0.81s)1316=== CONT TestService_verifyS3Integrity13172026/10/07 07:42:52 INFO Aborted multipart uploads count=0 kept=013182026/10/07 07:42:52 WARN Force mode enabled - objects will be deleted immediately without grace period13192026/10/07 07:42: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=013202026/10/07 07:42:52 INFO Vacuumed table table=pending_closures13212026/10/07 07:42:52 INFO Vacuumed table table=pending_objects13222026/10/07 07:42:52 INFO Vacuumed table table=multipart_uploads13232026/10/07 07:42:52 INFO Vacuumed table table=closures13242026/10/07 07:42:52 INFO Vacuumed table table=objects13252026/10/07 07:42:52 INFO lead: acquired remote=192.0.2.1:12341326--- PASS: TestGCMetrics (0.43s)1327=== CONT TestReadRedirectKeepsNarinfoProxied13282026/10/07 07:42:52 INFO lead: acquired remote=192.0.2.1:123413292026/10/07 07:42:52 INFO lead: released remote=192.0.2.1:12341330--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.42s)1331=== CONT TestService_createPendingClosureHandler13322026/10/07 07:42:52 INFO Aborted multipart uploads count=0 kept=01333=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1334=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1335=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1336=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1337=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1338=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1339=== CONT TestReadProxyContentNegotiation13402026/10/07 07:42:52 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013412026/10/07 07:42:52 INFO Vacuumed table table=pending_closures13422026/10/07 07:42:52 INFO Vacuumed table table=pending_objects13432026/10/07 07:42:52 INFO Vacuumed table table=multipart_uploads13442026/10/07 07:42:52 INFO Vacuumed table table=closures13452026/10/07 07:42:52 INFO Vacuumed table table=objects1346--- PASS: TestPresentRefreshesOnlyStaleClosures (0.40s)1347=== CONT TestReadRedirectNar13482026/10/07 07:42:52 INFO Aborted multipart uploads count=0 kept=013492026/10/07 07:42:52 WARN Force mode enabled - objects will be deleted immediately without grace period13502026/10/07 07:42: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=013512026/10/07 07:42:52 INFO Vacuumed table table=pending_closures13522026/10/07 07:42:52 INFO Vacuumed table table=pending_objects13532026/10/07 07:42:52 INFO Received push request method=POST path=/api/pushes13542026/10/07 07:42:52 INFO Vacuumed table table=multipart_uploads13552026/10/07 07:42:52 INFO Vacuumed table table=closures13562026/10/07 07:42:52 INFO Vacuumed table table=objects1357--- PASS: TestPushDedupSurvivesConcurrentGC (0.53s)1358=== CONT TestService_cleanupPendingClosuresHandler13592026/10/07 07:42:52 INFO Received push request method=POST path=/api/pushes13602026/10/07 07:42:52 INFO Received complete push request method=POST path=/api/pushes/1/complete1361--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.32s)1362=== CONT TestReadProxyNarinfoAlreadyDecompressed13632026/10/07 07:42:52 INFO Completed push id=1 objects=6 duration=10.222969ms1364--- PASS: TestPush_CompleteCommitsEveryRoot (0.45s)1365=== CONT TestReadProxyDisabled13662026/10/07 07:42:52 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=nixbld database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1367--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.33s)1368=== CONT TestReadProxyOutlastsServerWriteTimeout13692026/10/07 07:42:52 INFO lead: acquired remote=192.0.2.1:12341370--- PASS: TestReadRedirectUsesPublicS3URL (0.34s)1371=== CONT TestReadProxyNarinfo1372--- PASS: TestReadProxyInvalidPath (0.34s)1373=== CONT TestReadProxyConditionalGet13742026/10/07 07:42:52 INFO Received uploads request method=POST path=/api/pending_closures1375--- PASS: TestReadProxy404 (0.38s)1376=== CONT TestIsValidCachePath1377=== RUN TestIsValidCachePath/narinfo1378=== PAUSE TestIsValidCachePath/narinfo1379=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1380=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1381=== RUN TestIsValidCachePath/nar_zst1382=== PAUSE TestIsValidCachePath/nar_zst1383=== RUN TestIsValidCachePath/nar_xz1384=== PAUSE TestIsValidCachePath/nar_xz1385=== RUN TestIsValidCachePath/nar_bz21386=== PAUSE TestIsValidCachePath/nar_bz21387=== RUN TestIsValidCachePath/nar_uncompressed1388=== PAUSE TestIsValidCachePath/nar_uncompressed1389=== RUN TestIsValidCachePath/ls1390=== PAUSE TestIsValidCachePath/ls1391=== RUN TestIsValidCachePath/log1392=== PAUSE TestIsValidCachePath/log1393=== RUN TestIsValidCachePath/realisation1394=== PAUSE TestIsValidCachePath/realisation1395=== RUN TestIsValidCachePath/nix-cache-info1396=== PAUSE TestIsValidCachePath/nix-cache-info1397=== RUN TestIsValidCachePath/index.html1398=== PAUSE TestIsValidCachePath/index.html1399=== RUN TestIsValidCachePath/traversal_parent1400=== PAUSE TestIsValidCachePath/traversal_parent1401=== RUN TestIsValidCachePath/traversal_in_middle1402=== PAUSE TestIsValidCachePath/traversal_in_middle1403=== RUN TestIsValidCachePath/invalid_char_e1404=== PAUSE TestIsValidCachePath/invalid_char_e1405=== RUN TestIsValidCachePath/invalid_char_u1406=== PAUSE TestIsValidCachePath/invalid_char_u1407=== RUN TestIsValidCachePath/random_path1408=== PAUSE TestIsValidCachePath/random_path1409=== RUN TestIsValidCachePath/empty1410=== PAUSE TestIsValidCachePath/empty1411=== RUN TestIsValidCachePath/leading_slash1412=== PAUSE TestIsValidCachePath/leading_slash1413=== RUN TestIsValidCachePath/wrong_extension1414=== PAUSE TestIsValidCachePath/wrong_extension1415=== RUN TestIsValidCachePath/short_hash1416=== PAUSE TestIsValidCachePath/short_hash1417=== CONT TestReadProxyRootRedirectsToIndexHTML1418--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.37s)1419=== CONT TestParseSingleRange1420=== RUN TestParseSingleRange/none1421=== PAUSE TestParseSingleRange/none1422=== RUN TestParseSingleRange/unknown_unit1423=== PAUSE TestParseSingleRange/unknown_unit1424=== RUN TestParseSingleRange/multi-range_ignored1425=== PAUSE TestParseSingleRange/multi-range_ignored1426=== RUN TestParseSingleRange/malformed_no_dash1427=== PAUSE TestParseSingleRange/malformed_no_dash1428=== RUN TestParseSingleRange/malformed_both_empty1429=== PAUSE TestParseSingleRange/malformed_both_empty1430=== RUN TestParseSingleRange/malformed_end_before_start1431=== PAUSE TestParseSingleRange/malformed_end_before_start1432=== RUN TestParseSingleRange/closed1433=== PAUSE TestParseSingleRange/closed1434=== RUN TestParseSingleRange/open-ended1435=== PAUSE TestParseSingleRange/open-ended1436=== RUN TestParseSingleRange/end_clamped_to_size1437=== PAUSE TestParseSingleRange/end_clamped_to_size1438=== RUN TestParseSingleRange/suffix1439=== PAUSE TestParseSingleRange/suffix1440=== RUN TestParseSingleRange/suffix_exceeds_size1441=== PAUSE TestParseSingleRange/suffix_exceeds_size1442=== RUN TestParseSingleRange/single_byte1443=== PAUSE TestParseSingleRange/single_byte1444=== RUN TestParseSingleRange/start_past_EOF1445=== PAUSE TestParseSingleRange/start_past_EOF1446=== RUN TestParseSingleRange/start_far_past_EOF1447=== PAUSE TestParseSingleRange/start_far_past_EOF1448=== CONT TestService_NativeMTLS14492026/10/07 07:42:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14502026/10/07 07:42:52 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1451--- PASS: TestCompleteMultipartUnregistered (0.37s)1452=== CONT TestPresentNotReportedWhileGCDeletesClosure1453=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1454=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1455=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1456=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1457=== CONT TestReadProxyHead1458--- PASS: TestReadProxyRangeRequest (0.40s)1459=== CONT TestObjectStatsTrigger1460--- PASS: TestReadProxyNarStreaming (0.37s)1461=== CONT TestObjectStatsLargeCommit14622026/10/07 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures1463--- PASS: TestReadRedirectKeepsNarinfoProxied (0.36s)1464=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1465--- PASS: TestGCBugBareHashReferences (0.56s)1466=== CONT TestMultipartCleanup14672026/10/07 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures14682026/10/07 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures14692026/10/07 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures1470--- PASS: TestReadRedirectNar (0.40s)1471=== CONT TestCreatePin_ReservedPins1472--- PASS: TestReadProxyHead (0.19s)1473=== CONT TestOrphanedObjectsGCStressTest1474--- PASS: TestReadProxyContentNegotiation (0.44s)1475=== CONT TestPendingCleanupUsesOneCutoff14762026/10/07 07:42:53 INFO Received cleanup request method=DELETE path=/api/pending_closures14772026/10/07 07:42:53 INFO Aborted multipart uploads count=0 kept=014782026/10/07 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures1479--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.66s)1480=== CONT TestServerTLSConfig1481=== RUN TestServerTLSConfig/no_client_CA1482=== PAUSE TestServerTLSConfig/no_client_CA1483=== RUN TestServerTLSConfig/missing_CA_file1484=== PAUSE TestServerTLSConfig/missing_CA_file1485=== RUN TestServerTLSConfig/not_a_PEM_file1486=== PAUSE TestServerTLSConfig/not_a_PEM_file1487=== CONT TestOrphanedObjectsGC14882026/10/07 07:42:53 INFO Received cleanup request method=DELETE path=/api/pending_closures14892026/10/07 07:42:53 INFO Aborted multipart uploads count=1 kept=014902026/10/07 07:42:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14912026-10-07 07:42:53.230 UTC [1530] ERROR: Closure does not exist: id=114922026-10-07 07:42:53.230 UTC [1530] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE14932026-10-07 07:42:53.230 UTC [1530] STATEMENT: -- name: CommitPendingClosure :one1494 SELECT commit_pending_closure($1::bigint)::bigint1495 1496--- PASS: TestService_cleanupPendingClosuresHandler (0.44s)1497=== CONT TestPresentReportsOnlyClosureRoots1498--- PASS: TestReadProxyDisabled (0.41s)1499=== CONT TestService_healthCheckHandler1500--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.44s)1501=== CONT TestGenerateLandingPage1502--- PASS: TestGenerateLandingPage (0.00s)1503=== CONT TestMetricsInventory1504--- PASS: TestReadProxyConditionalGet (0.43s)1505=== CONT TestService_readinessHandler1506--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.37s)1507=== CONT TestMetricsCommit15082026/10/07 07:42:53 WARN mTLS auth: subject not in bound subjects subject="CN=reader"15092026/10/07 07:42:53 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1510--- PASS: TestService_NativeMTLS (0.37s)1511=== CONT TestNARDeduplicationMetadataUploadBug15122026/10/07 07:42:53 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>15132026/10/07 07:42:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1514--- PASS: TestReadProxyNarinfo (0.49s)1515=== CONT TestGracefulShutdownDrainsInflight15162026/10/07 07:42:53 INFO Starting HTTP server address=127.0.0.1:3690515172026/10/07 07:42:53 INFO Shutdown signal received, draining in-flight requests timeout=10s1518--- PASS: TestObjectStatsTrigger (0.37s)1519=== CONT TestPendingClosureWriteTimeout1520=== RUN TestPendingClosureWriteTimeout/empty1521=== PAUSE TestPendingClosureWriteTimeout/empty1522=== RUN TestPendingClosureWriteTimeout/400_objects1523=== PAUSE TestPendingClosureWriteTimeout/400_objects1524=== RUN TestPendingClosureWriteTimeout/670k_objects1525=== PAUSE TestPendingClosureWriteTimeout/670k_objects1526=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1527=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1528=== CONT TestCreatePendingClosureRejectsOversizedNAR15292026/10/07 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures1530--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1531=== CONT TestCacheConfigHandlerMaxNarSize1532--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1533=== CONT TestIsValidUploadKey1534=== RUN TestIsValidUploadKey/narinfo1535=== PAUSE TestIsValidUploadKey/narinfo1536=== RUN TestIsValidUploadKey/nar_zst1537=== PAUSE TestIsValidUploadKey/nar_zst1538=== RUN TestIsValidUploadKey/nar_xz1539=== PAUSE TestIsValidUploadKey/nar_xz1540=== RUN TestIsValidUploadKey/nar_plain1541=== PAUSE TestIsValidUploadKey/nar_plain1542=== RUN TestIsValidUploadKey/listing1543=== PAUSE TestIsValidUploadKey/listing1544=== RUN TestIsValidUploadKey/build_log1545=== PAUSE TestIsValidUploadKey/build_log1546=== RUN TestIsValidUploadKey/build_log_home-manager_file1547=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1548=== RUN TestIsValidUploadKey/build_log_plus_in_name1549=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1550=== RUN TestIsValidUploadKey/build_log_question_mark1551=== PAUSE TestIsValidUploadKey/build_log_question_mark1552=== RUN TestIsValidUploadKey/build_log_equals1553=== PAUSE TestIsValidUploadKey/build_log_equals1554=== RUN TestIsValidUploadKey/realisation1555=== PAUSE TestIsValidUploadKey/realisation1556=== RUN TestIsValidUploadKey/realisation_plus_in_output1557=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1558=== RUN TestIsValidUploadKey/nix-cache-info1559=== PAUSE TestIsValidUploadKey/nix-cache-info1560=== RUN TestIsValidUploadKey/index.html1561=== PAUSE TestIsValidUploadKey/index.html1562=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1563=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1564=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1565=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1566=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1567=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1568=== RUN TestIsValidUploadKey/traversal1569=== PAUSE TestIsValidUploadKey/traversal1570=== RUN TestIsValidUploadKey/traversal_nar1571=== PAUSE TestIsValidUploadKey/traversal_nar1572=== RUN TestIsValidUploadKey/absolute1573=== PAUSE TestIsValidUploadKey/absolute1574=== RUN TestIsValidUploadKey/empty_key1575=== PAUSE TestIsValidUploadKey/empty_key1576=== RUN TestIsValidUploadKey/unknown_type1577=== PAUSE TestIsValidUploadKey/unknown_type1578=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle15792026/10/07 07:42:53 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=OWRkNzcyZjMtODVhNy00NzhlLWI0NTEtYTgwNjhkMmMzNGYwLmY5YjFiZjg5LWQwNDQtNDZhMS1iOTYzLTExYzYyYmU3NzE1OXgxNzkxMzU4OTczMDYzNjQyMTg5 parts=1015802026/10/07 07:42:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15812026/10/07 07:42:53 INFO Completed upload id=1 objects=2 duration=3.241888ms15822026/10/07 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures15832026/10/07 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures15842026/10/07 07:42:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15852026/10/07 07:42:53 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo15862026/10/07 07:42:53 WARN Found objects in DB but missing from S3, will re-upload count=11587--- PASS: TestService_verifyS3Integrity (0.73s)1588=== CONT TestUploadHandlersRejectInvalidKeys1589=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1590=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1591=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1592=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1593=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1594=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1595=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1596=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1597=== CONT TestProxyWriteTimeout1598=== RUN TestProxyWriteTimeout/narinfo1599=== PAUSE TestProxyWriteTimeout/narinfo1600=== RUN TestProxyWriteTimeout/1_GiB_nar1601=== PAUSE TestProxyWriteTimeout/1_GiB_nar1602=== RUN TestProxyWriteTimeout/10_GiB_nar1603=== PAUSE TestProxyWriteTimeout/10_GiB_nar1604=== RUN TestProxyWriteTimeout/unknown_size1605=== PAUSE TestProxyWriteTimeout/unknown_size1606=== CONT TestGCTaskStore_Fail1607--- PASS: TestGCTaskStore_Fail (0.00s)1608=== CONT TestGCEndsOnShutdown/before_the_run16092026/10/07 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures16102026/10/07 07:42:53 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=OWRkNzcyZjMtODVhNy00NzhlLWI0NTEtYTgwNjhkMmMzNGYwLjA5ODcwZTk3LTY5MTItNDRhYS1hMmJlLTM1MmE3NGYyYzRkZHgxNzkxMzU4OTczMTA0NDkyNDI2 parts=1016112026/10/07 07:42:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16122026/10/07 07:42:53 INFO Completed upload id=1 objects=2 duration=3.370749ms16132026/10/07 07:42:53 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000016142026/10/07 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures16152026/10/07 07:42:53 INFO Starting cleanup of old closures method=DELETE path=/api/closures1616--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.37s)1617=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark16182026/10/07 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures16192026/10/07 07:42:53 INFO Aborted multipart uploads count=0 kept=01620--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1621=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete16222026/10/07 07:42:53 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=016232026/10/07 07:42:53 INFO Vacuumed table table=pending_closures16242026/10/07 07:42:53 INFO Vacuumed table table=pending_objects16252026/10/07 07:42:53 INFO Vacuumed table table=multipart_uploads16262026/10/07 07:42:53 INFO Vacuumed table table=closures16272026/10/07 07:42:53 INFO Vacuumed table table=objects16282026/10/07 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures16292026/10/07 07:42:53 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000016302026/10/07 07:42:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33313/oidc1631--- PASS: TestService_createPendingClosureHandler (0.76s)1632=== CONT TestClientErrorHandling/InvalidStorePath16332026/10/07 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures16342026/10/07 07:42:53 INFO Received cleanup request method=DELETE path=/api/pending_closures1635--- PASS: TestService_healthCheckHandler (0.31s)1636=== CONT TestClientErrorHandling/InvalidAuthToken16372026/10/07 07:42:53 INFO Received cleanup request method=DELETE path=/api/pending_closures16382026/10/07 07:42:53 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket79/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""16392026/10/07 07:42:53 INFO Aborted multipart uploads count=0 kept=11640--- PASS: TestPresentReportsOnlyClosureRoots (0.34s)1641=== CONT TestClientErrorHandling/ServerNotAvailable16422026/10/07 07:42:53 INFO Received cleanup request method=DELETE path=/api/pending_closures16432026/10/07 07:42:53 INFO Aborted multipart uploads count=1 kept=01644--- PASS: TestMultipartCleanup (0.49s)1645=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1646--- PASS: TestMetricsInventory (0.34s)1647=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check16482026/10/07 07:42:53 WARN readiness check failed error="closed pool"1649--- PASS: TestService_readinessHandler (0.26s)1650=== CONT TestCacheConfigHandler/full_config,_no_issuer1651=== CONT TestCacheConfigHandler/no_signing_keys1652=== CONT TestCacheConfigHandler/no_cache_url_configured1653=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1654--- PASS: TestCacheConfigHandler (0.00s)1655 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1656 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1657 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1658 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1659=== CONT TestPush_RejectsBadRequests/root_not_in_objects16602026/10/07 07:42:53 INFO Received push request method=POST path=/api/pushes1661=== CONT TestPush_RejectsBadRequests/no_objects16622026/10/07 07:42:53 INFO Received push request method=POST path=/api/pushes1663=== CONT TestPush_RejectsBadRequests/no_roots16642026/10/07 07:42:53 INFO Received push request method=POST path=/api/pushes1665=== CONT TestPush_RejectsBadRequests/bad_root16662026/10/07 07:42:53 INFO Received push request method=POST path=/api/pushes1667=== CONT TestService_RequireScope_OIDC/builder_may_write1668--- PASS: TestPush_RejectsBadRequests (0.49s)1669 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1670 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1671 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1672 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1673=== CONT TestService_RequireScope_OIDC/reader_may_read1674=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1675=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1676=== CONT TestService_RequireScope_OIDC/writer_implies_read1677=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read16782026/10/07 07:42:53 WARN Authentication failed token_preview=wrong token_length=5 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1679=== CONT TestService_RequireScope_OIDC/reader_may_not_write1680=== CONT TestService_RequireScope_OIDC/static_token_may_write1681=== CONT TestService_RequireScope_OIDC/static_token_may_admin1682=== CONT TestService_RequireScope_OIDC/ops_may_admin1683=== CONT TestService_RequireScope_OIDC/ops_may_not_write1684=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1685=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1686=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1687=== CONT TestResolveDBConnectionString/flag_wins1688=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1689=== CONT TestResolveDBConnectionString/nothing_configured1690=== CONT TestResolveDBConnectionString/missing_file_is_an_error1691=== CONT TestResolveDBConnectionString/file_when_flag_empty1692=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1693--- PASS: TestService_RequireScope_OIDC (0.51s)1694 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1695 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1696 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1697 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1698 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1699 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1700 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1701 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1702 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1703 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1704 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1705 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1706 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1707 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1708--- PASS: TestResolveDBConnectionString (0.00s)1709 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1710 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1711 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1712 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1713 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1714=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected17152026/10/07 07:42:53 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1716=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1717=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected17182026/10/07 07:42:53 WARN Authentication failed token_preview=eyJhbGciOi...DizFV8DX5Q token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1719=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17202026/10/07 07:42:53 INFO Received uploads request method=POST path=/1721--- PASS: TestService_AuthMiddleware_OIDC (0.51s)1722 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1723 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1724 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1725 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)17262026/10/07 07:42:53 INFO Received push request method=POST path=/api/pushes17272026/10/07 07:42:53 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17282026/10/07 07:42:53 INFO Received complete push request method=POST path=/api/pushes/1/complete17292026/10/07 07:42:53 INFO Completed push id=1 objects=4 duration=7.720988ms17302026/10/07 07:42:53 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17312026/10/07 07:42:53 INFO Completed upload id=2 objects=2 duration=1.095509ms1732--- PASS: TestMetricsCommit (0.31s)1733=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17342026/10/07 07:42:53 INFO Received request for more parts method=POST path=/17352026/10/07 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures1736=== NAME TestNARDeduplicationMetadataUploadBug1737 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2454265856/001/store/b0yxfk7a2p197973cs4z51yxgwks30z5-file1.txt1738=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17392026/10/07 07:42:53 INFO Received complete multipart upload request method=POST path=/1740--- PASS: TestDeleteClosuresRacingPins (1.78s)1741=== CONT TestIsValidCachePath/narinfo1742=== CONT TestIsValidCachePath/index.html1743=== CONT TestIsValidCachePath/short_hash1744=== CONT TestIsValidCachePath/wrong_extension1745=== CONT TestIsValidCachePath/leading_slash1746=== CONT TestIsValidCachePath/empty1747=== CONT TestIsValidCachePath/random_path1748=== CONT TestIsValidCachePath/invalid_char_u1749=== CONT TestIsValidCachePath/invalid_char_e1750=== CONT TestIsValidCachePath/traversal_in_middle1751=== CONT TestIsValidCachePath/traversal_parent1752=== CONT TestIsValidCachePath/nar_uncompressed1753=== CONT TestIsValidCachePath/nix-cache-info1754=== CONT TestIsValidCachePath/realisation1755=== CONT TestIsValidCachePath/log1756=== CONT TestIsValidCachePath/ls1757=== CONT TestIsValidCachePath/nar_xz1758=== CONT TestIsValidCachePath/nar_bz21759=== CONT TestIsValidCachePath/nar_zst1760=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1761=== CONT TestParseSingleRange/none1762=== CONT TestParseSingleRange/start_past_EOF1763=== CONT TestParseSingleRange/single_byte1764=== CONT TestParseSingleRange/suffix_exceeds_size1765=== CONT TestParseSingleRange/suffix1766=== CONT TestParseSingleRange/end_clamped_to_size1767=== CONT TestParseSingleRange/start_far_past_EOF1768=== CONT TestParseSingleRange/open-ended1769=== CONT TestParseSingleRange/closed1770=== CONT TestParseSingleRange/malformed_end_before_start1771=== CONT TestParseSingleRange/malformed_both_empty1772=== CONT TestParseSingleRange/unknown_unit1773=== CONT TestParseSingleRange/malformed_no_dash1774=== CONT TestParseSingleRange/multi-range_ignored1775=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1776--- PASS: TestIsValidCachePath (0.00s)1777 --- PASS: TestIsValidCachePath/narinfo (0.00s)1778 --- PASS: TestIsValidCachePath/index.html (0.00s)1779 --- PASS: TestIsValidCachePath/short_hash (0.00s)1780 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1781 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1782 --- PASS: TestIsValidCachePath/empty (0.00s)1783 --- PASS: TestIsValidCachePath/random_path (0.00s)1784 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1785 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1786 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1787 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1788 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1789 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1790 --- PASS: TestIsValidCachePath/realisation (0.00s)1791 --- PASS: TestIsValidCachePath/log (0.00s)1792 --- PASS: TestIsValidCachePath/ls (0.00s)1793 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1794 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1795 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1796 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1797--- PASS: TestParseSingleRange (0.00s)1798 --- PASS: TestParseSingleRange/none (0.00s)1799 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1800 --- PASS: TestParseSingleRange/single_byte (0.00s)1801 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1802 --- PASS: TestParseSingleRange/suffix (0.00s)1803 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1804 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1805 --- PASS: TestParseSingleRange/open-ended (0.00s)1806 --- PASS: TestParseSingleRange/closed (0.00s)1807 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1808 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1809 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1810 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1811 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1812=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh18132026/10/07 07:42:53 INFO Aborted multipart uploads count=0 kept=018142026/10/07 07:42:53 WARN Force mode enabled - objects will be deleted immediately without grace period1815=== CONT TestServerTLSConfig/no_client_CA1816=== CONT TestServerTLSConfig/not_a_PEM_file1817=== CONT TestServerTLSConfig/missing_CA_file1818--- PASS: TestServerTLSConfig (0.00s)1819 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1820 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1821 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1822=== CONT TestPendingClosureWriteTimeout/empty1823=== CONT TestPendingClosureWriteTimeout/670k_objects1824=== CONT TestPendingClosureWriteTimeout/400_objects1825=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline18262026/10/07 07:42:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18272026/10/07 07:42:53 INFO Aborted multipart uploads count=0 kept=018282026/10/07 07:42:53 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=216.212439ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18292026-10-07 07:42:53.742 UTC [1715] ERROR: canceling statement due to user request18302026-10-07 07:42:53.742 UTC [1715] CONTEXT: SQL statement "UPDATE object_stats s1831 SET object_count = s.object_count + n.n - o.n,1832 total_bytes = s.total_bytes + n.bytes - o.bytes1833 FROM (1834 SELECT count(*) AS n, coalesce(sum(size), 0) AS bytes1835 FROM new_rows WHERE deleted_at IS NULL1836 ) AS n,1837 (1838 SELECT count(*) AS n, coalesce(sum(size), 0) AS bytes1839 FROM old_rows WHERE deleted_at IS NULL1840 ) AS o1841 WHERE s.id AND (n.n <> o.n OR n.bytes <> o.bytes)"1842 PL/pgSQL function object_stats_update() line 3 at SQL statement18432026-10-07 07:42:53.742 UTC [1715] STATEMENT: -- name: MarkStaleObjects :execrows1844 WITH RECURSIVE ct AS (1845 SELECT timezone('UTC', now()) AS now1846 ),1847 closure_reach AS (1848 -- Start with all closure keys1849 SELECT o.key, o.refs1850 FROM objects o1851 INNER JOIN closures c ON o.key = c.key1852 UNION1853 -- Recursively add all referenced objects1854 SELECT o.key, o.refs1855 FROM objects o1856 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1857 ),1858 reachable_objects AS (1859 SELECT DISTINCT key FROM closure_reach1860 ),1861 stale_objects AS (1862 SELECT o.key1863 FROM objects AS o, ct1864 WHERE1865 NOT EXISTS (1866 SELECT 11867 FROM reachable_objects ro1868 WHERE ro.key = o.key1869 )1870 AND NOT EXISTS (1871 SELECT 11872 FROM pending_objects AS po1873 WHERE po.key = o.key1874 )1875 AND o.deleted_at IS NULL -- Only mark fresh objects1876 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure1877 FOR UPDATE1878 )1879 UPDATE objects1880 SET1881 deleted_at = ct.now,1882 first_deleted_at = COALESCE(first_deleted_at, ct.now)1883 FROM stale_objects, ct1884 WHERE objects.key = stale_objects.key1885 18862026/10/07 07:42:53 WARN Force mode enabled - objects will be deleted immediately without grace period1887=== CONT TestIsValidUploadKey/narinfo1888=== CONT TestIsValidUploadKey/traversal_nar1889=== CONT TestIsValidUploadKey/traversal1890=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1891=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1892=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1893=== CONT TestIsValidUploadKey/index.html1894=== CONT TestIsValidUploadKey/nix-cache-info1895=== CONT TestIsValidUploadKey/realisation_plus_in_output1896=== CONT TestIsValidUploadKey/realisation1897=== CONT TestIsValidUploadKey/absolute1898=== CONT TestIsValidUploadKey/build_log_equals1899=== CONT TestIsValidUploadKey/build_log_question_mark1900=== CONT TestIsValidUploadKey/build_log_plus_in_name1901=== CONT TestIsValidUploadKey/build_log_home-manager_file1902=== CONT TestIsValidUploadKey/build_log1903=== CONT TestIsValidUploadKey/listing1904=== CONT TestIsValidUploadKey/nar_plain1905=== CONT TestIsValidUploadKey/nar_xz1906=== CONT TestIsValidUploadKey/unknown_type1907=== CONT TestIsValidUploadKey/empty_key1908=== CONT TestIsValidUploadKey/nar_zst1909--- PASS: TestIsValidUploadKey (0.00s)1910 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1911 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1912 --- PASS: TestIsValidUploadKey/traversal (0.00s)1913 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1914 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1915 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1916 --- PASS: TestIsValidUploadKey/index.html (0.00s)1917 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1918 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1919 --- PASS: TestIsValidUploadKey/realisation (0.00s)1920 --- PASS: TestIsValidUploadKey/absolute (0.00s)1921 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1922 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1923 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1924 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1925 --- PASS: TestIsValidUploadKey/build_log (0.00s)1926 --- PASS: TestIsValidUploadKey/listing (0.00s)1927 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1928 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1929 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1930 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1931 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1932=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info19332026/10/07 07:42:53 INFO Received uploads request method=POST path=/1934=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key19352026/10/07 07:42:53 INFO Received complete multipart upload request method=POST path=/1936=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal19372026/10/07 07:42:53 INFO Received uploads request method=POST path=/1938=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key19392026/10/07 07:42:53 INFO Received request for more parts method=POST path=/1940--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1941 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1942 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1943 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1944 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1945=== CONT TestProxyWriteTimeout/narinfo1946=== CONT TestProxyWriteTimeout/10_GiB_nar1947=== CONT TestProxyWriteTimeout/unknown_size1948=== CONT TestProxyWriteTimeout/1_GiB_nar1949--- PASS: TestProxyWriteTimeout (0.00s)1950 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1951 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1952 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1953 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)19542026/10/07 07:42:53 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:43437/bucket92/?delete=\": context canceled"19552026/10/07 07:42:53 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux19562026/10/07 07:42:53 WARN Refused reserved pin name=worker-x86_64-linux19572026/10/07 07:42:53 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1958--- PASS: TestGCEndsOnShutdown (0.00s)1959 --- PASS: TestGCEndsOnShutdown/before_the_run (0.27s)1960 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.30s)1961 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.29s)19622026/10/07 07:42:53 INFO Received create pin request method=POST path=/api/pins/my-app19632026/10/07 07:42:53 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1964--- PASS: TestCreatePin_ReservedPins (0.59s)19652026/10/07 07:42:53 INFO Received push request method=POST path=/api/pushes19662026/10/07 07:42:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19672026/10/07 07:42:53 INFO Uploading b0yxfk7a2p197973cs4z51yxgwks30z5-file1.txt (160B)19682026/10/07 07:42:53 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"19692026/10/07 07:42:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19702026/10/07 07:42:53 WARN Failed to register uploaded object key=b0yxfk7a2p197973cs4z51yxgwks30z5.ls error="server returned 404: 404 page not found\n"19712026/10/07 07:42:53 INFO Signed narinfos id=1 count=119722026/10/07 07:42:53 INFO Uploading 1 narinfos19732026/10/07 07:42:53 INFO Received complete push request method=POST path=/api/pushes/1/complete19742026/10/07 07:42:53 WARN Failed to register uploaded object key=b0yxfk7a2p197973cs4z51yxgwks30z5.narinfo error="server returned 404: 404 page not found\n"19752026/10/07 07:42:53 INFO Completed push id=1 objects=3 duration=6.309355ms19762026/10/07 07:42:53 INFO Upload complete. (59ms)1977=== NAME TestNARDeduplicationMetadataUploadBug1978 metadata_upload_test.go:54: Retrieved narinfo from S3:1979 StorePath: /build/TestNARDeduplicationMetadataUploadBug2454265856/001/store/b0yxfk7a2p197973cs4z51yxgwks30z5-file1.txt1980 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1981 Compression: zstd1982 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1983 NarSize: 1601984 References: 1985 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1986 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1987 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1988 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}19892026/10/07 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures19902026/10/07 07:42:53 INFO Aborted multipart uploads count=0 kept=01991 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2454265856/001/store/x2kwp7hq75lmb7y5ckg0inwfgr7j6sg9-file2.txt19922026/10/07 07:42:53 WARN Force mode enabled - objects will be deleted immediately without grace period19932026/10/07 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures1994=== NAME TestOrphanedObjectsGC1995 orphaned_objects_gc_test.go:287: GC Test Summary:1996 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1997 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1998 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1999 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)2000 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects2001--- PASS: TestOrphanedObjectsGC (0.61s)20022026/10/07 07:42:53 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=1 objects-deleted-after-grace-period=1 objects-failed-to-delete=020032026/10/07 07:42:53 INFO Vacuumed table table=pending_closures20042026/10/07 07:42:53 INFO Vacuumed table table=pending_objects20052026/10/07 07:42:53 INFO Vacuumed table table=multipart_uploads20062026/10/07 07:42:53 INFO Vacuumed table table=closures20072026/10/07 07:42:53 INFO Vacuumed table table=objects20082026/10/07 07:42:53 INFO Aborted multipart uploads count=0 kept=020092026/10/07 07:42:53 WARN Force mode enabled - objects will be deleted immediately without grace period20102026/10/07 07:42:53 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20112026/10/07 07:42:53 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=020122026/10/07 07:42:53 INFO Vacuumed table table=pending_closures20132026/10/07 07:42:53 INFO Vacuumed table table=pending_objects20142026/10/07 07:42:53 INFO Vacuumed table table=multipart_uploads20152026/10/07 07:42:53 INFO Vacuumed table table=closures20162026/10/07 07:42:53 INFO Vacuumed table table=objects2017--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2018 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.28s)2019 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.28s)20202026/10/07 07:42:53 INFO Received push request method=POST path=/api/pushes20212026/10/07 07:42:53 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)20222026/10/07 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures20232026/10/07 07:42:53 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign20242026/10/07 07:42:53 WARN Failed to register uploaded object key=x2kwp7hq75lmb7y5ckg0inwfgr7j6sg9.ls error="server returned 404: 404 page not found\n"20252026/10/07 07:42:53 INFO Signed narinfos id=2 count=120262026/10/07 07:42:53 INFO Uploading 1 narinfos20272026/10/07 07:42:53 INFO Received complete push request method=POST path=/api/pushes/2/complete20282026/10/07 07:42:53 WARN Failed to register uploaded object key=x2kwp7hq75lmb7y5ckg0inwfgr7j6sg9.narinfo error="server returned 404: 404 page not found\n"20292026/10/07 07:42:53 INFO Completed push id=2 objects=3 duration=1.417572ms20302026/10/07 07:42:53 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20312026/10/07 07:42:53 INFO Upload complete. (44ms)2032=== NAME TestNARDeduplicationMetadataUploadBug2033 metadata_upload_test.go:76: Retrieved narinfo from S3:2034 StorePath: /build/TestNARDeduplicationMetadataUploadBug2454265856/001/store/x2kwp7hq75lmb7y5ckg0inwfgr7j6sg9-file2.txt2035 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2036 Compression: zstd2037 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2038 NarSize: 1602039 References: 2040 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2041 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2042 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2043 {"version":1,"root":{"type":"regular","size":44}}2044--- PASS: TestNARDeduplicationMetadataUploadBug (0.54s)20452026/10/07 07:42:53 INFO lead: released remote=192.0.2.1:123420462026/10/07 07:42:53 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=380.166583ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20472026/10/07 07:42:53 INFO lead: acquired remote=192.0.2.1:123420482026/10/07 07:42:53 INFO lead: released remote=192.0.2.1:12342049--- PASS: TestLeadEndsOnShutdown (1.44s)2050--- PASS: TestObjectStatsLargeCommit (1.26s)20512026/10/07 07:42:54 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=791.434816ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2052--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2053 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.66s)2054 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.66s)20552026/10/07 07:42:54 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020562026/10/07 07:42:54 INFO Received create pin request method=POST path=/api/pins/myapp20572026/10/07 07:42:54 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3903751695/001/store/b9ww68gxiqvqhq7vrvlmq9z661qakwy6-pinned-file.txt narinfo_key=b9ww68gxiqvqhq7vrvlmq9z661qakwy6.narinfo20582026/10/07 07:42:54 INFO Starting cleanup of old closures method=DELETE path=/api/closures20592026/10/07 07:42:54 INFO Garbage collection started20602026/10/07 07:42:54 INFO Aborted multipart uploads count=0 kept=020612026/10/07 07:42:54 WARN Force mode enabled - objects will be deleted immediately without grace period20622026/10/07 07:42:54 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=020632026/10/07 07:42:54 INFO Vacuumed table table=pending_closures20642026/10/07 07:42:54 INFO Vacuumed table table=pending_objects20652026/10/07 07:42:54 INFO Vacuumed table table=multipart_uploads20662026/10/07 07:42:54 INFO Vacuumed table table=closures20672026/10/07 07:42:54 INFO Vacuumed table table=objects20682026/10/07 07:42:54 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02069=== NAME TestClientIntegration2070 client_integration_test.go:323: Objects in database after GC:2071 client_integration_test.go:323: Successfully deleted all objects with GC --force2072--- PASS: TestClientIntegration (2.69s)2073--- PASS: TestUploadHandlersRejectOversizedBody (0.15s)2074 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)2075 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.04s)2076 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.99s)2077=== NAME TestOrphanedObjectsGCStressTest2078 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2079 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion2080--- PASS: TestPendingClosureWriteTimeout (0.00s)2081 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2082 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2083 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2084 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (0.96s)2085=== NAME TestOrphanedObjectsGCStressTest2086 orphaned_objects_gc_test.go:503: Stress test completed successfully:2087 orphaned_objects_gc_test.go:504: - Active objects preserved: 202088 orphaned_objects_gc_test.go:505: - Objects deleted: 2102089 orphaned_objects_gc_test.go:506: - Total GC'd: 2102090--- PASS: TestOrphanedObjectsGCStressTest (1.68s)20912026/10/07 07:42:55 INFO lead: released remote=192.0.2.1:12342092--- PASS: TestLeadElectsOneAndHandsOver (2.72s)20932026/10/07 07:42:55 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.642694083s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2094=== NAME TestPinProtectsFromGC2095 client_integration_test.go:840: Pin successfully protected closure from garbage collection2096--- PASS: TestPinProtectsFromGC (4.93s)20972026/10/07 07:42:56 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20982026/10/07 07:42:56 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=216.192687ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20992026/10/07 07:42:57 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=389.42964ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2100--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.65s)21012026/10/07 07:42:57 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=817.220784ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2102--- PASS: TestConnectWaitsForAPeerMigration (5.11s)21032026/10/07 07:42:58 WARN Rate limiter enabled after throttle name=s3-test rate=521042026/10/07 07:42:58 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2105=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2106 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102107 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002108--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.70s)21092026/10/07 07:42:58 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.60926034s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21102026/10/07 07:42:59 INFO Aborted multipart uploads count=1 kept=021112026/10/07 07:42:59 INFO Received cleanup request method=DELETE path=/api/pending_closures21122026/10/07 07:42:59 INFO Aborted multipart uploads count=1 kept=02113--- PASS: TestPendingCleanupUsesOneCutoff (6.33s)21142026/10/07 07:42:59 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"21152026/10/07 07:42:59 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21162026/10/07 07:43:00 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=213.266961ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21172026/10/07 07:43:00 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=363.502758ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21182026/10/07 07:43:00 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=877.102313ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21192026/10/07 07:43:01 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.746084859s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21202026/10/07 07:43:03 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21212026/10/07 07:43:03 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=181.238697ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21222026/10/07 07:43:03 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=399.111175ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21232026/10/07 07:43:03 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=867.582489ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21242026/10/07 07:43:04 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.615416053s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2125--- PASS: TestClientErrorHandling (0.00s)2126 --- PASS: TestClientErrorHandling/InvalidStorePath (0.30s)2127 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.36s)2128 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.86s)2129PASS21302026-10-07 07:43:06.687 UTC [128] LOG: received smart shutdown request21312026-10-07 07:43:06.690 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 121322026-10-07 07:43:06.702 UTC [133] LOG: shutting down21332026-10-07 07:43:06.702 UTC [133] LOG: checkpoint starting: shutdown immediate21342026-10-07 07:43:07.366 UTC [133] LOG: checkpoint complete: wrote 10887 buffers (66.4%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.171 s, sync=0.462 s, total=0.665 s; sync files=34045, longest=0.007 s, average=0.001 s; distance=531530 kB, estimate=531530 kB; lsn=0/21E78668, redo lsn=0/21E7866821352026-10-07 07:43:07.436 UTC [128] LOG: database system is shut down2136Running OIDC tests...2137=== RUN TestAudienceForIssuer2138=== PAUSE TestAudienceForIssuer2139=== RUN TestGlobMatch2140=== PAUSE TestGlobMatch2141=== RUN TestValidateToken_ValidToken2142=== PAUSE TestValidateToken_ValidToken2143=== RUN TestValidateToken_WrongAudience2144=== PAUSE TestValidateToken_WrongAudience2145=== RUN TestValidateToken_Expired2146=== PAUSE TestValidateToken_Expired2147=== RUN TestValidateToken_BoundClaimsMismatch2148=== PAUSE TestValidateToken_BoundClaimsMismatch2149=== RUN TestValidateToken_BoundSubjectMismatch2150=== PAUSE TestValidateToken_BoundSubjectMismatch2151=== RUN TestValidateToken_MultipleProviders2152=== PAUSE TestValidateToken_MultipleProviders2153=== RUN TestValidateToken_NoMatchingProvider2154=== PAUSE TestValidateToken_NoMatchingProvider2155=== RUN TestValidateToken_KubernetesServiceAccount2156=== PAUSE TestValidateToken_KubernetesServiceAccount2157=== RUN TestNewValidator_KubernetesRequiresCA2158=== PAUSE TestNewValidator_KubernetesRequiresCA2159=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2160=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2161=== RUN TestPins_ReservedForMatchingRule2162=== PAUSE TestPins_ReservedForMatchingRule2163=== RUN TestPins_TopLevelShorthand2164=== PAUSE TestPins_TopLevelShorthand2165=== RUN TestPins_ConfigValidation2166=== PAUSE TestPins_ConfigValidation2167=== RUN TestScopes_LegacyProviderDefaultsToWrite2168=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2169=== RUN TestScopes_Rules2170=== PAUSE TestScopes_Rules2171=== RUN TestScopes_ConfigValidation2172=== PAUSE TestScopes_ConfigValidation2173=== CONT TestAudienceForIssuer2174=== CONT TestScopes_ConfigValidation2175=== CONT TestValidateToken_WrongAudience2176=== CONT TestValidateToken_BoundClaimsMismatch2177=== CONT TestValidateToken_NoMatchingProvider2178=== CONT TestValidateToken_MultipleProviders2179=== CONT TestValidateToken_BoundSubjectMismatch2180=== CONT TestValidateToken_Expired2181=== CONT TestValidateToken_ValidToken2182=== CONT TestPins_TopLevelShorthand2183=== CONT TestScopes_Rules2184=== CONT TestScopes_LegacyProviderDefaultsToWrite2185=== CONT TestPins_ConfigValidation2186=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2187=== CONT TestPins_ReservedForMatchingRule2188=== CONT TestNewValidator_KubernetesRequiresCA2189=== CONT TestGlobMatch2190=== RUN TestGlobMatch/foo_foo2191=== PAUSE TestGlobMatch/foo_foo2192=== RUN TestGlobMatch/foo_bar2193=== PAUSE TestGlobMatch/foo_bar2194=== RUN TestGlobMatch/*_2195=== PAUSE TestGlobMatch/*_2196=== RUN TestGlobMatch/*_anything2197=== PAUSE TestGlobMatch/*_anything2198=== RUN TestGlobMatch/foo*_foo2199--- PASS: TestAudienceForIssuer (0.00s)2200=== CONT TestValidateToken_KubernetesServiceAccount2201--- PASS: TestScopes_ConfigValidation (0.00s)2202--- PASS: TestPins_ConfigValidation (0.00s)2203=== PAUSE TestGlobMatch/foo*_foo2204=== RUN TestGlobMatch/foo*_foobar2205=== PAUSE TestGlobMatch/foo*_foobar2206=== RUN TestGlobMatch/foo*_bar2207=== PAUSE TestGlobMatch/foo*_bar2208=== RUN TestGlobMatch/*bar_bar2209=== PAUSE TestGlobMatch/*bar_bar2210=== RUN TestGlobMatch/*bar_foobar2211=== PAUSE TestGlobMatch/*bar_foobar2212=== RUN TestGlobMatch/*bar_foo2213=== PAUSE TestGlobMatch/*bar_foo2214=== RUN TestGlobMatch/foo*bar_foobar2215=== PAUSE TestGlobMatch/foo*bar_foobar2216=== RUN TestGlobMatch/foo*bar_foo123bar2217=== PAUSE TestGlobMatch/foo*bar_foo123bar2218=== RUN TestGlobMatch/foo*bar_foobarbaz2219=== PAUSE TestGlobMatch/foo*bar_foobarbaz2220=== RUN TestGlobMatch/*/*_foo/bar2221=== PAUSE TestGlobMatch/*/*_foo/bar2222=== RUN TestGlobMatch/*/*_foo2223=== PAUSE TestGlobMatch/*/*_foo2224=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2225=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2226=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02227=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02228=== RUN TestGlobMatch/refs/*/main_refs/heads/main2229=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2230=== RUN TestGlobMatch/fo?_foo2231=== PAUSE TestGlobMatch/fo?_foo2232=== RUN TestGlobMatch/fo?_fo2233=== PAUSE TestGlobMatch/fo?_fo2234=== RUN TestGlobMatch/fo?_fooo2235=== PAUSE TestGlobMatch/fo?_fooo2236=== RUN TestGlobMatch/?oo_foo2237=== PAUSE TestGlobMatch/?oo_foo2238=== RUN TestGlobMatch/?oo_boo2239=== PAUSE TestGlobMatch/?oo_boo2240=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2241=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2242=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2243=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2244=== CONT TestGlobMatch/foo_foo2245=== CONT TestGlobMatch/foo*bar_foo123bar2246=== CONT TestGlobMatch/foo*bar_foobar2247=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2248=== CONT TestGlobMatch/fo?_foo2249=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2250=== CONT TestGlobMatch/?oo_boo2251=== CONT TestGlobMatch/?oo_foo2252=== CONT TestGlobMatch/fo?_fooo2253=== CONT TestGlobMatch/fo?_fo2254=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2255=== CONT TestGlobMatch/refs/*/main_refs/heads/main2256=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02257=== CONT TestGlobMatch/*/*_foo2258=== CONT TestGlobMatch/*/*_foo/bar2259=== CONT TestGlobMatch/foo*bar_foobarbaz2260=== CONT TestGlobMatch/*bar_foo2261=== CONT TestGlobMatch/*bar_foobar2262=== CONT TestGlobMatch/*bar_bar2263=== CONT TestGlobMatch/foo*_bar2264=== CONT TestGlobMatch/foo*_foobar2265=== CONT TestGlobMatch/foo*_foo2266=== CONT TestGlobMatch/*_anything2267=== CONT TestGlobMatch/*_2268=== CONT TestGlobMatch/foo_bar2269--- PASS: TestGlobMatch (0.00s)2270 --- PASS: TestGlobMatch/foo_foo (0.00s)2271 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2272 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2273 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2274 --- PASS: TestGlobMatch/fo?_foo (0.00s)2275 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2276 --- PASS: TestGlobMatch/?oo_boo (0.00s)2277 --- PASS: TestGlobMatch/?oo_foo (0.00s)2278 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2279 --- PASS: TestGlobMatch/fo?_fo (0.00s)2280 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2281 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2282 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2283 --- PASS: TestGlobMatch/*/*_foo (0.00s)2284 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2285 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2286 --- PASS: TestGlobMatch/*bar_foo (0.00s)2287 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2288 --- PASS: TestGlobMatch/*bar_bar (0.00s)2289 --- PASS: TestGlobMatch/foo*_bar (0.00s)2290 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2291 --- PASS: TestGlobMatch/foo*_foo (0.00s)2292 --- PASS: TestGlobMatch/*_anything (0.00s)2293 --- PASS: TestGlobMatch/*_ (0.00s)2294 --- PASS: TestGlobMatch/foo_bar (0.00s)22952026/10/07 07:43:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35669/oidc2296--- PASS: TestPins_TopLevelShorthand (0.04s)22972026/10/07 07:43:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42465/oidc22982026/10/07 07:43:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34869/oidc2299--- PASS: TestPins_ReservedForMatchingRule (0.06s)23002026/10/07 07:43:09 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:359612301--- PASS: TestScopes_Rules (0.08s)2302--- PASS: TestValidateToken_KubernetesServiceAccount (0.08s)23032026/10/07 07:43:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39185/oidc23042026/10/07 07:43:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41063/oidc23052026/10/07 07:43:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39455/oidc2306--- PASS: TestValidateToken_ValidToken (0.12s)2307--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.12s)2308--- PASS: TestValidateToken_BoundClaimsMismatch (0.12s)23092026/10/07 07:43:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45077/oidc2310--- PASS: TestValidateToken_WrongAudience (0.17s)23112026/10/07 07:43:09 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:39601/oidc23122026/10/07 07:43:09 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:46351/oidc2313--- PASS: TestValidateToken_MultipleProviders (0.20s)23142026/10/07 07:43:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33463/oidc2315--- PASS: TestValidateToken_BoundSubjectMismatch (0.21s)23162026/10/07 07:43:09 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232317--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.22s)23182026/10/07 07:43:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34761/oidc23192026/10/07 07:43:09 http: TLS handshake error from 127.0.0.1:51362: remote error: tls: bad certificate2320--- PASS: TestNewValidator_KubernetesRequiresCA (0.24s)2321--- PASS: TestValidateToken_Expired (0.25s)23222026/10/07 07:43:09 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:33215/oidc2323--- PASS: TestValidateToken_NoMatchingProvider (0.32s)2324PASS2325Running hook tests...2326=== RUN TestSendPathsEmpty2327=== PAUSE TestSendPathsEmpty2328=== RUN TestQueueEnqueueAndFetch2329=== PAUSE TestQueueEnqueueAndFetch2330=== RUN TestQueueDeduplication2331=== PAUSE TestQueueDeduplication2332=== RUN TestQueueRemove2333=== PAUSE TestQueueRemove2334=== RUN TestQueueFetchBatchLimit2335=== PAUSE TestQueueFetchBatchLimit2336=== RUN TestQueueRetryMovesToBack2337=== PAUSE TestQueueRetryMovesToBack2338=== RUN TestQueueFetchRemoveLifecycle2339=== PAUSE TestQueueFetchRemoveLifecycle2340=== RUN TestQueueConcurrentWriters2341=== PAUSE TestQueueConcurrentWriters2342=== RUN TestQueueRemoveLargeClosure2343=== PAUSE TestQueueRemoveLargeClosure2344=== RUN TestServerClientIntegration2345--- PASS: TestServerClientIntegration (0.00s)2346=== RUN TestServerQueueError23472026/10/07 07:43:09 ERROR Failed to queue paths error="permission denied" count=12348--- PASS: TestServerQueueError (0.00s)2349=== RUN TestGetListenerSocketActivation2350 server_test.go:219: === RUN TestGetListenerSocketActivation2351 --- PASS: TestGetListenerSocketActivation (0.00s)2352 PASS2353 2354--- PASS: TestGetListenerSocketActivation (0.01s)2355=== RUN TestDrainIsolatesPoisonPath2356=== PAUSE TestDrainIsolatesPoisonPath2357=== RUN TestRunNotBlockedByPoisonHead2358=== PAUSE TestRunNotBlockedByPoisonHead2359=== RUN TestDrainGivesUpWhenServerDown2360=== PAUSE TestDrainGivesUpWhenServerDown2361=== RUN TestFailedPathPrunedByLaterClosure2362=== PAUSE TestFailedPathPrunedByLaterClosure2363=== RUN TestWorkerUploadsAndRemoves2364=== PAUSE TestWorkerUploadsAndRemoves2365=== RUN TestWorkerSkipsGCdPaths2366=== PAUSE TestWorkerSkipsGCdPaths2367=== RUN TestWorkerPrunesClosureDeps2368=== PAUSE TestWorkerPrunesClosureDeps2369=== RUN TestDrainTimeout2370=== PAUSE TestDrainTimeout2371=== CONT TestSendPathsEmpty2372=== CONT TestQueueFetchBatchLimit2373--- PASS: TestSendPathsEmpty (0.00s)2374=== CONT TestDrainTimeout2375=== CONT TestWorkerPrunesClosureDeps2376=== CONT TestWorkerSkipsGCdPaths2377=== CONT TestQueueConcurrentWriters2378=== CONT TestQueueRemove2379=== CONT TestQueueDeduplication2380=== CONT TestWorkerUploadsAndRemoves2381=== CONT TestQueueEnqueueAndFetch2382=== CONT TestFailedPathPrunedByLaterClosure2383=== CONT TestDrainGivesUpWhenServerDown2384=== CONT TestQueueFetchRemoveLifecycle2385=== CONT TestRunNotBlockedByPoisonHead2386=== CONT TestDrainIsolatesPoisonPath2387=== CONT TestQueueRetryMovesToBack2388=== CONT TestQueueRemoveLargeClosure23892026/10/07 07:43:09 INFO Upload queue status pending=223902026/10/07 07:43:09 INFO Uploading batch count=423912026/10/07 07:43:09 ERROR Upload failed error="upload failed" count=423922026/10/07 07:43:09 INFO Uploading batch count=123932026/10/07 07:43:09 ERROR Upload failed error="upload failed" count=123942026/10/07 07:43:09 INFO Uploading batch count=223952026/10/07 07:43:09 INFO Upload queue status pending=223962026/10/07 07:43:09 INFO Upload queue status pending=323972026/10/07 07:43:09 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath115619168/002/bbb2398--- PASS: TestQueueFetchBatchLimit (0.01s)23992026/10/07 07:43:09 INFO Uploading batch count=124002026/10/07 07:43:09 INFO Uploading batch count=124012026/10/07 07:43:09 INFO Uploading batch count=22402--- PASS: TestQueueEnqueueAndFetch (0.01s)24032026/10/07 07:43:09 INFO Upload queue status pending=224042026/10/07 07:43:09 INFO Uploading batch count=124052026/10/07 07:43:09 ERROR Upload failed error="upload failed" count=12406--- PASS: TestQueueDeduplication (0.02s)24072026/10/07 07:43:09 INFO Uploading batch count=224082026/10/07 07:43:09 ERROR Upload failed error="upload failed" count=224092026/10/07 07:43:09 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3267481288/002/a24102026/10/07 07:43:09 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3358608518/002/nonexistent24112026/10/07 07:43:09 INFO Uploading batch count=124122026/10/07 07:43:09 ERROR Upload failed error="upload failed" count=124132026/10/07 07:43:09 INFO Uploading batch count=12414--- PASS: TestQueueRetryMovesToBack (0.01s)2415--- PASS: TestQueueRemove (0.02s)24162026/10/07 07:43:09 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3267481288/002/b2417--- PASS: TestQueueFetchRemoveLifecycle (0.02s)24182026/10/07 07:43:09 INFO Uploading batch count=124192026/10/07 07:43:09 INFO Uploading batch count=124202026/10/07 07:43:09 ERROR Upload failed error="upload failed" count=124212026/10/07 07:43:09 INFO Uploading batch count=224222026/10/07 07:43:09 ERROR Upload failed error="upload failed" count=224232026/10/07 07:43:09 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3267481288/002/c24242026/10/07 07:43:09 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3267481288/002/d2425--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)24262026/10/07 07:43:09 INFO Uploading batch count=124272026/10/07 07:43:09 ERROR Upload failed error="upload failed" count=124282026/10/07 07:43:09 INFO Uploading batch count=224292026/10/07 07:43:09 ERROR Upload failed error="upload failed" count=224302026/10/07 07:43:09 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3267481288/002/e24312026/10/07 07:43:09 ERROR Drain finished with paths left in queue remaining=124322026/10/07 07:43:09 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3267481288/002/f24332026/10/07 07:43:09 ERROR Drain finished with paths left in queue remaining=102434--- PASS: TestDrainIsolatesPoisonPath (0.02s)2435--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2436--- PASS: TestWorkerSkipsGCdPaths (0.03s)2437--- PASS: TestWorkerUploadsAndRemoves (0.03s)2438--- PASS: TestWorkerPrunesClosureDeps (0.03s)2439--- PASS: TestQueueRemoveLargeClosure (0.10s)2440--- PASS: TestQueueConcurrentWriters (0.16s)24412026/10/07 07:43:09 ERROR Upload failed error="context deadline exceeded" count=224422026/10/07 07:43:09 ERROR Drain finished with paths left in queue remaining=42443--- PASS: TestDrainTimeout (0.22s)24442026/10/07 07:43:10 INFO Uploading batch count=124452026/10/07 07:43:10 INFO Uploading batch count=124462026/10/07 07:43:10 INFO Uploading batch count=124472026/10/07 07:43:10 ERROR Upload failed error="upload failed" count=124482026/10/07 07:43:10 INFO Uploading batch count=124492026/10/07 07:43:10 ERROR Upload failed error="upload failed" count=124502026/10/07 07:43:10 INFO Uploading batch count=124512026/10/07 07:43:10 ERROR Upload failed error="upload failed" count=124522026/10/07 07:43:10 INFO Uploading batch count=124532026/10/07 07:43:10 ERROR Upload failed error="upload failed" count=124542026/10/07 07:43:10 ERROR Drain finished with paths left in queue remaining=12455--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2456PASS2457Running signing tests...2458=== RUN TestExternalSigner2459=== PAUSE TestExternalSigner2460=== RUN TestExternalSignerWrongPublicKey2461=== PAUSE TestExternalSignerWrongPublicKey2462=== RUN TestExternalSignerErrors2463=== PAUSE TestExternalSignerErrors2464=== RUN TestExternalSignerRestartsAfterCrash2465=== PAUSE TestExternalSignerRestartsAfterCrash2466=== RUN TestExternalSignerProgramErrorKeepsProcess2467=== PAUSE TestExternalSignerProgramErrorKeepsProcess2468=== RUN TestExternalSignerClose2469=== PAUSE TestExternalSignerClose2470=== RUN TestExternalSignerRejectsInvalidPublicKey2471=== PAUSE TestExternalSignerRejectsInvalidPublicKey2472=== RUN TestExternalSignerCancellation2473=== PAUSE TestExternalSignerCancellation2474=== RUN TestGenerateFingerprint2475=== PAUSE TestGenerateFingerprint2476=== RUN TestParseSigningKey2477=== PAUSE TestParseSigningKey2478=== RUN TestSign2479=== PAUSE TestSign2480=== RUN TestSignBatch2481=== PAUSE TestSignBatch2482=== RUN TestNilKeyPublicKey2483=== PAUSE TestNilKeyPublicKey2484=== RUN TestSignErrors2485=== PAUSE TestSignErrors2486=== CONT TestExternalSigner2487=== CONT TestSignBatch2488=== CONT TestParseSigningKey2489=== CONT TestExternalSignerCancellation2490=== CONT TestGenerateFingerprint2491=== RUN TestGenerateFingerprint/basic_with_references2492=== PAUSE TestGenerateFingerprint/basic_with_references2493=== RUN TestGenerateFingerprint/no_references2494=== PAUSE TestGenerateFingerprint/no_references2495=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2496=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2497=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2498=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2499=== RUN TestGenerateFingerprint/invalid_nar_hash_length2500=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2501=== RUN TestGenerateFingerprint/invalid_store_path_prefix2502=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2503=== RUN TestGenerateFingerprint/invalid_reference_prefix2504=== CONT TestExternalSignerProgramErrorKeepsProcess2505=== CONT TestExternalSignerRejectsInvalidPublicKey2506=== CONT TestExternalSignerClose2507=== RUN TestExternalSignerRejectsInvalidPublicKey/#002508=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002509=== CONT TestSignErrors2510=== CONT TestNilKeyPublicKey2511--- PASS: TestNilKeyPublicKey (0.00s)2512=== CONT TestSign2513=== CONT TestExternalSignerErrors2514=== RUN TestExternalSignerErrors/unrequested_key2515=== CONT TestExternalSignerRestartsAfterCrash2516=== PAUSE TestExternalSignerErrors/unrequested_key2517=== RUN TestExternalSignerErrors/missing_signature_name2518=== PAUSE TestExternalSignerErrors/missing_signature_name2519=== RUN TestExternalSignerErrors/exit_at_startup2520=== PAUSE TestExternalSignerErrors/exit_at_startup2521=== RUN TestExternalSignerErrors/invalid_JSON2522=== PAUSE TestExternalSignerErrors/invalid_JSON2523=== RUN TestExternalSignerErrors/wrong_shape2524=== PAUSE TestExternalSignerErrors/wrong_shape2525=== RUN TestExternalSignerErrors/null_signatures2526=== CONT TestExternalSignerWrongPublicKey2527=== RUN TestParseSigningKey/valid_32-byte_key2528=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2529=== CONT TestGenerateFingerprint/basic_with_references2530=== CONT TestGenerateFingerprint/invalid_store_path_prefix2531=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2532=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2533=== CONT TestGenerateFingerprint/invalid_nar_hash_length2534=== PAUSE TestExternalSignerErrors/null_signatures2535=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2536=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2537=== CONT TestGenerateFingerprint/invalid_reference_prefix2538=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2539=== CONT TestGenerateFingerprint/no_references2540=== PAUSE TestParseSigningKey/valid_32-byte_key2541=== RUN TestExternalSignerErrors/wrong_signatures_shape2542=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2543=== RUN TestExternalSignerErrors/too_few_signatures2544=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2545--- PASS: TestGenerateFingerprint (0.00s)2546 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2547 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2548 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2549 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2550 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2551 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2552 --- PASS: TestGenerateFingerprint/no_references (0.00s)2553=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2554=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2555=== PAUSE TestExternalSignerErrors/too_few_signatures2556=== RUN TestExternalSignerErrors/wrong_signature_name2557=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2558=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2559=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2560=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2561=== CONT TestExternalSignerRejectsInvalidPublicKey/#002562=== RUN TestParseSigningKey/no_colon2563=== PAUSE TestParseSigningKey/no_colon2564=== RUN TestParseSigningKey/empty_name2565=== PAUSE TestExternalSignerErrors/wrong_signature_name2566=== RUN TestExternalSignerErrors/invalid_signature_base642567=== PAUSE TestExternalSignerErrors/invalid_signature_base642568=== RUN TestExternalSignerErrors/wrong_id2569=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2570=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2571=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2572=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2573--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2574 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2575 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2576 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2577 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2578 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2579=== PAUSE TestParseSigningKey/empty_name2580=== RUN TestParseSigningKey/invalid_base642581=== PAUSE TestParseSigningKey/invalid_base642582=== RUN TestParseSigningKey/wrong_length2583=== PAUSE TestParseSigningKey/wrong_length2584=== CONT TestParseSigningKey/valid_32-byte_key2585=== RUN TestSignErrors/nil_key2586=== CONT TestParseSigningKey/empty_name2587=== CONT TestParseSigningKey/wrong_length2588=== CONT TestParseSigningKey/invalid_base642589=== CONT TestParseSigningKey/no_colon2590=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2591--- PASS: TestParseSigningKey (0.00s)2592 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2593 --- PASS: TestParseSigningKey/empty_name (0.00s)2594 --- PASS: TestParseSigningKey/wrong_length (0.00s)2595 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2596 --- PASS: TestParseSigningKey/no_colon (0.00s)2597 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2598=== PAUSE TestExternalSignerErrors/wrong_id2599=== RUN TestExternalSignerErrors/exit_on_request2600=== PAUSE TestSignErrors/nil_key2601--- PASS: TestSign (0.00s)2602=== PAUSE TestExternalSignerErrors/exit_on_request2603=== RUN TestSignErrors/nil_narinfo2604=== PAUSE TestSignErrors/nil_narinfo2605=== RUN TestSignErrors/invalid_narinfo2606=== PAUSE TestSignErrors/invalid_narinfo2607=== RUN TestSignErrors/canceled2608=== PAUSE TestSignErrors/canceled2609=== CONT TestSignErrors/nil_key2610=== RUN TestExternalSignerErrors/missing_signatures2611=== PAUSE TestExternalSignerErrors/missing_signatures2612=== RUN TestExternalSignerErrors/wrong_signature_length2613=== PAUSE TestExternalSignerErrors/wrong_signature_length2614=== RUN TestExternalSignerErrors/program_error2615=== PAUSE TestExternalSignerErrors/program_error2616=== RUN TestExternalSignerErrors/null2617=== PAUSE TestExternalSignerErrors/null2618=== CONT TestExternalSignerErrors/unrequested_key2619=== CONT TestExternalSignerErrors/missing_signatures2620--- PASS: TestSignBatch (0.00s)2621=== CONT TestExternalSignerErrors/missing_signature_name2622=== CONT TestSignErrors/invalid_narinfo2623=== CONT TestExternalSignerErrors/invalid_JSON2624=== CONT TestExternalSignerErrors/wrong_signatures_shape2625=== CONT TestExternalSignerErrors/null2626=== CONT TestSignErrors/nil_narinfo2627=== CONT TestSignErrors/canceled2628--- PASS: TestSignErrors (0.00s)2629 --- PASS: TestSignErrors/nil_key (0.00s)2630 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2631 --- PASS: TestSignErrors/nil_narinfo (0.00s)2632 --- PASS: TestSignErrors/canceled (0.00s)2633=== CONT TestExternalSignerErrors/wrong_signature_name2634=== CONT TestExternalSignerErrors/program_error2635=== CONT TestExternalSignerErrors/wrong_shape2636=== CONT TestExternalSignerErrors/wrong_signature_length2637=== CONT TestExternalSignerErrors/too_few_signatures2638=== CONT TestExternalSignerErrors/wrong_id2639=== CONT TestExternalSignerErrors/null_signatures2640=== CONT TestExternalSignerErrors/exit_on_request2641=== CONT TestExternalSignerErrors/invalid_signature_base642642=== CONT TestExternalSignerErrors/exit_at_startup2643--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.01s)2644--- PASS: TestExternalSignerClose (0.00s)2645--- PASS: TestExternalSignerWrongPublicKey (0.01s)2646--- PASS: TestExternalSigner (0.01s)2647--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2648--- PASS: TestExternalSignerErrors (0.00s)2649 --- PASS: TestExternalSignerErrors/missing_signatures (0.00s)2650 --- PASS: TestExternalSignerErrors/unrequested_key (0.00s)2651 --- PASS: TestExternalSignerErrors/null (0.00s)2652 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)2653 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.00s)2654 --- PASS: TestExternalSignerErrors/program_error (0.00s)2655 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2656 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2657 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2658 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2659 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2660 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2661 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2662 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2663 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2664 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2665--- PASS: TestExternalSignerCancellation (0.02s)2666PASS2667Running OpenBao signer tests...2668=== RUN TestSign2669=== PAUSE TestSign2670=== RUN TestSignErrors2671=== PAUSE TestSignErrors2672=== RUN TestServe2673=== PAUSE TestServe2674=== RUN TestServeRejectsGarbage2675=== PAUSE TestServeRejectsGarbage2676=== CONT TestSign2677=== CONT TestServe2678=== CONT TestSignErrors2679=== RUN TestSignErrors/http_error2680=== PAUSE TestSignErrors/http_error2681=== RUN TestSignErrors/invalid_json2682=== PAUSE TestSignErrors/invalid_json2683=== RUN TestSignErrors/no_prefix2684=== PAUSE TestSignErrors/no_prefix2685=== RUN TestSignErrors/invalid_base642686=== PAUSE TestSignErrors/invalid_base642687=== CONT TestSignErrors/http_error2688=== CONT TestSignErrors/no_prefix2689=== CONT TestServeRejectsGarbage2690=== CONT TestSignErrors/invalid_base642691=== CONT TestSignErrors/invalid_json2692--- PASS: TestServe (0.00s)2693--- PASS: TestServeRejectsGarbage (0.00s)2694--- PASS: TestSignErrors (0.00s)2695 --- PASS: TestSignErrors/invalid_json (0.01s)2696 --- PASS: TestSignErrors/no_prefix (0.01s)2697 --- PASS: TestSignErrors/http_error (0.01s)2698 --- PASS: TestSignErrors/invalid_base64 (0.01s)2699--- PASS: TestSign (0.01s)2700PASS

succeeded niks3-go-unit-tests checks.aarch64-linux.go-unit-tests · build #395 · raw

succeeded `niks3-go-unit-tests` `checks.aarch64-linux.go-unit-tests` · build #395 · raw