niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #276
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestRegisterUploadedObjectReusesConnections5=== PAUSE TestRegisterUploadedObjectReusesConnections6=== RUN TestCaseHackSuffix7=== PAUSE TestCaseHackSuffix8=== RUN TestFilterOversizedClosures9=== PAUSE TestFilterOversizedClosures10=== RUN TestUploadMultipart_PartsInParallel11=== PAUSE TestUploadMultipart_PartsInParallel12=== RUN TestPartSizeForNAR13=== PAUSE TestPartSizeForNAR14=== RUN TestUploadMultipart_SupersededByPeer15=== PAUSE TestUploadMultipart_SupersededByPeer16=== RUN TestDumpPathCaseHackMatchesNix17--- PASS: TestDumpPathCaseHackMatchesNix (0.08s)18=== RUN TestDumpPathCaseHackCollision19--- PASS: TestDumpPathCaseHackCollision (0.00s)20=== RUN TestDumpPathMatchesNix21=== PAUSE TestDumpPathMatchesNix22=== RUN TestDumpPathSingleFile23=== PAUSE TestDumpPathSingleFile24=== RUN TestDumpPathWriterError25=== PAUSE TestDumpPathWriterError26=== RUN TestEncodeNixBase3227=== PAUSE TestEncodeNixBase3228=== RUN TestEncodeNixBase32WithRealHash29=== PAUSE TestEncodeNixBase32WithRealHash30=== RUN TestConvertHashToNix3231=== PAUSE TestConvertHashToNix3232=== RUN TestGetStorePathHash33=== PAUSE TestGetStorePathHash34=== RUN TestPathInfoHashCompatibility35=== PAUSE TestPathInfoHashCompatibility36=== RUN TestParsePathInfoJSON37=== PAUSE TestParsePathInfoJSON38=== RUN TestParsePathInfoJSONMultiplePaths39=== PAUSE TestParsePathInfoJSONMultiplePaths40=== RUN TestPathInfoCACompatibility41=== PAUSE TestPathInfoCACompatibility42=== RUN TestRateLimiterFeedback43=== PAUSE TestRateLimiterFeedback44=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess45=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== RUN TestResolveStorePath47=== PAUSE TestResolveStorePath48=== RUN TestDoWithRetry_BodyReplayedViaGetBody49=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody50=== RUN TestShellSplit51=== PAUSE TestShellSplit52=== RUN TestShellSplitErrors53=== PAUSE TestShellSplitErrors54=== RUN TestStreamPushReportsEveryPath55=== PAUSE TestStreamPushReportsEveryPath56=== RUN TestStreamPushBatchesUnderLoad57=== PAUSE TestStreamPushBatchesUnderLoad58=== RUN TestStreamPushIsolatesFailures59=== PAUSE TestStreamPushIsolatesFailures60=== RUN TestStreamPushGivesUpOnDeadServer61=== PAUSE TestStreamPushGivesUpOnDeadServer62=== RUN TestStreamPushRequestLine63=== PAUSE TestStreamPushRequestLine64=== RUN TestStreamPushReportsSignatures65=== PAUSE TestStreamPushReportsSignatures66=== RUN TestClientSignaturesByStorePath67=== PAUSE TestClientSignaturesByStorePath68=== RUN TestSetClientTLS69=== PAUSE TestSetClientTLS70=== RUN TestSetClientTLSDoesNotMutateDefaultTransport71=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport72=== RUN TestSetClientTLSErrors73=== PAUSE TestSetClientTLSErrors74=== RUN TestStaticToken75=== PAUSE TestStaticToken76=== RUN TestFileTokenReadsAndCaches77=== PAUSE TestFileTokenReadsAndCaches78=== RUN TestFileTokenMissing79=== PAUSE TestFileTokenMissing80=== RUN TestFileTokenEmpty81=== PAUSE TestFileTokenEmpty82=== RUN TestScriptTokenNoExpiryRerunsEveryCall83=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall84=== RUN TestScriptTokenCachesUntilRefresh85=== PAUSE TestScriptTokenCachesUntilRefresh86=== RUN TestScriptTokenEmptyToken87=== PAUSE TestScriptTokenEmptyToken88=== RUN TestScriptTokenBadJSON89=== PAUSE TestScriptTokenBadJSON90=== RUN TestScriptTokenScriptFails91=== PAUSE TestScriptTokenScriptFails92=== RUN TestScriptTokenEmptyCommand93=== PAUSE TestScriptTokenEmptyCommand94=== CONT TestDoServerRequestAttachesToken95=== CONT TestShellSplit96=== CONT TestEncodeNixBase32WithRealHash97=== CONT TestScriptTokenEmptyCommand98--- PASS: TestEncodeNixBase32WithRealHash (0.00s)99=== CONT TestScriptTokenScriptFails100--- PASS: TestScriptTokenEmptyCommand (0.00s)101=== CONT TestDoWithRetry_BodyReplayedViaGetBody102--- PASS: TestShellSplit (0.00s)103=== CONT TestStreamPushGivesUpOnDeadServer104=== CONT TestResolveStorePath105=== CONT TestStreamPushRequestLine106=== CONT TestStreamPushIsolatesFailures107=== CONT TestStreamPushBatchesUnderLoad108=== CONT TestStreamPushReportsEveryPath1092026/09/29 08:15:08 ERROR Upload failed error="connection refused" count=201102026/09/29 08:15:08 ERROR Server seems unavailable, giving up on batch untried=17111=== CONT TestSetClientTLSErrors1122026/09/29 08:15:08 ERROR Upload failed error="bad path" count=3113--- PASS: TestStreamPushReportsEveryPath (0.00s)114--- PASS: TestStreamPushIsolatesFailures (0.00s)115=== CONT TestSetClientTLSDoesNotMutateDefaultTransport116=== CONT TestShellSplitErrors117--- PASS: TestShellSplitErrors (0.00s)118=== CONT TestSetClientTLS1192026/09/29 08:15:08 ERROR Upload failed error=boom count=1120--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)121=== CONT TestClientSignaturesByStorePath122--- PASS: TestClientSignaturesByStorePath (0.00s)123=== CONT TestStreamPushReportsSignatures1242026/09/29 08:15:08 ERROR Upload failed error=boom count=1125--- PASS: TestStreamPushReportsSignatures (0.00s)126=== CONT TestScriptTokenNoExpiryRerunsEveryCall127--- PASS: TestResolveStorePath (0.00s)128=== CONT TestScriptTokenBadJSON129=== RUN TestSetClientTLSErrors/missing_cert_file130=== PAUSE TestSetClientTLSErrors/missing_cert_file131=== RUN TestSetClientTLSErrors/missing_key_file132=== PAUSE TestSetClientTLSErrors/missing_key_file133=== RUN TestSetClientTLSErrors/missing_ca_file134=== PAUSE TestSetClientTLSErrors/missing_ca_file135=== RUN TestSetClientTLSErrors/invalid_ca_file136=== PAUSE TestSetClientTLSErrors/invalid_ca_file137=== CONT TestScriptTokenEmptyToken1382026/09/29 08:15:08 WARN Rate limiter enabled after throttle name=server-test rate=51392026/09/29 08:15:08 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:55598140--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)141=== CONT TestScriptTokenCachesUntilRefresh1422026/09/29 08:15:08 WARN Rate limiter backed off name=server-test rate=51432026/09/29 08:15:08 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:55598144--- PASS: TestDoServerRequestAttachesToken (0.00s)145=== CONT TestFileTokenMissing146--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)147=== CONT TestFileTokenEmpty148=== CONT TestPartSizeForNAR149=== CONT TestEncodeNixBase32150=== RUN TestPartSizeForNAR/zero_stays_at_minimum151=== RUN TestEncodeNixBase32/test_string_hash152=== RUN TestSetClientTLS/rejects_connection_without_client_cert153--- PASS: TestScriptTokenScriptFails (0.01s)154--- PASS: TestFileTokenMissing (0.00s)155=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum156=== RUN TestPartSizeForNAR/small_stays_at_minimum157=== PAUSE TestPartSizeForNAR/small_stays_at_minimum158=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum159=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum160=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert161=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA162=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA163=== RUN TestSetClientTLS/preserves_debug_logging_transport164=== PAUSE TestSetClientTLS/preserves_debug_logging_transport165=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts166=== PAUSE TestEncodeNixBase32/test_string_hash167=== RUN TestEncodeNixBase32/empty_input168--- PASS: TestFileTokenEmpty (0.00s)169=== PAUSE TestEncodeNixBase32/empty_input170=== CONT TestDumpPathSingleFile171=== CONT TestDumpPathMatchesNix172=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts173=== RUN TestPartSizeForNAR/1_TiB174=== PAUSE TestPartSizeForNAR/1_TiB175=== CONT TestDumpPathWriterError176=== RUN TestPartSizeForNAR/5_TiB_S3_max_object177=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object178=== RUN TestPartSizeForNAR/capped_at_5_GiB179=== PAUSE TestPartSizeForNAR/capped_at_5_GiB180=== CONT TestUploadMultipart_SupersededByPeer181=== RUN TestUploadMultipart_SupersededByPeer/exists182=== PAUSE TestUploadMultipart_SupersededByPeer/exists183=== RUN TestUploadMultipart_SupersededByPeer/missing184=== PAUSE TestUploadMultipart_SupersededByPeer/missing185=== CONT TestUploadMultipart_PartsInParallel186--- PASS: TestScriptTokenEmptyToken (0.01s)187=== CONT TestRegisterUploadedObjectReusesConnections188--- PASS: TestScriptTokenBadJSON (0.01s)189=== CONT TestFileTokenReadsAndCaches190--- PASS: TestFileTokenReadsAndCaches (0.00s)191=== CONT TestParsePathInfoJSON192=== RUN TestParsePathInfoJSON/Nix_format193=== PAUSE TestParsePathInfoJSON/Nix_format194=== RUN TestParsePathInfoJSON/Lix_format195=== PAUSE TestParsePathInfoJSON/Lix_format196=== RUN TestParsePathInfoJSON/empty_input197=== PAUSE TestParsePathInfoJSON/empty_input198=== RUN TestParsePathInfoJSON/whitespace_only199=== PAUSE TestParsePathInfoJSON/whitespace_only200=== RUN TestParsePathInfoJSON/invalid_JSON201=== PAUSE TestParsePathInfoJSON/invalid_JSON202=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess2032026/09/29 08:15:08 WARN Rate limiter enabled after throttle name=server-test rate=5204--- PASS: TestStreamPushRequestLine (0.02s)205=== CONT TestRateLimiterFeedback206=== RUN TestRateLimiterFeedback/429_enables_limiter207=== PAUSE TestRateLimiterFeedback/429_enables_limiter208=== RUN TestRateLimiterFeedback/503_enables_limiter209=== PAUSE TestRateLimiterFeedback/503_enables_limiter210=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter211=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter212=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter213=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter214=== CONT TestPathInfoCACompatibility215=== RUN TestPathInfoCACompatibility/null_ca_field216=== PAUSE TestPathInfoCACompatibility/null_ca_field217=== RUN TestPathInfoCACompatibility/old_string_format_-_text218=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text219=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive220=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive221=== RUN TestPathInfoCACompatibility/new_structured_format_-_text222=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text223=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method224=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method225=== CONT TestParsePathInfoJSONMultiplePaths226=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths227=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths228=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths229=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths230=== CONT TestGetStorePathHash231=== RUN TestGetStorePathHash/valid_store_path232=== PAUSE TestGetStorePathHash/valid_store_path233=== RUN TestGetStorePathHash/basename_without_hyphen_should_error234=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error235=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error236=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error237=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error238=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error239=== CONT TestPathInfoHashCompatibility240=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)241=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)242=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon243=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon244=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI245=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI246=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512247=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512248=== CONT TestConvertHashToNix32249=== RUN TestConvertHashToNix32/SRI_format_to_Nix32250=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32251=== RUN TestConvertHashToNix32/already_Nix32_format252=== PAUSE TestConvertHashToNix32/already_Nix32_format253=== RUN TestConvertHashToNix32/invalid_format254=== PAUSE TestConvertHashToNix32/invalid_format255=== CONT TestFilterOversizedClosures256=== RUN TestFilterOversizedClosures/no_limit_keeps_everything257=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything258=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped259=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped260=== RUN TestFilterOversizedClosures/all_closures_skipped261=== PAUSE TestFilterOversizedClosures/all_closures_skipped262=== CONT TestCaseHackSuffix263--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)264=== CONT TestStaticToken265--- PASS: TestStaticToken (0.00s)266=== CONT TestSetClientTLSErrors/missing_cert_file267=== CONT TestSetClientTLSErrors/missing_ca_file268=== CONT TestSetClientTLSErrors/invalid_ca_file269=== CONT TestSetClientTLSErrors/missing_key_file270--- PASS: TestSetClientTLSErrors (0.00s)271 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)272 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)273 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)274 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)275=== CONT TestSetClientTLS/rejects_connection_without_client_cert276--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)277=== CONT TestSetClientTLS/preserves_debug_logging_transport278--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)279=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA280=== CONT TestEncodeNixBase32/test_string_hash281=== CONT TestEncodeNixBase32/empty_input282--- PASS: TestEncodeNixBase32 (0.00s)283 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)284 --- PASS: TestEncodeNixBase32/empty_input (0.00s)285=== CONT TestPartSizeForNAR/zero_stays_at_minimum286=== CONT TestUploadMultipart_SupersededByPeer/exists287=== CONT TestPartSizeForNAR/capped_at_5_GiB288=== CONT TestPartSizeForNAR/5_TiB_S3_max_object289=== CONT TestPartSizeForNAR/1_TiB290=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum291=== CONT TestPartSizeForNAR/small_stays_at_minimum292=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts293--- PASS: TestPartSizeForNAR (0.00s)294 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)295 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)296 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)297 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)298 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)299 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)300 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)301=== CONT TestUploadMultipart_SupersededByPeer/missing302=== CONT TestParsePathInfoJSON/Nix_format303=== CONT TestParsePathInfoJSON/invalid_JSON304=== CONT TestParsePathInfoJSON/whitespace_only305=== CONT TestParsePathInfoJSON/empty_input306=== CONT TestParsePathInfoJSON/Lix_format307--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)308 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)309 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)310=== CONT TestRateLimiterFeedback/429_enables_limiter311=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter312--- PASS: TestParsePathInfoJSON (0.00s)313 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)314 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)315 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)316 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)317 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)3182026/09/29 08:15:08 WARN Rate limiter enabled after throttle name=server-test rate=53192026/09/29 08:15:08 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:55682320=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter3212026/09/29 08:15:08 WARN Rate limiter backed off name=server-test rate=5322=== CONT TestRateLimiterFeedback/503_enables_limiter3232026/09/29 08:15:08 WARN Rate limiter enabled after throttle name=server-test rate=53242026/09/29 08:15:08 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:55687325=== CONT TestPathInfoCACompatibility/null_ca_field326=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths327=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method3282026/09/29 08:15:08 WARN Rate limiter backed off name=server-test rate=5329=== CONT TestPathInfoCACompatibility/new_structured_format_-_text330--- PASS: TestRateLimiterFeedback (0.00s)331 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)332 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)333 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)334 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)335=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive336=== CONT TestPathInfoCACompatibility/old_string_format_-_text337=== CONT TestGetStorePathHash/valid_store_path338=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths339--- PASS: TestPathInfoCACompatibility (0.00s)340 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)341 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)342 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)343 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)344 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)345=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)346--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)347 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)348 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)349=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error350=== CONT TestGetStorePathHash/basename_without_hyphen_should_error351=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error352--- PASS: TestGetStorePathHash (0.00s)353 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)354 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)355 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)356 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)357=== CONT TestConvertHashToNix32/SRI_format_to_Nix32358=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512359=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon360=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI361--- PASS: TestPathInfoHashCompatibility (0.00s)362 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)363 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)364 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)365 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)366=== CONT TestConvertHashToNix32/invalid_format367=== CONT TestFilterOversizedClosures/no_limit_keeps_everything368=== CONT TestConvertHashToNix32/already_Nix32_format369=== CONT TestFilterOversizedClosures/all_closures_skipped370--- PASS: TestConvertHashToNix32 (0.00s)371 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)372 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)373 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)374=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3752026/09/29 08:15:08 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=503762026/09/29 08:15:08 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=2000377--- PASS: TestFilterOversizedClosures (0.00s)378 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)379 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)380 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)381--- PASS: TestDumpPathWriterError (0.04s)3822026/09/29 08:15:08 http: TLS handshake error from 127.0.0.1:55674: remote error: tls: bad certificate383--- PASS: TestSetClientTLS (0.01s)384 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)385 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)386 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)387--- PASS: TestDumpPathSingleFile (0.05s)388--- PASS: TestCaseHackSuffix (0.04s)389--- PASS: TestDumpPathMatchesNix (0.07s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestUploadMultipart_PartsInParallel (0.61s)392--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)393PASS394Running server tests...395The files belonging to this database system will be owned by user "_nixbld1".396This user must also own the server process.397398The database cluster will be initialized with locale "C".399The default database encoding has accordingly been set to "SQL_ASCII".400The default text search configuration will be set to "english".401402Data page checksums are enabled.403404creating directory /nix/var/nix/builds/nix-1883-381732109/postgres3615951339/data ... ok405creating subdirectories ... ok406selecting dynamic shared memory implementation ... posix407selecting default "max_connections" ... 100408selecting default "shared_buffers" ... 128MB409selecting default time zone ... UTC410creating configuration files ... ok411running bootstrap script ... ok412performing post-bootstrap initialization ... ok413syncing data to disk ... ok414415initdb: warning: enabling "trust" authentication for local connections416initdb: 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.417418Success. You can now start the database server using:419420 pg_ctl -D /nix/var/nix/builds/nix-1883-381732109/postgres3615951339/data -l logfile start4214222026-09-29 08:15:12.038 UTC [1960] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4232026-09-29 08:15:12.038 UTC [1960] LOG: listening on Unix socket "/nix/var/nix/builds/nix-1883-381732109/postgres3615951339/.s.PGSQL.5432"4242026-09-29 08:15:12.040 UTC [1967] LOG: database system was shut down at 2026-09-29 08:15:12 UTC4252026-09-29 08:15:12.041 UTC [1960] LOG: database system is ready to accept connections426/nix/var/nix/builds/nix-1883-381732109/postgres3615951339:5432 - accepting connections427{"timestamp":"2026-09-29T08:15:14.237116Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"a8c52383-67f1-40ab-bb39-c1f83bdf31fc","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(8)"}428=== RUN TestService_AuthMiddleware429=== PAUSE TestService_AuthMiddleware430=== RUN TestService_AuthMiddleware_MTLSProxyHeader431=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader432=== RUN TestService_AuthMiddleware_MTLSBoundSubjects433=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects434=== RUN TestService_ReadAuthMiddleware435=== PAUSE TestService_ReadAuthMiddleware436=== RUN TestService_AuthMiddleware_OIDC437=== PAUSE TestService_AuthMiddleware_OIDC438=== RUN TestService_RequireScope_OIDC439=== PAUSE TestService_RequireScope_OIDC440=== RUN TestService_ReadScope_PublicByDefault441=== PAUSE TestService_ReadScope_PublicByDefault442=== RUN TestCacheConfigHandler443=== PAUSE TestCacheConfigHandler444=== RUN TestCacheStatsHandler445=== PAUSE TestCacheStatsHandler446=== RUN TestClientCADerivations447=== PAUSE TestClientCADerivations448=== RUN TestClientErrorHandling449=== PAUSE TestClientErrorHandling450=== RUN TestClientIntegration451=== PAUSE TestClientIntegration452=== RUN TestClientMultipleUploads453=== PAUSE TestClientMultipleUploads454=== RUN TestClientWithDependencies455=== PAUSE TestClientWithDependencies456=== RUN TestClientSharedPathCommittedMidPush457=== PAUSE TestClientSharedPathCommittedMidPush458=== RUN TestPinProtectsFromGC459=== PAUSE TestPinProtectsFromGC460=== RUN TestClientPushesUseOnePush461=== PAUSE TestClientPushesUseOnePush462=== RUN TestClientFallsBackToClosures463=== PAUSE TestClientFallsBackToClosures464=== RUN TestResolveDBConnectionString465=== PAUSE TestResolveDBConnectionString466=== RUN TestLeadElectsOneAndHandsOver467=== PAUSE TestLeadElectsOneAndHandsOver468=== RUN TestLeadIncumbentWinsAfterRestart4692026-09-29 08:15:14.619 UTC [1996] ERROR: relation "goose_db_version" does not exist at character 364702026-09-29 08:15:14.619 UTC [1996] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4712026/09/29 08:15:14 OK 20241026095416_initial_model.sql (5.78ms)4722026/09/29 08:15:14 OK 20251210153512_drop_unused_gin_index.sql (630.5µs)4732026/09/29 08:15:14 OK 20251218171726_add_pins.sql (1.16ms)4742026/09/29 08:15:14 OK 20260628120000_add_object_size_and_stats.sql (1.46ms)4752026/09/29 08:15:14 OK 20260905000000_add_claims.sql (1.47ms)4762026/09/29 08:15:14 OK 20260920000000_drop_claims.sql (1.1ms)4772026/09/29 08:15:14 OK 20260923120000_add_pushes.sql (809µs)4782026/09/29 08:15:14 goose: successfully migrated database to version: 202609231200004792026/09/29 08:15:14 OK 1_commit_pending_closure.sql (1.19ms)4802026/09/29 08:15:14 OK 2_object_stats_trigger.sql (279.21µs)4812026/09/29 08:15:14 OK 3_commit_push.sql (299.58µs)4822026/09/29 08:15:14 goose: up to current file version: 34832026/09/29 08:15:14 INFO lead: acquired remote=192.0.2.1:12344842026/09/29 08:15:15 INFO lead: released remote=192.0.2.1:12344852026/09/29 08:15:15 INFO lead: acquired remote=192.0.2.1:12344862026/09/29 08:15:15 INFO lead: released remote=192.0.2.1:1234487--- PASS: TestLeadIncumbentWinsAfterRestart (1.05s)488=== RUN TestLeadEndsOnShutdown489=== PAUSE TestLeadEndsOnShutdown490=== RUN TestGCAdvisoryLockBlocksConcurrentRun4912026-09-29 08:15:15.441 UTC [2000] ERROR: relation "goose_db_version" does not exist at character 364922026-09-29 08:15:15.441 UTC [2000] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4932026/09/29 08:15:15 OK 20241026095416_initial_model.sql (3.45ms)4942026/09/29 08:15:15 OK 20251210153512_drop_unused_gin_index.sql (707.79µs)4952026/09/29 08:15:15 OK 20251218171726_add_pins.sql (891.13µs)4962026/09/29 08:15:15 OK 20260628120000_add_object_size_and_stats.sql (1.01ms)4972026/09/29 08:15:15 OK 20260905000000_add_claims.sql (1.14ms)4982026/09/29 08:15:15 OK 20260920000000_drop_claims.sql (642.54µs)4992026/09/29 08:15:15 OK 20260923120000_add_pushes.sql (421.83µs)5002026/09/29 08:15:15 goose: successfully migrated database to version: 202609231200005012026/09/29 08:15:15 OK 1_commit_pending_closure.sql (962.04µs)5022026/09/29 08:15:15 OK 2_object_stats_trigger.sql (237.5µs)5032026/09/29 08:15:15 OK 3_commit_push.sql (241.21µs)5042026/09/29 08:15:15 goose: up to current file version: 3505--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.15s)506=== RUN TestGCBugBareHashReferences507=== PAUSE TestGCBugBareHashReferences508=== RUN TestGCMetrics509=== PAUSE TestGCMetrics510=== RUN TestGCTaskStore_StartNew511=== PAUSE TestGCTaskStore_StartNew512=== RUN TestGCTaskStore_DeduplicateSameParams513=== PAUSE TestGCTaskStore_DeduplicateSameParams514=== RUN TestGCTaskStore_ConflictDifferentParams515=== PAUSE TestGCTaskStore_ConflictDifferentParams516=== RUN TestGCTaskStore_GetEmpty517=== PAUSE TestGCTaskStore_GetEmpty518=== RUN TestGCTaskStore_GetReturnsLatest519=== PAUSE TestGCTaskStore_GetReturnsLatest520=== RUN TestGCTaskStore_CompletedAllowsNewTask521=== PAUSE TestGCTaskStore_CompletedAllowsNewTask522=== RUN TestGCTaskStore_PhaseUpdates523=== PAUSE TestGCTaskStore_PhaseUpdates524=== RUN TestGCTaskStore_Fail525=== PAUSE TestGCTaskStore_Fail526=== RUN TestGracefulShutdownDrainsInflight527=== PAUSE TestGracefulShutdownDrainsInflight528=== RUN TestService_healthCheckHandler529=== PAUSE TestService_healthCheckHandler530=== RUN TestService_readinessHandler531=== PAUSE TestService_readinessHandler532=== RUN TestGenerateLandingPage533=== PAUSE TestGenerateLandingPage534=== RUN TestCacheConfigHandlerMaxNarSize535=== PAUSE TestCacheConfigHandlerMaxNarSize536=== RUN TestCreatePendingClosureRejectsOversizedNAR537=== PAUSE TestCreatePendingClosureRejectsOversizedNAR538=== RUN TestNARDeduplicationMetadataUploadBug539=== PAUSE TestNARDeduplicationMetadataUploadBug540=== RUN TestMetricsInventory541=== PAUSE TestMetricsInventory542=== RUN TestService_NativeMTLS543=== PAUSE TestService_NativeMTLS544=== RUN TestServerTLSConfig545=== PAUSE TestServerTLSConfig546=== RUN TestMultipartCleanup547=== PAUSE TestMultipartCleanup548=== RUN TestObjectStatsTrigger549=== PAUSE TestObjectStatsTrigger550=== RUN TestOrphanedObjectsGC551=== PAUSE TestOrphanedObjectsGC552=== RUN TestOrphanedObjectsGCStressTest553=== PAUSE TestOrphanedObjectsGCStressTest554=== RUN TestResurrectedObjectNotDeleted555=== PAUSE TestResurrectedObjectNotDeleted556=== RUN TestCreatePin_ReservedPins557=== PAUSE TestCreatePin_ReservedPins558=== RUN TestParseSingleRange559=== PAUSE TestParseSingleRange560=== RUN TestProxyHeadersOnlyTrustedOnSocket561=== PAUSE TestProxyHeadersOnlyTrustedOnSocket562=== RUN TestIsValidCachePath563=== PAUSE TestIsValidCachePath564=== RUN TestReadProxyNarinfo565=== PAUSE TestReadProxyNarinfo566=== RUN TestReadProxyNarinfoAlreadyDecompressed567=== PAUSE TestReadProxyNarinfoAlreadyDecompressed568=== RUN TestReadProxyNarStreaming569=== PAUSE TestReadProxyNarStreaming570=== RUN TestReadProxy404571=== PAUSE TestReadProxy404572=== RUN TestReadProxyInvalidPath573=== PAUSE TestReadProxyInvalidPath574=== RUN TestReadProxyHead575=== PAUSE TestReadProxyHead576=== RUN TestReadProxyConditionalGet577=== PAUSE TestReadProxyConditionalGet578=== RUN TestReadProxyRootRedirectsToIndexHTML579=== PAUSE TestReadProxyRootRedirectsToIndexHTML580=== RUN TestReadProxyDisabled581=== PAUSE TestReadProxyDisabled582=== RUN TestReadRedirectNar583=== PAUSE TestReadRedirectNar584=== RUN TestReadRedirectKeepsNarinfoProxied585=== PAUSE TestReadRedirectKeepsNarinfoProxied586=== RUN TestReadProxyRangeRequest587=== PAUSE TestReadProxyRangeRequest588=== RUN TestReadRedirectUsesPublicS3URL589=== PAUSE TestReadRedirectUsesPublicS3URL590=== RUN TestPush_OverlappingRootsStoreOneRowPerKey591=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey592=== RUN TestPush_CompleteCommitsEveryRoot593=== PAUSE TestPush_CompleteCommitsEveryRoot594=== RUN TestPush_CommitFailsWhenSkippedKeyWasCollected595=== PAUSE TestPush_CommitFailsWhenSkippedKeyWasCollected596=== RUN TestPush_RejectsBadRequests597=== PAUSE TestPush_RejectsBadRequests598=== RUN TestPush_SignsNarinfosOfItsPendingObjects599=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects600=== RUN TestRedundantMultipartUpload601=== PAUSE TestRedundantMultipartUpload602=== RUN TestCompleteMultipartUpload_ErrorButObjectExists603=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists604=== RUN TestCompletedNarNotReofferedAcrossClosures605=== PAUSE TestCompletedNarNotReofferedAcrossClosures606=== RUN TestPresignedUploadRegisteredBeforeCommit607=== PAUSE TestPresignedUploadRegisteredBeforeCommit608=== RUN TestService_Rustfstest609=== PAUSE TestService_Rustfstest610=== RUN TestParseSize611=== PAUSE TestParseSize612=== RUN TestSkippedUploadsHandler613=== PAUSE TestSkippedUploadsHandler614=== RUN TestSystemdListenerNotActivated615--- PASS: TestSystemdListenerNotActivated (0.00s)616=== RUN TestWatchdogBeatsWhenHealthy617--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)618=== RUN TestWatchdogSkipsWhenUnhealthy6192026/09/29 08:15:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6202026/09/29 08:15:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6212026/09/29 08:15:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6222026/09/29 08:15:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6232026/09/29 08:15:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6242026/09/29 08:15:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6252026/09/29 08:15:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6262026/09/29 08:15:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6272026/09/29 08:15:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6282026/09/29 08:15:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"629--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)630=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle631=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle632=== RUN TestProxyWriteTimeout633=== PAUSE TestProxyWriteTimeout634=== RUN TestIsValidUploadKey635=== PAUSE TestIsValidUploadKey636=== RUN TestUploadHandlersRejectInvalidKeys637=== PAUSE TestUploadHandlersRejectInvalidKeys638=== RUN TestUploadHandlersRejectOversizedBody639=== PAUSE TestUploadHandlersRejectOversizedBody640=== RUN TestService_cleanupPendingClosuresHandler641=== PAUSE TestService_cleanupPendingClosuresHandler642=== RUN TestService_createPendingClosureHandler643=== PAUSE TestService_createPendingClosureHandler644=== RUN TestService_verifyS3Integrity645=== PAUSE TestService_verifyS3Integrity646=== RUN TestCompleteMultipartUnregistered647=== PAUSE TestCompleteMultipartUnregistered648=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT649=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT650=== CONT TestService_AuthMiddleware651=== CONT TestOrphanedObjectsGC652=== CONT TestPush_CompleteCommitsEveryRoot653=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT654=== CONT TestCompleteMultipartUnregistered655=== CONT TestService_verifyS3Integrity656=== CONT TestService_createPendingClosureHandler657=== CONT TestService_cleanupPendingClosuresHandler658=== CONT TestUploadHandlersRejectOversizedBody659=== CONT TestUploadHandlersRejectInvalidKeys660=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info661=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info662=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal663=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal664=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key665=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key666=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key667=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key668=== CONT TestIsValidUploadKey669=== RUN TestIsValidUploadKey/narinfo670=== PAUSE TestIsValidUploadKey/narinfo671=== RUN TestIsValidUploadKey/nar_zst672=== PAUSE TestIsValidUploadKey/nar_zst673=== RUN TestIsValidUploadKey/nar_xz674=== PAUSE TestIsValidUploadKey/nar_xz675=== RUN TestIsValidUploadKey/nar_plain676=== PAUSE TestIsValidUploadKey/nar_plain677=== RUN TestIsValidUploadKey/listing678=== PAUSE TestIsValidUploadKey/listing679=== RUN TestIsValidUploadKey/build_log680=== PAUSE TestIsValidUploadKey/build_log681=== RUN TestIsValidUploadKey/build_log_home-manager_file682=== PAUSE TestIsValidUploadKey/build_log_home-manager_file683=== RUN TestIsValidUploadKey/build_log_plus_in_name684=== PAUSE TestIsValidUploadKey/build_log_plus_in_name685=== RUN TestIsValidUploadKey/build_log_question_mark686=== PAUSE TestIsValidUploadKey/build_log_question_mark687=== RUN TestIsValidUploadKey/build_log_equals688=== PAUSE TestIsValidUploadKey/build_log_equals689=== RUN TestIsValidUploadKey/realisation690=== PAUSE TestIsValidUploadKey/realisation691=== RUN TestIsValidUploadKey/realisation_plus_in_output692=== PAUSE TestIsValidUploadKey/realisation_plus_in_output693=== RUN TestIsValidUploadKey/nix-cache-info694=== PAUSE TestIsValidUploadKey/nix-cache-info695=== RUN TestIsValidUploadKey/index.html696=== PAUSE TestIsValidUploadKey/index.html697=== RUN TestIsValidUploadKey/narinfo_key,_nar_type698=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type699=== RUN TestIsValidUploadKey/nar_key,_narinfo_type700=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type701=== RUN TestIsValidUploadKey/listing_key,_narinfo_type702=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type703=== RUN TestIsValidUploadKey/traversal704=== PAUSE TestIsValidUploadKey/traversal705=== RUN TestIsValidUploadKey/traversal_nar706=== PAUSE TestIsValidUploadKey/traversal_nar707=== RUN TestIsValidUploadKey/absolute708=== PAUSE TestIsValidUploadKey/absolute709=== RUN TestIsValidUploadKey/empty_key710=== PAUSE TestIsValidUploadKey/empty_key711=== RUN TestIsValidUploadKey/unknown_type712=== PAUSE TestIsValidUploadKey/unknown_type713=== CONT TestProxyWriteTimeout714=== RUN TestProxyWriteTimeout/narinfo715=== PAUSE TestProxyWriteTimeout/narinfo716=== RUN TestProxyWriteTimeout/1_GiB_nar717=== PAUSE TestProxyWriteTimeout/1_GiB_nar718=== RUN TestProxyWriteTimeout/10_GiB_nar719=== PAUSE TestProxyWriteTimeout/10_GiB_nar720=== RUN TestProxyWriteTimeout/unknown_size721=== PAUSE TestProxyWriteTimeout/unknown_size722=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle723=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure724=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure725=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart726=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart727=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts728=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts729=== CONT TestSkippedUploadsHandler7302026/09/29 08:15:15 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000731--- PASS: TestSkippedUploadsHandler (0.00s)732=== CONT TestParseSize733--- PASS: TestParseSize (0.00s)734=== CONT TestService_Rustfstest7352026-09-29 08:15:16.044 UTC [2022] ERROR: relation "goose_db_version" does not exist at character 367362026-09-29 08:15:16.044 UTC [2022] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7372026/09/29 08:15:16 OK 20241026095416_initial_model.sql (13.52ms)7382026/09/29 08:15:16 OK 20251210153512_drop_unused_gin_index.sql (9.23ms)7392026-09-29 08:15:16.080 UTC [2023] ERROR: relation "goose_db_version" does not exist at character 367402026-09-29 08:15:16.080 UTC [2023] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7412026/09/29 08:15:16 OK 20251218171726_add_pins.sql (5.96ms)7422026-09-29 08:15:16.087 UTC [2024] ERROR: relation "goose_db_version" does not exist at character 367432026-09-29 08:15:16.087 UTC [2024] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7442026/09/29 08:15:16 OK 20260628120000_add_object_size_and_stats.sql (3.31ms)7452026/09/29 08:15:16 OK 20260905000000_add_claims.sql (3.8ms)7462026-09-29 08:15:16.094 UTC [2025] ERROR: relation "goose_db_version" does not exist at character 367472026-09-29 08:15:16.094 UTC [2025] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7482026/09/29 08:15:16 OK 20260920000000_drop_claims.sql (2.57ms)7492026-09-29 08:15:16.097 UTC [2026] ERROR: relation "goose_db_version" does not exist at character 367502026-09-29 08:15:16.097 UTC [2026] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7512026-09-29 08:15:16.097 UTC [2028] ERROR: relation "goose_db_version" does not exist at character 367522026-09-29 08:15:16.097 UTC [2028] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7532026-09-29 08:15:16.097 UTC [2027] ERROR: relation "goose_db_version" does not exist at character 367542026-09-29 08:15:16.097 UTC [2027] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7552026/09/29 08:15:16 OK 20260923120000_add_pushes.sql (2.25ms)7562026/09/29 08:15:16 goose: successfully migrated database to version: 202609231200007572026-09-29 08:15:16.099 UTC [2029] ERROR: relation "goose_db_version" does not exist at character 367582026-09-29 08:15:16.099 UTC [2029] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7592026/09/29 08:15:16 OK 20241026095416_initial_model.sql (11.34ms)7602026/09/29 08:15:16 OK 1_commit_pending_closure.sql (1.96ms)7612026-09-29 08:15:16.100 UTC [2031] ERROR: relation "goose_db_version" does not exist at character 367622026-09-29 08:15:16.100 UTC [2031] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7632026/09/29 08:15:16 OK 20251210153512_drop_unused_gin_index.sql (1.36ms)7642026-09-29 08:15:16.101 UTC [2030] ERROR: relation "goose_db_version" does not exist at character 367652026-09-29 08:15:16.101 UTC [2030] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7662026/09/29 08:15:16 OK 2_object_stats_trigger.sql (716.38µs)7672026/09/29 08:15:16 OK 3_commit_push.sql (731.96µs)7682026/09/29 08:15:16 goose: up to current file version: 37692026/09/29 08:15:16 OK 20241026095416_initial_model.sql (8.57ms)7702026/09/29 08:15:16 OK 20251218171726_add_pins.sql (1.97ms)7712026/09/29 08:15:16 OK 20251210153512_drop_unused_gin_index.sql (1.36ms)7722026/09/29 08:15:16 OK 20260628120000_add_object_size_and_stats.sql (2.61ms)7732026/09/29 08:15:16 OK 20251218171726_add_pins.sql (2.84ms)7742026/09/29 08:15:16 OK 20241026095416_initial_model.sql (6.01ms)7752026/09/29 08:15:16 OK 20241026095416_initial_model.sql (7.7ms)7762026/09/29 08:15:16 OK 20260905000000_add_claims.sql (14.52ms)7772026/09/29 08:15:16 OK 20251210153512_drop_unused_gin_index.sql (33.65ms)7782026/09/29 08:15:16 OK 20251210153512_drop_unused_gin_index.sql (33.71ms)7792026/09/29 08:15:16 OK 20241026095416_initial_model.sql (47.17ms)7802026/09/29 08:15:16 OK 20260628120000_add_object_size_and_stats.sql (40.7ms)7812026/09/29 08:15:16 OK 20260920000000_drop_claims.sql (28.27ms)7822026/09/29 08:15:16 OK 20251218171726_add_pins.sql (7.44ms)7832026/09/29 08:15:16 OK 20251210153512_drop_unused_gin_index.sql (7.05ms)7842026/09/29 08:15:16 OK 20251218171726_add_pins.sql (15.58ms)7852026/09/29 08:15:16 OK 20260923120000_add_pushes.sql (9.29ms)7862026/09/29 08:15:16 goose: successfully migrated database to version: 202609231200007872026/09/29 08:15:16 OK 1_commit_pending_closure.sql (862.96µs)7882026/09/29 08:15:16 OK 2_object_stats_trigger.sql (186.5µs)7892026/09/29 08:15:16 OK 3_commit_push.sql (171.25µs)7902026/09/29 08:15:16 goose: up to current file version: 37912026/09/29 08:15:16 OK 20241026095416_initial_model.sql (64.61ms)7922026/09/29 08:15:16 OK 20251210153512_drop_unused_gin_index.sql (837.42µs)7932026/09/29 08:15:16 OK 20260628120000_add_object_size_and_stats.sql (17.49ms)7942026/09/29 08:15:16 OK 20251218171726_add_pins.sql (11.58ms)7952026/09/29 08:15:16 OK 20241026095416_initial_model.sql (63.34ms)7962026/09/29 08:15:16 OK 20260628120000_add_object_size_and_stats.sql (10.36ms)7972026/09/29 08:15:16 OK 20260905000000_add_claims.sql (19.24ms)7982026/09/29 08:15:16 OK 20251218171726_add_pins.sql (1.53ms)7992026/09/29 08:15:16 OK 20251210153512_drop_unused_gin_index.sql (1.14ms)8002026/09/29 08:15:16 OK 20241026095416_initial_model.sql (65.17ms)8012026/09/29 08:15:16 OK 20260628120000_add_object_size_and_stats.sql (8.18ms)8022026/09/29 08:15:16 OK 20251210153512_drop_unused_gin_index.sql (6.65ms)8032026/09/29 08:15:16 OK 20260920000000_drop_claims.sql (9.11ms)8042026/09/29 08:15:16 OK 20260628120000_add_object_size_and_stats.sql (8.85ms)8052026/09/29 08:15:16 OK 20251218171726_add_pins.sql (8.42ms)8062026/09/29 08:15:16 OK 20241026095416_initial_model.sql (71.32ms)8072026/09/29 08:15:16 OK 20260905000000_add_claims.sql (18.5ms)8082026/09/29 08:15:16 OK 20260923120000_add_pushes.sql (8.47ms)8092026/09/29 08:15:16 goose: successfully migrated database to version: 202609231200008102026/09/29 08:15:16 OK 20260905000000_add_claims.sql (17.86ms)8112026/09/29 08:15:16 OK 20251210153512_drop_unused_gin_index.sql (8.33ms)8122026/09/29 08:15:16 OK 20260628120000_add_object_size_and_stats.sql (9.64ms)8132026/09/29 08:15:16 OK 20251218171726_add_pins.sql (10.1ms)8142026/09/29 08:15:16 OK 1_commit_pending_closure.sql (1.46ms)8152026/09/29 08:15:16 OK 2_object_stats_trigger.sql (225.96µs)8162026/09/29 08:15:16 OK 3_commit_push.sql (191.54µs)8172026/09/29 08:15:16 goose: up to current file version: 38182026/09/29 08:15:16 OK 20260905000000_add_claims.sql (18.96ms)8192026/09/29 08:15:16 OK 20260920000000_drop_claims.sql (10.94ms)8202026/09/29 08:15:16 OK 20260920000000_drop_claims.sql (10.56ms)8212026/09/29 08:15:16 OK 20251218171726_add_pins.sql (11.08ms)8222026/09/29 08:15:16 OK 20260628120000_add_object_size_and_stats.sql (17.39ms)8232026/09/29 08:15:16 OK 20260905000000_add_claims.sql (27.36ms)8242026/09/29 08:15:16 OK 20260923120000_add_pushes.sql (8.3ms)8252026/09/29 08:15:16 goose: successfully migrated database to version: 202609231200008262026/09/29 08:15:16 OK 20260923120000_add_pushes.sql (8.3ms)8272026/09/29 08:15:16 goose: successfully migrated database to version: 202609231200008282026/09/29 08:15:16 OK 20260905000000_add_claims.sql (17.88ms)8292026/09/29 08:15:16 OK 20260920000000_drop_claims.sql (10.47ms)8302026/09/29 08:15:16 OK 1_commit_pending_closure.sql (1.02ms)8312026/09/29 08:15:16 OK 1_commit_pending_closure.sql (1.3ms)8322026/09/29 08:15:16 OK 2_object_stats_trigger.sql (422.17µs)8332026/09/29 08:15:16 OK 20260628120000_add_object_size_and_stats.sql (9.34ms)8342026/09/29 08:15:16 OK 3_commit_push.sql (226.75µs)8352026/09/29 08:15:16 goose: up to current file version: 38362026/09/29 08:15:16 OK 2_object_stats_trigger.sql (371.25µs)8372026/09/29 08:15:16 OK 3_commit_push.sql (196.63µs)8382026/09/29 08:15:16 goose: up to current file version: 38392026/09/29 08:15:16 OK 20260923120000_add_pushes.sql (6.09ms)8402026/09/29 08:15:16 goose: successfully migrated database to version: 202609231200008412026/09/29 08:15:16 OK 20260920000000_drop_claims.sql (7.28ms)8422026/09/29 08:15:16 OK 20260920000000_drop_claims.sql (7.07ms)8432026/09/29 08:15:16 OK 1_commit_pending_closure.sql (1.13ms)8442026/09/29 08:15:16 OK 2_object_stats_trigger.sql (220.79µs)8452026/09/29 08:15:16 OK 3_commit_push.sql (191.92µs)8462026/09/29 08:15:16 goose: up to current file version: 38472026/09/29 08:15:16 OK 20260905000000_add_claims.sql (14.11ms)8482026/09/29 08:15:16 OK 20260923120000_add_pushes.sql (14.34ms)8492026/09/29 08:15:16 goose: successfully migrated database to version: 202609231200008502026/09/29 08:15:16 OK 20260923120000_add_pushes.sql (14.47ms)8512026/09/29 08:15:16 goose: successfully migrated database to version: 202609231200008522026/09/29 08:15:16 OK 1_commit_pending_closure.sql (900.88µs)8532026/09/29 08:15:16 OK 1_commit_pending_closure.sql (933.04µs)8542026/09/29 08:15:16 OK 2_object_stats_trigger.sql (214.5µs)8552026/09/29 08:15:16 OK 2_object_stats_trigger.sql (217.71µs)8562026/09/29 08:15:16 OK 3_commit_push.sql (196.21µs)8572026/09/29 08:15:16 goose: up to current file version: 38582026/09/29 08:15:16 OK 3_commit_push.sql (219.42µs)8592026/09/29 08:15:16 goose: up to current file version: 38602026/09/29 08:15:16 OK 20260920000000_drop_claims.sql (14.34ms)8612026/09/29 08:15:16 OK 20260905000000_add_claims.sql (30.26ms)8622026/09/29 08:15:16 OK 20260923120000_add_pushes.sql (3.97ms)8632026/09/29 08:15:16 goose: successfully migrated database to version: 202609231200008642026/09/29 08:15:16 OK 1_commit_pending_closure.sql (1.03ms)8652026/09/29 08:15:16 OK 2_object_stats_trigger.sql (230.33µs)8662026/09/29 08:15:16 OK 3_commit_push.sql (218.92µs)8672026/09/29 08:15:16 goose: up to current file version: 38682026/09/29 08:15:16 OK 20260920000000_drop_claims.sql (8.01ms)8692026/09/29 08:15:16 OK 20260923120000_add_pushes.sql (4.56ms)8702026/09/29 08:15:16 goose: successfully migrated database to version: 202609231200008712026/09/29 08:15:16 OK 1_commit_pending_closure.sql (1.01ms)8722026/09/29 08:15:16 OK 2_object_stats_trigger.sql (256.13µs)8732026/09/29 08:15:16 OK 3_commit_push.sql (247.46µs)8742026/09/29 08:15:16 goose: up to current file version: 38752026/09/29 08:15:16 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"876--- PASS: TestService_AuthMiddleware (0.49s)877=== CONT TestPresignedUploadRegisteredBeforeCommit8782026/09/29 08:15:16 INFO Received uploads request method=POST path=/api/pending_closures879--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.68s)880=== CONT TestCompletedNarNotReofferedAcrossClosures8812026/09/29 08:15:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8822026/09/29 08:15:16 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst883--- PASS: TestCompleteMultipartUnregistered (0.80s)884=== CONT TestCompleteMultipartUpload_ErrorButObjectExists8852026/09/29 08:15:16 INFO Received uploads request method=POST path=/api/pending_closures8862026/09/29 08:15:16 INFO Received cleanup request method=DELETE path=/api/pending_closures8872026/09/29 08:15:16 INFO Aborted multipart uploads count=08882026/09/29 08:15:16 INFO Received uploads request method=POST path=/api/pending_closures8892026/09/29 08:15:17 INFO Received cleanup request method=DELETE path=/api/pending_closures8902026/09/29 08:15:17 INFO Aborted multipart uploads count=18912026/09/29 08:15:17 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8922026-09-29 08:15:17.087 UTC [2027] ERROR: Closure does not exist: id=18932026-09-29 08:15:17.087 UTC [2027] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE8942026-09-29 08:15:17.087 UTC [2027] STATEMENT: -- name: CommitPendingClosure :exec895 SELECT commit_pending_closure($1::bigint)896 897--- PASS: TestService_cleanupPendingClosuresHandler (1.31s)898=== CONT TestRedundantMultipartUpload8992026-09-29 08:15:17.218 UTC [2058] ERROR: relation "goose_db_version" does not exist at character 369002026-09-29 08:15:17.218 UTC [2058] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9012026/09/29 08:15:17 INFO Received uploads request method=POST path=/api/pending_closures9022026/09/29 08:15:17 INFO Received uploads request method=POST path=/api/pending_closures9032026/09/29 08:15:17 INFO Received uploads request method=POST path=/api/pending_closures9042026/09/29 08:15:17 OK 20241026095416_initial_model.sql (113.6ms)9052026/09/29 08:15:17 OK 20251210153512_drop_unused_gin_index.sql (15.11ms)9062026/09/29 08:15:17 OK 20251218171726_add_pins.sql (30.01ms)9072026/09/29 08:15:17 OK 20260628120000_add_object_size_and_stats.sql (33.61ms)9082026-09-29 08:15:17.506 UTC [2059] ERROR: relation "goose_db_version" does not exist at character 369092026-09-29 08:15:17.506 UTC [2059] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9102026/09/29 08:15:17 OK 20260905000000_add_claims.sql (44.88ms)9112026/09/29 08:15:17 INFO Received push request method=POST path=/api/pushes9122026/09/29 08:15:17 OK 20260920000000_drop_claims.sql (28.11ms)9132026/09/29 08:15:17 OK 20260923120000_add_pushes.sql (18.24ms)9142026/09/29 08:15:17 goose: successfully migrated database to version: 202609231200009152026/09/29 08:15:17 OK 1_commit_pending_closure.sql (2.2ms)9162026/09/29 08:15:17 OK 2_object_stats_trigger.sql (515.58µs)9172026/09/29 08:15:17 OK 3_commit_push.sql (468.17µs)9182026/09/29 08:15:17 goose: up to current file version: 39192026/09/29 08:15:17 INFO Received complete push request method=POST path=/api/pushes/1/complete920--- PASS: TestPush_CompleteCommitsEveryRoot (1.85s)921=== CONT TestPush_SignsNarinfosOfItsPendingObjects9222026/09/29 08:15:17 OK 20241026095416_initial_model.sql (164.33ms)9232026/09/29 08:15:17 OK 20251210153512_drop_unused_gin_index.sql (12.35ms)9242026/09/29 08:15:17 OK 20251218171726_add_pins.sql (13.77ms)9252026-09-29 08:15:17.773 UTC [2064] ERROR: relation "goose_db_version" does not exist at character 369262026-09-29 08:15:17.773 UTC [2064] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9272026/09/29 08:15:17 OK 20260628120000_add_object_size_and_stats.sql (23.09ms)9282026/09/29 08:15:17 OK 20260905000000_add_claims.sql (68.02ms)9292026/09/29 08:15:17 OK 20260920000000_drop_claims.sql (34.11ms)9302026/09/29 08:15:17 OK 20260923120000_add_pushes.sql (14.24ms)9312026/09/29 08:15:17 goose: successfully migrated database to version: 202609231200009322026/09/29 08:15:17 OK 1_commit_pending_closure.sql (1.66ms)9332026/09/29 08:15:17 OK 2_object_stats_trigger.sql (350.33µs)9342026/09/29 08:15:17 OK 3_commit_push.sql (297.92µs)9352026/09/29 08:15:17 goose: up to current file version: 3936--- PASS: TestService_Rustfstest (2.26s)937=== CONT TestPush_RejectsBadRequests9382026/09/29 08:15:18 OK 20241026095416_initial_model.sql (247.71ms)9392026/09/29 08:15:18 OK 20251210153512_drop_unused_gin_index.sql (15.77ms)9402026/09/29 08:15:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9412026/09/29 08:15:18 OK 20251218171726_add_pins.sql (52.63ms)9422026/09/29 08:15:18 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YzZkNjU0NWEtOTBhZC00OWYxLWI2ZmEtNjVlZmE5M2I1MGU2LmM1MGM2NmE2LWVmZmMtNDBmYy05OTZhLTUwYmJiNGE1OTc1NHgxNzkwNjY5NzE2ODA0MTMxMDAw parts=109432026/09/29 08:15:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9442026/09/29 08:15:18 INFO Completed upload id=19452026/09/29 08:15:18 INFO Received uploads request method=POST path=/api/pending_closures9462026/09/29 08:15:18 INFO Received uploads request method=POST path=/api/pending_closures9472026/09/29 08:15:18 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9482026/09/29 08:15:18 WARN Found objects in DB but missing from S3, will re-upload count=1949--- PASS: TestService_verifyS3Integrity (2.41s)950=== CONT TestPush_CommitFailsWhenSkippedKeyWasCollected9512026/09/29 08:15:18 OK 20260628120000_add_object_size_and_stats.sql (36.03ms)9522026/09/29 08:15:18 OK 20260905000000_add_claims.sql (63.06ms)9532026/09/29 08:15:18 OK 20260920000000_drop_claims.sql (17.42ms)9542026/09/29 08:15:18 OK 20260923120000_add_pushes.sql (15.55ms)9552026/09/29 08:15:18 goose: successfully migrated database to version: 202609231200009562026/09/29 08:15:18 OK 1_commit_pending_closure.sql (2.49ms)9572026/09/29 08:15:18 OK 2_object_stats_trigger.sql (811.04µs)9582026/09/29 08:15:18 OK 3_commit_push.sql (505.83µs)9592026/09/29 08:15:18 goose: up to current file version: 39602026/09/29 08:15:18 INFO Received uploads request method=POST path=/api/pending_closures961=== NAME TestOrphanedObjectsGC962 orphaned_objects_gc_test.go:290: GC Test Summary:963 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A964 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B965 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)966 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)967 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects968--- PASS: TestOrphanedObjectsGC (2.73s)969=== CONT TestGCMetrics9702026/09/29 08:15:18 INFO Received uploads request method=POST path=/api/pending_closures9712026/09/29 08:15:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9722026/09/29 08:15:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9732026-09-29 08:15:18.706 UTC [2080] ERROR: relation "goose_db_version" does not exist at character 369742026-09-29 08:15:18.706 UTC [2080] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9752026/09/29 08:15:18 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9762026/09/29 08:15:18 INFO Received uploads request method=POST path=/api/pending_closures977--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.44s)978=== CONT TestObjectStatsTrigger9792026/09/29 08:15:18 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YzZkNjU0NWEtOTBhZC00OWYxLWI2ZmEtNjVlZmE5M2I1MGU2LjAzNGUxZmZiLWNjM2QtNDU3YS04MDI0LTc3NmFjN2QwMmE0YngxNzkwNjY5NzE3MjgzNjkyMDAw parts=109802026/09/29 08:15:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9812026/09/29 08:15:18 INFO Completed upload id=19822026/09/29 08:15:18 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009832026/09/29 08:15:18 INFO Received uploads request method=POST path=/api/pending_closures9842026/09/29 08:15:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures9852026/09/29 08:15:18 INFO Aborted multipart uploads count=09862026/09/29 08:15:18 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=0 objects-failed-to-delete=09872026/09/29 08:15:18 INFO Vacuumed table table=pending_closures9882026/09/29 08:15:18 INFO Vacuumed table table=pending_objects9892026/09/29 08:15:18 INFO Vacuumed table table=multipart_uploads9902026/09/29 08:15:18 INFO Vacuumed table table=closures9912026/09/29 08:15:18 INFO Vacuumed table table=objects9922026/09/29 08:15:18 OK 20241026095416_initial_model.sql (105.12ms)9932026/09/29 08:15:18 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000994--- PASS: TestService_createPendingClosureHandler (3.11s)995=== CONT TestMultipartCleanup9962026/09/29 08:15:18 OK 20251210153512_drop_unused_gin_index.sql (10.78ms)9972026/09/29 08:15:18 INFO Received uploads request method=POST path=/api/pending_closures9982026/09/29 08:15:18 OK 20251218171726_add_pins.sql (36.41ms)9992026/09/29 08:15:18 OK 20260628120000_add_object_size_and_stats.sql (23.49ms)10002026/09/29 08:15:18 OK 20260905000000_add_claims.sql (26.21ms)10012026/09/29 08:15:19 OK 20260920000000_drop_claims.sql (26.21ms)10022026/09/29 08:15:19 OK 20260923120000_add_pushes.sql (13.1ms)10032026/09/29 08:15:19 goose: successfully migrated database to version: 2026092312000010042026/09/29 08:15:19 OK 1_commit_pending_closure.sql (1.73ms)10052026/09/29 08:15:19 OK 2_object_stats_trigger.sql (409.29µs)10062026/09/29 08:15:19 OK 3_commit_push.sql (357.38µs)10072026/09/29 08:15:19 goose: up to current file version: 310082026/09/29 08:15:19 INFO Received uploads request method=POST path=/api/pending_closures10092026/09/29 08:15:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10102026/09/29 08:15:19 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YzZkNjU0NWEtOTBhZC00OWYxLWI2ZmEtNjVlZmE5M2I1MGU2LmM4M2Q5MDAwLTU0YWEtNDk4ZS04MGNhLWM2MTg5ODdlZWQzZXgxNzkwNjY5NzE5MTE4MTY5MDAw10112026/09/29 08:15:19 INFO Received uploads request method=POST path=/api/pending_closures10122026/09/29 08:15:19 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YzZkNjU0NWEtOTBhZC00OWYxLWI2ZmEtNjVlZmE5M2I1MGU2LmM4M2Q5MDAwLTU0YWEtNDk4ZS04MGNhLWM2MTg5ODdlZWQzZXgxNzkwNjY5NzE5MTE4MTY5MDAw parts=11013--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.82s)1014=== CONT TestServerTLSConfig1015=== RUN TestServerTLSConfig/no_client_CA1016=== PAUSE TestServerTLSConfig/no_client_CA1017=== RUN TestServerTLSConfig/missing_CA_file1018=== PAUSE TestServerTLSConfig/missing_CA_file1019=== RUN TestServerTLSConfig/not_a_PEM_file1020=== PAUSE TestServerTLSConfig/not_a_PEM_file1021=== CONT TestService_NativeMTLS10222026/09/29 08:15:19 INFO Received uploads request method=POST path=/api/pending_closures10232026-09-29 08:15:19.460 UTC [2088] ERROR: relation "goose_db_version" does not exist at character 3610242026-09-29 08:15:19.460 UTC [2088] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10252026/09/29 08:15:19 OK 20241026095416_initial_model.sql (126.1ms)10262026/09/29 08:15:19 OK 20251210153512_drop_unused_gin_index.sql (6.03ms)10272026-09-29 08:15:19.632 UTC [2089] ERROR: relation "goose_db_version" does not exist at character 3610282026-09-29 08:15:19.632 UTC [2089] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10292026-09-29 08:15:19.642 UTC [2090] ERROR: relation "goose_db_version" does not exist at character 3610302026-09-29 08:15:19.642 UTC [2090] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10312026/09/29 08:15:19 OK 20251218171726_add_pins.sql (11.58ms)10322026/09/29 08:15:19 OK 20260628120000_add_object_size_and_stats.sql (9.94ms)10332026/09/29 08:15:19 OK 20260905000000_add_claims.sql (2.99ms)10342026/09/29 08:15:19 OK 20260920000000_drop_claims.sql (2.34ms)10352026/09/29 08:15:19 OK 20260923120000_add_pushes.sql (910.63µs)10362026/09/29 08:15:19 goose: successfully migrated database to version: 2026092312000010372026/09/29 08:15:19 OK 1_commit_pending_closure.sql (1.5ms)10382026/09/29 08:15:19 OK 2_object_stats_trigger.sql (317.88µs)10392026/09/29 08:15:19 OK 3_commit_push.sql (285.13µs)10402026/09/29 08:15:19 goose: up to current file version: 310412026/09/29 08:15:19 OK 20241026095416_initial_model.sql (106.57ms)10422026/09/29 08:15:19 OK 20241026095416_initial_model.sql (113.75ms)10432026/09/29 08:15:19 OK 20251210153512_drop_unused_gin_index.sql (14.68ms)10442026/09/29 08:15:19 OK 20251210153512_drop_unused_gin_index.sql (8.16ms)10452026/09/29 08:15:19 OK 20251218171726_add_pins.sql (4.16ms)10462026/09/29 08:15:19 OK 20251218171726_add_pins.sql (10.56ms)10472026/09/29 08:15:19 OK 20260628120000_add_object_size_and_stats.sql (37.65ms)10482026/09/29 08:15:19 OK 20260628120000_add_object_size_and_stats.sql (41.3ms)10492026/09/29 08:15:19 OK 20260905000000_add_claims.sql (72.68ms)10502026/09/29 08:15:19 OK 20260905000000_add_claims.sql (60.43ms)10512026/09/29 08:15:19 OK 20260920000000_drop_claims.sql (17.17ms)10522026/09/29 08:15:19 OK 20260920000000_drop_claims.sql (17.23ms)10532026/09/29 08:15:19 OK 20260923120000_add_pushes.sql (16.36ms)10542026/09/29 08:15:19 goose: successfully migrated database to version: 2026092312000010552026/09/29 08:15:19 OK 1_commit_pending_closure.sql (2.32ms)10562026/09/29 08:15:19 OK 2_object_stats_trigger.sql (498.5µs)10572026/09/29 08:15:19 OK 3_commit_push.sql (399.5µs)10582026/09/29 08:15:19 goose: up to current file version: 310592026/09/29 08:15:19 OK 20260923120000_add_pushes.sql (25.24ms)10602026/09/29 08:15:19 goose: successfully migrated database to version: 2026092312000010612026/09/29 08:15:19 INFO Received push request method=POST path=/api/pushes10622026-09-29 08:15:19.934 UTC [2091] ERROR: relation "goose_db_version" does not exist at character 3610632026-09-29 08:15:19.934 UTC [2091] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10642026/09/29 08:15:19 OK 1_commit_pending_closure.sql (4.22ms)10652026/09/29 08:15:19 OK 2_object_stats_trigger.sql (1.93ms)10662026/09/29 08:15:19 OK 3_commit_push.sql (566.08µs)10672026/09/29 08:15:19 goose: up to current file version: 310682026/09/29 08:15:20 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10692026/09/29 08:15:20 INFO Signed narinfos id=1 count=11070--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (2.40s)1071=== CONT TestMetricsInventory10722026/09/29 08:15:20 OK 20241026095416_initial_model.sql (138.22ms)10732026/09/29 08:15:20 OK 20251210153512_drop_unused_gin_index.sql (13.21ms)10742026/09/29 08:15:20 OK 20251218171726_add_pins.sql (23.1ms)10752026/09/29 08:15:20 OK 20260628120000_add_object_size_and_stats.sql (27.88ms)10762026/09/29 08:15:20 INFO Received push request method=POST path=/api/pushes10772026/09/29 08:15:20 OK 20260905000000_add_claims.sql (83ms)10782026/09/29 08:15:20 INFO Received complete push request method=POST path=/api/pushes/1/complete10792026/09/29 08:15:20 OK 20260920000000_drop_claims.sql (21.96ms)10802026-09-29 08:15:20.326 UTC [2094] ERROR: relation "goose_db_version" does not exist at character 3610812026-09-29 08:15:20.326 UTC [2094] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10822026/09/29 08:15:20 OK 20260923120000_add_pushes.sql (13.49ms)10832026/09/29 08:15:20 goose: successfully migrated database to version: 2026092312000010842026/09/29 08:15:20 INFO Received push request method=POST path=/api/pushes10852026/09/29 08:15:20 OK 1_commit_pending_closure.sql (4.37ms)10862026/09/29 08:15:20 OK 2_object_stats_trigger.sql (811.17µs)10872026/09/29 08:15:20 OK 3_commit_push.sql (556.13µs)10882026/09/29 08:15:20 goose: up to current file version: 310892026-09-29 08:15:20.374 UTC [2096] ERROR: relation "goose_db_version" does not exist at character 3610902026-09-29 08:15:20.374 UTC [2096] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10912026/09/29 08:15:20 INFO Received complete push request method=POST path=/api/pushes/2/complete10922026-09-29 08:15:20.405 UTC [2095] ERROR: Push object missing: aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo10932026-09-29 08:15:20.405 UTC [2095] CONTEXT: PL/pgSQL function commit_push(bigint) line 37 at RAISE10942026-09-29 08:15:20.405 UTC [2095] STATEMENT: -- name: CommitPush :exec1095 SELECT commit_push($1::bigint)1096 1097--- PASS: TestPush_CommitFailsWhenSkippedKeyWasCollected (2.22s)1098=== CONT TestNARDeduplicationMetadataUploadBug10992026/09/29 08:15:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11002026/09/29 08:15:20 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YzZkNjU0NWEtOTBhZC00OWYxLWI2ZmEtNjVlZmE5M2I1MGU2LjMzODJmZTdhLTFhMjktNDhkOS04MGFhLWJjMjIwZGQyNDRmNHgxNzkwNjY5NzE4OTI2NDc5MDAw parts=121101=== RUN TestPush_RejectsBadRequests/root_not_in_objects1102=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1103=== RUN TestPush_RejectsBadRequests/no_roots1104=== PAUSE TestPush_RejectsBadRequests/no_roots1105=== RUN TestPush_RejectsBadRequests/no_objects1106=== PAUSE TestPush_RejectsBadRequests/no_objects1107=== RUN TestPush_RejectsBadRequests/bad_root1108=== PAUSE TestPush_RejectsBadRequests/bad_root1109=== CONT TestCreatePendingClosureRejectsOversizedNAR11102026/09/29 08:15:20 INFO Received uploads request method=POST path=/api/pending_closures1111--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1112=== CONT TestCacheConfigHandlerMaxNarSize1113--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1114=== CONT TestGenerateLandingPage11152026/09/29 08:15:20 INFO Received uploads request method=POST path=/api/pending_closures1116--- PASS: TestGenerateLandingPage (0.00s)1117=== CONT TestService_readinessHandler1118--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.09s)1119=== CONT TestService_healthCheckHandler11202026/09/29 08:15:20 OK 20241026095416_initial_model.sql (183.81ms)11212026/09/29 08:15:20 OK 20251210153512_drop_unused_gin_index.sql (1.53ms)11222026/09/29 08:15:20 OK 20251218171726_add_pins.sql (17.73ms)11232026/09/29 08:15:20 OK 20241026095416_initial_model.sql (184.48ms)11242026/09/29 08:15:20 OK 20251210153512_drop_unused_gin_index.sql (19.76ms)11252026/09/29 08:15:20 OK 20260628120000_add_object_size_and_stats.sql (43.22ms)11262026/09/29 08:15:20 OK 20251218171726_add_pins.sql (18.93ms)11272026/09/29 08:15:20 OK 20260628120000_add_object_size_and_stats.sql (22.99ms)11282026/09/29 08:15:20 OK 20260905000000_add_claims.sql (48.52ms)11292026/09/29 08:15:20 OK 20260905000000_add_claims.sql (29.84ms)11302026/09/29 08:15:20 OK 20260920000000_drop_claims.sql (25.68ms)11312026/09/29 08:15:20 OK 20260923120000_add_pushes.sql (10.59ms)11322026/09/29 08:15:20 goose: successfully migrated database to version: 2026092312000011332026/09/29 08:15:20 OK 1_commit_pending_closure.sql (2.31ms)11342026/09/29 08:15:20 OK 2_object_stats_trigger.sql (457.25µs)11352026/09/29 08:15:20 OK 3_commit_push.sql (404.21µs)11362026/09/29 08:15:20 goose: up to current file version: 311372026/09/29 08:15:20 OK 20260920000000_drop_claims.sql (31.48ms)11382026/09/29 08:15:20 OK 20260923120000_add_pushes.sql (8.62ms)11392026/09/29 08:15:20 goose: successfully migrated database to version: 2026092312000011402026/09/29 08:15:20 OK 1_commit_pending_closure.sql (2.31ms)11412026/09/29 08:15:20 OK 2_object_stats_trigger.sql (516.75µs)11422026/09/29 08:15:20 OK 3_commit_push.sql (388µs)11432026/09/29 08:15:20 goose: up to current file version: 311442026/09/29 08:15:20 INFO Aborted multipart uploads count=011452026/09/29 08:15:20 WARN Force mode enabled - objects will be deleted immediately without grace period11462026/09/29 08:15:20 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=011472026/09/29 08:15:20 INFO Vacuumed table table=pending_closures11482026/09/29 08:15:20 INFO Vacuumed table table=pending_objects11492026/09/29 08:15:20 INFO Vacuumed table table=multipart_uploads11502026/09/29 08:15:20 INFO Vacuumed table table=closures11512026/09/29 08:15:20 INFO Vacuumed table table=objects1152--- PASS: TestGCMetrics (2.33s)1153=== CONT TestGracefulShutdownDrainsInflight11542026/09/29 08:15:20 INFO Starting HTTP server address=127.0.0.1:5576611552026/09/29 08:15:20 INFO Shutdown signal received, draining in-flight requests timeout=10s1156--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1157=== CONT TestGCTaskStore_Fail1158--- PASS: TestGCTaskStore_Fail (0.00s)1159=== CONT TestGCTaskStore_PhaseUpdates1160--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1161=== CONT TestGCTaskStore_CompletedAllowsNewTask1162--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1163=== CONT TestGCTaskStore_GetReturnsLatest1164--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1165=== CONT TestGCTaskStore_GetEmpty1166--- PASS: TestGCTaskStore_GetEmpty (0.00s)1167=== CONT TestGCTaskStore_ConflictDifferentParams1168--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1169=== CONT TestGCTaskStore_DeduplicateSameParams1170--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1171=== CONT TestGCTaskStore_StartNew1172--- PASS: TestGCTaskStore_StartNew (0.00s)1173=== CONT TestReadProxyInvalidPath11742026/09/29 08:15:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11752026-09-29 08:15:20.980 UTC [2105] ERROR: relation "goose_db_version" does not exist at character 3611762026-09-29 08:15:20.980 UTC [2105] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11772026/09/29 08:15:21 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YzZkNjU0NWEtOTBhZC00OWYxLWI2ZmEtNjVlZmE5M2I1MGU2LjIzMjkyNzdmLWU1MzEtNGZiMC1iMWM5LTZmYzJmZjdhODlkNHgxNzkwNjY5NzE5MzkxNzcyMDAw parts=121178--- PASS: TestRedundantMultipartUpload (3.91s)1179=== CONT TestPush_OverlappingRootsStoreOneRowPerKey1180--- PASS: TestObjectStatsTrigger (2.39s)1181=== CONT TestReadRedirectUsesPublicS3URL11822026/09/29 08:15:21 OK 20241026095416_initial_model.sql (101.21ms)11832026/09/29 08:15:21 OK 20251210153512_drop_unused_gin_index.sql (1.58ms)11842026/09/29 08:15:21 OK 20251218171726_add_pins.sql (14.6ms)11852026/09/29 08:15:21 OK 20260628120000_add_object_size_and_stats.sql (22.52ms)11862026/09/29 08:15:21 OK 20260905000000_add_claims.sql (27.86ms)11872026/09/29 08:15:21 OK 20260920000000_drop_claims.sql (22.03ms)11882026/09/29 08:15:21 INFO Received uploads request method=POST path=/api/pending_closures11892026/09/29 08:15:21 OK 20260923120000_add_pushes.sql (6.49ms)11902026/09/29 08:15:21 goose: successfully migrated database to version: 2026092312000011912026/09/29 08:15:21 OK 1_commit_pending_closure.sql (2.17ms)11922026/09/29 08:15:21 OK 2_object_stats_trigger.sql (506.5µs)11932026/09/29 08:15:21 OK 3_commit_push.sql (415µs)11942026/09/29 08:15:21 goose: up to current file version: 311952026/09/29 08:15:21 INFO Received cleanup request method=DELETE path=/api/pending_closures11962026/09/29 08:15:21 INFO Aborted multipart uploads count=11197--- PASS: TestMultipartCleanup (2.54s)1198=== CONT TestReadProxyRangeRequest11992026/09/29 08:15:21 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12002026/09/29 08:15:21 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1201--- PASS: TestService_NativeMTLS (2.07s)1202=== CONT TestReadRedirectKeepsNarinfoProxied12032026-09-29 08:15:21.473 UTC [2112] ERROR: relation "goose_db_version" does not exist at character 3612042026-09-29 08:15:21.473 UTC [2112] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12052026/09/29 08:15:21 OK 20241026095416_initial_model.sql (19.18ms)12062026/09/29 08:15:21 OK 20251210153512_drop_unused_gin_index.sql (535.63µs)12072026/09/29 08:15:21 OK 20251218171726_add_pins.sql (1.02ms)12082026/09/29 08:15:21 OK 20260628120000_add_object_size_and_stats.sql (5.83ms)12092026/09/29 08:15:21 OK 20260905000000_add_claims.sql (4.53ms)12102026/09/29 08:15:21 OK 20260920000000_drop_claims.sql (738.29µs)12112026/09/29 08:15:21 OK 20260923120000_add_pushes.sql (528.75µs)12122026/09/29 08:15:21 goose: successfully migrated database to version: 2026092312000012132026/09/29 08:15:21 OK 1_commit_pending_closure.sql (1ms)12142026/09/29 08:15:21 OK 2_object_stats_trigger.sql (231.33µs)12152026/09/29 08:15:21 OK 3_commit_push.sql (218.46µs)12162026/09/29 08:15:21 goose: up to current file version: 312172026-09-29 08:15:21.570 UTC [2117] ERROR: relation "goose_db_version" does not exist at character 3612182026-09-29 08:15:21.570 UTC [2117] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12192026/09/29 08:15:21 OK 20241026095416_initial_model.sql (70.91ms)12202026/09/29 08:15:21 OK 20251210153512_drop_unused_gin_index.sql (7.96ms)12212026/09/29 08:15:21 OK 20251218171726_add_pins.sql (21.56ms)12222026/09/29 08:15:21 OK 20260628120000_add_object_size_and_stats.sql (28.91ms)12232026/09/29 08:15:21 OK 20260905000000_add_claims.sql (85.39ms)1224--- PASS: TestMetricsInventory (1.78s)1225=== CONT TestReadRedirectNar12262026/09/29 08:15:21 OK 20260920000000_drop_claims.sql (33.17ms)12272026-09-29 08:15:21.843 UTC [2119] ERROR: relation "goose_db_version" does not exist at character 3612282026-09-29 08:15:21.843 UTC [2119] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12292026/09/29 08:15:21 OK 20260923120000_add_pushes.sql (2.79ms)12302026/09/29 08:15:21 goose: successfully migrated database to version: 2026092312000012312026/09/29 08:15:21 OK 1_commit_pending_closure.sql (2.1ms)12322026/09/29 08:15:21 OK 2_object_stats_trigger.sql (392.88µs)12332026/09/29 08:15:21 OK 3_commit_push.sql (427.29µs)12342026/09/29 08:15:21 goose: up to current file version: 312352026-09-29 08:15:21.907 UTC [2121] ERROR: relation "goose_db_version" does not exist at character 3612362026-09-29 08:15:21.907 UTC [2121] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12372026/09/29 08:15:21 OK 20241026095416_initial_model.sql (82.36ms)12382026/09/29 08:15:21 OK 20251210153512_drop_unused_gin_index.sql (10.58ms)12392026/09/29 08:15:22 OK 20251218171726_add_pins.sql (26.45ms)12402026/09/29 08:15:22 OK 20241026095416_initial_model.sql (108.32ms)12412026/09/29 08:15:22 OK 20260628120000_add_object_size_and_stats.sql (39.94ms)12422026/09/29 08:15:22 OK 20251210153512_drop_unused_gin_index.sql (15.98ms)12432026/09/29 08:15:22 OK 20251218171726_add_pins.sql (30.09ms)12442026/09/29 08:15:22 OK 20260905000000_add_claims.sql (81.73ms)12452026/09/29 08:15:22 OK 20260628120000_add_object_size_and_stats.sql (56.65ms)12462026/09/29 08:15:22 OK 20260920000000_drop_claims.sql (47.81ms)12472026/09/29 08:15:22 OK 20260923120000_add_pushes.sql (12.98ms)12482026/09/29 08:15:22 goose: successfully migrated database to version: 2026092312000012492026/09/29 08:15:22 OK 1_commit_pending_closure.sql (3.97ms)12502026/09/29 08:15:22 OK 2_object_stats_trigger.sql (1.08ms)12512026/09/29 08:15:22 OK 3_commit_push.sql (658.42µs)12522026/09/29 08:15:22 goose: up to current file version: 312532026/09/29 08:15:22 OK 20260905000000_add_claims.sql (67.27ms)12542026/09/29 08:15:22 OK 20260920000000_drop_claims.sql (43.65ms)12552026/09/29 08:15:22 OK 20260923120000_add_pushes.sql (18.79ms)12562026/09/29 08:15:22 goose: successfully migrated database to version: 2026092312000012572026/09/29 08:15:22 OK 1_commit_pending_closure.sql (2.27ms)12582026/09/29 08:15:22 OK 2_object_stats_trigger.sql (447.58µs)12592026/09/29 08:15:22 OK 3_commit_push.sql (291.54µs)12602026/09/29 08:15:22 goose: up to current file version: 31261=== NAME TestNARDeduplicationMetadataUploadBug1262 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-1883-381732109/TestNARDeduplicationMetadataUploadBug3696727035/001/store/rkwg45s4da1s348yd85z54z1xdxgbswp-file1.txt1263--- PASS: TestService_healthCheckHandler (1.96s)1264=== CONT TestReadProxyDisabled12652026-09-29 08:15:22.542 UTC [2124] ERROR: relation "goose_db_version" does not exist at character 3612662026-09-29 08:15:22.542 UTC [2124] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12672026-09-29 08:15:22.575 UTC [2126] ERROR: relation "goose_db_version" does not exist at character 3612682026-09-29 08:15:22.575 UTC [2126] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12692026-09-29 08:15:22.614 UTC [2131] ERROR: relation "goose_db_version" does not exist at character 3612702026-09-29 08:15:22.614 UTC [2131] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12712026/09/29 08:15:22 INFO Received push request method=POST path=/api/pushes12722026/09/29 08:15:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12732026/09/29 08:15:22 INFO Uploading rkwg45s4da1s348yd85z54z1xdxgbswp-file1.txt (160B)12742026/09/29 08:15:22 WARN Failed to register uploaded object key=rkwg45s4da1s348yd85z54z1xdxgbswp.ls error="server returned 404: 404 page not found\n"12752026/09/29 08:15:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12762026/09/29 08:15:22 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12772026/09/29 08:15:22 INFO Signed narinfos id=1 count=112782026/09/29 08:15:22 INFO Uploading 1 narinfos12792026/09/29 08:15:22 INFO Received complete push request method=POST path=/api/pushes/1/complete12802026/09/29 08:15:22 WARN Failed to register uploaded object key=rkwg45s4da1s348yd85z54z1xdxgbswp.narinfo error="server returned 404: 404 page not found\n"12812026/09/29 08:15:22 INFO Upload complete. (154ms)1282=== NAME TestNARDeduplicationMetadataUploadBug1283 metadata_upload_test.go:54: Retrieved narinfo from S3:1284 StorePath: /nix/var/nix/builds/nix-1883-381732109/TestNARDeduplicationMetadataUploadBug3696727035/001/store/rkwg45s4da1s348yd85z54z1xdxgbswp-file1.txt1285 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1286 Compression: zstd1287 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1288 NarSize: 1601289 References: 1290 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1291 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1292 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1293 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12942026/09/29 08:15:22 WARN readiness check failed error="closed pool"1295--- PASS: TestService_readinessHandler (2.23s)1296=== CONT TestReadProxyRootRedirectsToIndexHTML12972026/09/29 08:15:22 OK 20241026095416_initial_model.sql (164.61ms)12982026/09/29 08:15:22 OK 20241026095416_initial_model.sql (180.59ms)12992026/09/29 08:15:22 OK 20251210153512_drop_unused_gin_index.sql (5.39ms)13002026/09/29 08:15:22 OK 20251210153512_drop_unused_gin_index.sql (6.66ms)1301=== NAME TestNARDeduplicationMetadataUploadBug1302 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-1883-381732109/TestNARDeduplicationMetadataUploadBug3696727035/001/store/198b5xf3r83rcydgdi45i0xkpp43p4p0-file2.txt13032026/09/29 08:15:22 OK 20251218171726_add_pins.sql (32.54ms)13042026/09/29 08:15:22 OK 20251218171726_add_pins.sql (27.08ms)13052026/09/29 08:15:22 OK 20241026095416_initial_model.sql (177.76ms)13062026/09/29 08:15:22 OK 20260628120000_add_object_size_and_stats.sql (19.48ms)13072026/09/29 08:15:22 OK 20260628120000_add_object_size_and_stats.sql (19.72ms)13082026/09/29 08:15:22 OK 20251210153512_drop_unused_gin_index.sql (1.04ms)13092026/09/29 08:15:22 OK 20251218171726_add_pins.sql (827.75µs)13102026/09/29 08:15:22 OK 20260628120000_add_object_size_and_stats.sql (20.02ms)13112026/09/29 08:15:22 OK 20260905000000_add_claims.sql (21.99ms)13122026/09/29 08:15:22 OK 20260905000000_add_claims.sql (29.23ms)13132026/09/29 08:15:22 OK 20260920000000_drop_claims.sql (15.65ms)13142026/09/29 08:15:22 OK 20260920000000_drop_claims.sql (22.75ms)13152026/09/29 08:15:22 INFO Received push request method=POST path=/api/pushes13162026/09/29 08:15:22 OK 20260905000000_add_claims.sql (25.04ms)13172026/09/29 08:15:22 OK 20260923120000_add_pushes.sql (2.73ms)13182026/09/29 08:15:22 goose: successfully migrated database to version: 2026092312000013192026/09/29 08:15:22 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13202026/09/29 08:15:22 OK 1_commit_pending_closure.sql (1.23ms)13212026/09/29 08:15:22 OK 2_object_stats_trigger.sql (232.42µs)13222026/09/29 08:15:22 OK 3_commit_push.sql (190.88µs)13232026/09/29 08:15:22 goose: up to current file version: 313242026/09/29 08:15:22 OK 20260923120000_add_pushes.sql (8.83ms)13252026/09/29 08:15:22 goose: successfully migrated database to version: 2026092312000013262026/09/29 08:15:22 OK 1_commit_pending_closure.sql (1.2ms)13272026/09/29 08:15:22 OK 2_object_stats_trigger.sql (219.08µs)13282026/09/29 08:15:22 OK 3_commit_push.sql (186.46µs)13292026/09/29 08:15:22 goose: up to current file version: 313302026/09/29 08:15:22 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13312026/09/29 08:15:22 INFO Signed narinfos id=2 count=113322026/09/29 08:15:22 WARN Failed to register uploaded object key=198b5xf3r83rcydgdi45i0xkpp43p4p0.ls error="server returned 404: 404 page not found\n"13332026/09/29 08:15:22 INFO Uploading 1 narinfos13342026/09/29 08:15:22 OK 20260920000000_drop_claims.sql (25.91ms)13352026/09/29 08:15:22 OK 20260923120000_add_pushes.sql (15.8ms)13362026/09/29 08:15:22 goose: successfully migrated database to version: 2026092312000013372026/09/29 08:15:22 INFO Received complete push request method=POST path=/api/pushes/2/complete13382026/09/29 08:15:22 WARN Failed to register uploaded object key=198b5xf3r83rcydgdi45i0xkpp43p4p0.narinfo error="server returned 404: 404 page not found\n"13392026/09/29 08:15:22 INFO Upload complete. (81ms)13402026/09/29 08:15:22 OK 1_commit_pending_closure.sql (764.29µs)1341 metadata_upload_test.go:76: Retrieved narinfo from S3:13422026/09/29 08:15:22 OK 2_object_stats_trigger.sql (207.75µs)1343 StorePath: /nix/var/nix/builds/nix-1883-381732109/TestNARDeduplicationMetadataUploadBug3696727035/001/store/198b5xf3r83rcydgdi45i0xkpp43p4p0-file2.txt1344 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1345 Compression: zstd1346 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1347 NarSize: 1601348 References: 1349 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf13502026/09/29 08:15:22 OK 3_commit_push.sql (187.13µs)13512026/09/29 08:15:22 goose: up to current file version: 31352 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1353 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1354 {"version":1,"root":{"type":"regular","size":44}}13552026-09-29 08:15:22.935 UTC [2141] ERROR: relation "goose_db_version" does not exist at character 3613562026-09-29 08:15:22.935 UTC [2141] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1357--- PASS: TestNARDeduplicationMetadataUploadBug (2.61s)1358=== CONT TestReadProxyConditionalGet13592026-09-29 08:15:23.014 UTC [2142] ERROR: relation "goose_db_version" does not exist at character 3613602026-09-29 08:15:23.014 UTC [2142] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13612026/09/29 08:15:23 INFO Received push request method=POST path=/api/pushes13622026/09/29 08:15:23 OK 20241026095416_initial_model.sql (170.62ms)13632026/09/29 08:15:23 OK 20251210153512_drop_unused_gin_index.sql (2.41ms)13642026/09/29 08:15:23 OK 20251218171726_add_pins.sql (53.75ms)1365--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (2.21s)1366=== CONT TestReadProxyHead13672026/09/29 08:15:23 OK 20241026095416_initial_model.sql (174.18ms)13682026/09/29 08:15:23 OK 20251210153512_drop_unused_gin_index.sql (8.85ms)13692026/09/29 08:15:23 OK 20260628120000_add_object_size_and_stats.sql (23.98ms)13702026/09/29 08:15:23 OK 20251218171726_add_pins.sql (14.64ms)13712026/09/29 08:15:23 OK 20260905000000_add_claims.sql (17.46ms)13722026/09/29 08:15:23 OK 20260920000000_drop_claims.sql (14.02ms)13732026/09/29 08:15:23 OK 20260628120000_add_object_size_and_stats.sql (19.48ms)13742026/09/29 08:15:23 OK 20260923120000_add_pushes.sql (2.35ms)13752026/09/29 08:15:23 goose: successfully migrated database to version: 2026092312000013762026/09/29 08:15:23 OK 1_commit_pending_closure.sql (1.6ms)13772026/09/29 08:15:23 OK 2_object_stats_trigger.sql (376.13µs)13782026/09/29 08:15:23 OK 3_commit_push.sql (366.92µs)13792026/09/29 08:15:23 goose: up to current file version: 313802026/09/29 08:15:23 OK 20260905000000_add_claims.sql (23.61ms)13812026/09/29 08:15:23 OK 20260920000000_drop_claims.sql (27.37ms)13822026/09/29 08:15:23 OK 20260923120000_add_pushes.sql (18.93ms)13832026/09/29 08:15:23 goose: successfully migrated database to version: 2026092312000013842026/09/29 08:15:23 OK 1_commit_pending_closure.sql (2.85ms)13852026/09/29 08:15:23 OK 2_object_stats_trigger.sql (642.5µs)13862026/09/29 08:15:23 OK 3_commit_push.sql (534.83µs)13872026/09/29 08:15:23 goose: up to current file version: 31388--- PASS: TestReadProxyInvalidPath (2.45s)1389=== CONT TestClientSharedPathCommittedMidPush13902026-09-29 08:15:23.458 UTC [2150] ERROR: relation "goose_db_version" does not exist at character 3613912026-09-29 08:15:23.458 UTC [2150] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13922026/09/29 08:15:23 WARN Rate limiter enabled after throttle name=s3-test rate=513932026/09/29 08:15:23 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1394=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1395 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101396 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001397--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (7.71s)1398=== CONT TestClientPushesUseOnePush1399--- PASS: TestReadRedirectUsesPublicS3URL (2.52s)1400=== CONT TestPinProtectsFromGC14012026/09/29 08:15:23 OK 20241026095416_initial_model.sql (116.7ms)14022026/09/29 08:15:23 OK 20251210153512_drop_unused_gin_index.sql (12.81ms)14032026/09/29 08:15:23 OK 20251218171726_add_pins.sql (13.92ms)14042026/09/29 08:15:23 OK 20260628120000_add_object_size_and_stats.sql (46.76ms)14052026/09/29 08:15:23 OK 20260905000000_add_claims.sql (44.41ms)14062026/09/29 08:15:23 OK 20260920000000_drop_claims.sql (30.25ms)14072026/09/29 08:15:23 OK 20260923120000_add_pushes.sql (12.96ms)14082026/09/29 08:15:23 goose: successfully migrated database to version: 2026092312000014092026/09/29 08:15:23 OK 1_commit_pending_closure.sql (3.39ms)14102026/09/29 08:15:23 OK 2_object_stats_trigger.sql (666.71µs)14112026/09/29 08:15:23 OK 3_commit_push.sql (1.58ms)14122026/09/29 08:15:23 goose: up to current file version: 31413--- PASS: TestReadRedirectKeepsNarinfoProxied (2.44s)1414=== CONT TestClientWithDependencies1415--- PASS: TestReadProxyRangeRequest (2.80s)1416=== CONT TestClientFallsBackToClosures14172026-09-29 08:15:24.357 UTC [2159] ERROR: relation "goose_db_version" does not exist at character 3614182026-09-29 08:15:24.357 UTC [2159] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1419--- PASS: TestReadRedirectNar (2.75s)1420=== CONT TestGCBugBareHashReferences14212026/09/29 08:15:24 OK 20241026095416_initial_model.sql (222.3ms)14222026/09/29 08:15:24 OK 20251210153512_drop_unused_gin_index.sql (9.26ms)14232026/09/29 08:15:24 OK 20251218171726_add_pins.sql (18.18ms)14242026-09-29 08:15:24.684 UTC [2162] ERROR: relation "goose_db_version" does not exist at character 3614252026-09-29 08:15:24.684 UTC [2162] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14262026/09/29 08:15:24 OK 20260628120000_add_object_size_and_stats.sql (29.13ms)14272026/09/29 08:15:24 OK 20260905000000_add_claims.sql (36.51ms)14282026/09/29 08:15:24 OK 20260920000000_drop_claims.sql (17.15ms)14292026/09/29 08:15:24 OK 20260923120000_add_pushes.sql (7.29ms)14302026/09/29 08:15:24 goose: successfully migrated database to version: 2026092312000014312026/09/29 08:15:24 OK 1_commit_pending_closure.sql (2.81ms)14322026/09/29 08:15:24 OK 2_object_stats_trigger.sql (585.71µs)14332026/09/29 08:15:24 OK 3_commit_push.sql (370.33µs)14342026/09/29 08:15:24 goose: up to current file version: 314352026-09-29 08:15:24.809 UTC [2163] ERROR: relation "goose_db_version" does not exist at character 3614362026-09-29 08:15:24.809 UTC [2163] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14372026/09/29 08:15:24 OK 20241026095416_initial_model.sql (100.45ms)14382026/09/29 08:15:24 OK 20251210153512_drop_unused_gin_index.sql (15.38ms)14392026/09/29 08:15:24 OK 20251218171726_add_pins.sql (30.79ms)14402026/09/29 08:15:24 OK 20260628120000_add_object_size_and_stats.sql (43.95ms)14412026/09/29 08:15:24 OK 20260905000000_add_claims.sql (41.12ms)14422026/09/29 08:15:24 OK 20241026095416_initial_model.sql (104.45ms)14432026/09/29 08:15:24 OK 20260920000000_drop_claims.sql (24.46ms)14442026/09/29 08:15:24 OK 20251210153512_drop_unused_gin_index.sql (9.49ms)14452026-09-29 08:15:24.994 UTC [2164] ERROR: relation "goose_db_version" does not exist at character 3614462026-09-29 08:15:24.994 UTC [2164] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14472026/09/29 08:15:25 OK 20260923120000_add_pushes.sql (17.09ms)14482026/09/29 08:15:25 goose: successfully migrated database to version: 2026092312000014492026/09/29 08:15:25 OK 1_commit_pending_closure.sql (3.83ms)14502026/09/29 08:15:25 OK 2_object_stats_trigger.sql (730.42µs)14512026/09/29 08:15:25 OK 3_commit_push.sql (495.42µs)14522026/09/29 08:15:25 goose: up to current file version: 314532026/09/29 08:15:25 OK 20251218171726_add_pins.sql (26.65ms)14542026/09/29 08:15:25 OK 20260628120000_add_object_size_and_stats.sql (20.94ms)1455--- PASS: TestReadProxyDisabled (2.57s)1456=== CONT TestLeadEndsOnShutdown14572026/09/29 08:15:25 OK 20260905000000_add_claims.sql (39.36ms)14582026/09/29 08:15:25 OK 20260920000000_drop_claims.sql (50.83ms)14592026/09/29 08:15:25 OK 20260923120000_add_pushes.sql (7.71ms)14602026/09/29 08:15:25 goose: successfully migrated database to version: 2026092312000014612026/09/29 08:15:25 OK 1_commit_pending_closure.sql (2.8ms)14622026/09/29 08:15:25 OK 2_object_stats_trigger.sql (564.38µs)14632026/09/29 08:15:25 OK 3_commit_push.sql (537.54µs)14642026/09/29 08:15:25 goose: up to current file version: 314652026/09/29 08:15:25 OK 20241026095416_initial_model.sql (119.35ms)14662026/09/29 08:15:25 OK 20251210153512_drop_unused_gin_index.sql (8.07ms)14672026-09-29 08:15:25.172 UTC [2167] ERROR: relation "goose_db_version" does not exist at character 3614682026-09-29 08:15:25.172 UTC [2167] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14692026/09/29 08:15:25 OK 20251218171726_add_pins.sql (19.13ms)14702026/09/29 08:15:25 OK 20260628120000_add_object_size_and_stats.sql (15.41ms)14712026/09/29 08:15:25 OK 20260905000000_add_claims.sql (25.95ms)14722026/09/29 08:15:25 OK 20260920000000_drop_claims.sql (20.44ms)14732026/09/29 08:15:25 OK 20260923120000_add_pushes.sql (6.14ms)14742026/09/29 08:15:25 goose: successfully migrated database to version: 2026092312000014752026/09/29 08:15:25 OK 1_commit_pending_closure.sql (2.88ms)14762026/09/29 08:15:25 OK 2_object_stats_trigger.sql (927.38µs)14772026/09/29 08:15:25 OK 3_commit_push.sql (769µs)14782026/09/29 08:15:25 goose: up to current file version: 314792026-09-29 08:15:25.275 UTC [2168] ERROR: relation "goose_db_version" does not exist at character 3614802026-09-29 08:15:25.275 UTC [2168] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14812026/09/29 08:15:25 OK 20241026095416_initial_model.sql (84.7ms)14822026/09/29 08:15:25 OK 20251210153512_drop_unused_gin_index.sql (7.79ms)14832026/09/29 08:15:25 OK 20251218171726_add_pins.sql (19.7ms)14842026/09/29 08:15:25 OK 20260628120000_add_object_size_and_stats.sql (27.1ms)1485--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.59s)1486=== CONT TestLeadElectsOneAndHandsOver14872026/09/29 08:15:25 OK 20260905000000_add_claims.sql (58.27ms)14882026/09/29 08:15:25 OK 20260920000000_drop_claims.sql (26.24ms)14892026/09/29 08:15:25 OK 20260923120000_add_pushes.sql (17.77ms)14902026/09/29 08:15:25 goose: successfully migrated database to version: 2026092312000014912026/09/29 08:15:25 OK 1_commit_pending_closure.sql (2.93ms)14922026/09/29 08:15:25 OK 2_object_stats_trigger.sql (670.13µs)14932026/09/29 08:15:25 OK 3_commit_push.sql (464.04µs)14942026/09/29 08:15:25 goose: up to current file version: 314952026/09/29 08:15:25 OK 20241026095416_initial_model.sql (138.56ms)14962026-09-29 08:15:25.466 UTC [2171] ERROR: relation "goose_db_version" does not exist at character 3614972026-09-29 08:15:25.466 UTC [2171] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14982026/09/29 08:15:25 OK 20251210153512_drop_unused_gin_index.sql (3.39ms)14992026/09/29 08:15:25 OK 20251218171726_add_pins.sql (21.53ms)15002026/09/29 08:15:25 OK 20260628120000_add_object_size_and_stats.sql (21.53ms)15012026/09/29 08:15:25 OK 20260905000000_add_claims.sql (22.82ms)15022026/09/29 08:15:25 OK 20260920000000_drop_claims.sql (18.07ms)15032026-09-29 08:15:25.556 UTC [2175] ERROR: relation "goose_db_version" does not exist at character 3615042026-09-29 08:15:25.556 UTC [2175] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15052026/09/29 08:15:25 OK 20260923120000_add_pushes.sql (7.07ms)15062026/09/29 08:15:25 goose: successfully migrated database to version: 2026092312000015072026/09/29 08:15:25 OK 1_commit_pending_closure.sql (1.58ms)15082026/09/29 08:15:25 OK 2_object_stats_trigger.sql (260.29µs)15092026/09/29 08:15:25 OK 3_commit_push.sql (227.25µs)15102026/09/29 08:15:25 goose: up to current file version: 315112026/09/29 08:15:25 OK 20241026095416_initial_model.sql (82.19ms)15122026/09/29 08:15:25 OK 20251210153512_drop_unused_gin_index.sql (1.77ms)1513--- PASS: TestReadProxyConditionalGet (2.59s)1514=== CONT TestResolveDBConnectionString1515=== RUN TestResolveDBConnectionString/flag_wins1516=== PAUSE TestResolveDBConnectionString/flag_wins1517=== RUN TestResolveDBConnectionString/file_when_flag_empty1518=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1519=== RUN TestResolveDBConnectionString/missing_file_is_an_error1520=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1521=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1522=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1523=== RUN TestResolveDBConnectionString/nothing_configured1524=== PAUSE TestResolveDBConnectionString/nothing_configured1525=== CONT TestClientIntegration15262026/09/29 08:15:25 OK 20251218171726_add_pins.sql (25.08ms)15272026-09-29 08:15:25.630 UTC [2176] ERROR: relation "goose_db_version" does not exist at character 3615282026-09-29 08:15:25.630 UTC [2176] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15292026/09/29 08:15:25 OK 20260628120000_add_object_size_and_stats.sql (24.74ms)15302026/09/29 08:15:25 OK 20260905000000_add_claims.sql (41.47ms)15312026/09/29 08:15:25 OK 20260920000000_drop_claims.sql (13.72ms)15322026/09/29 08:15:25 OK 20241026095416_initial_model.sql (107.18ms)15332026/09/29 08:15:25 OK 20260923120000_add_pushes.sql (1.13ms)15342026/09/29 08:15:25 goose: successfully migrated database to version: 2026092312000015352026/09/29 08:15:25 OK 1_commit_pending_closure.sql (939.71µs)15362026/09/29 08:15:25 OK 2_object_stats_trigger.sql (229.29µs)15372026/09/29 08:15:25 OK 3_commit_push.sql (257.13µs)15382026/09/29 08:15:25 goose: up to current file version: 315392026/09/29 08:15:25 OK 20251210153512_drop_unused_gin_index.sql (2.78ms)15402026/09/29 08:15:25 OK 20251218171726_add_pins.sql (7.65ms)15412026/09/29 08:15:25 OK 20260628120000_add_object_size_and_stats.sql (18.85ms)15422026/09/29 08:15:25 OK 20260905000000_add_claims.sql (48.18ms)15432026-09-29 08:15:25.777 UTC [2212] ERROR: relation "goose_db_version" does not exist at character 3615442026-09-29 08:15:25.777 UTC [2212] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15452026/09/29 08:15:25 OK 20241026095416_initial_model.sql (108.59ms)15462026/09/29 08:15:25 OK 20251210153512_drop_unused_gin_index.sql (7.1ms)15472026/09/29 08:15:25 OK 20260920000000_drop_claims.sql (17.32ms)15482026/09/29 08:15:25 OK 20251218171726_add_pins.sql (10.56ms)15492026/09/29 08:15:25 OK 20260923120000_add_pushes.sql (9.98ms)15502026/09/29 08:15:25 goose: successfully migrated database to version: 2026092312000015512026/09/29 08:15:25 OK 1_commit_pending_closure.sql (2.06ms)15522026/09/29 08:15:25 OK 2_object_stats_trigger.sql (432.33µs)15532026/09/29 08:15:25 OK 3_commit_push.sql (180.71µs)15542026/09/29 08:15:25 goose: up to current file version: 315552026/09/29 08:15:25 OK 20260628120000_add_object_size_and_stats.sql (18.99ms)1556--- PASS: TestReadProxyHead (2.61s)1557=== CONT TestIsValidCachePath1558=== RUN TestIsValidCachePath/narinfo1559=== PAUSE TestIsValidCachePath/narinfo1560=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1561=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1562=== RUN TestIsValidCachePath/nar_zst1563=== PAUSE TestIsValidCachePath/nar_zst1564=== RUN TestIsValidCachePath/nar_xz1565=== PAUSE TestIsValidCachePath/nar_xz1566=== RUN TestIsValidCachePath/nar_bz21567=== PAUSE TestIsValidCachePath/nar_bz21568=== RUN TestIsValidCachePath/nar_uncompressed1569=== PAUSE TestIsValidCachePath/nar_uncompressed1570=== RUN TestIsValidCachePath/ls1571=== PAUSE TestIsValidCachePath/ls1572=== RUN TestIsValidCachePath/log1573=== PAUSE TestIsValidCachePath/log1574=== RUN TestIsValidCachePath/realisation1575=== PAUSE TestIsValidCachePath/realisation1576=== RUN TestIsValidCachePath/nix-cache-info1577=== PAUSE TestIsValidCachePath/nix-cache-info1578=== RUN TestIsValidCachePath/index.html1579=== PAUSE TestIsValidCachePath/index.html1580=== RUN TestIsValidCachePath/traversal_parent1581=== PAUSE TestIsValidCachePath/traversal_parent1582=== RUN TestIsValidCachePath/traversal_in_middle1583=== PAUSE TestIsValidCachePath/traversal_in_middle1584=== RUN TestIsValidCachePath/invalid_char_e1585=== PAUSE TestIsValidCachePath/invalid_char_e1586=== RUN TestIsValidCachePath/invalid_char_u1587=== PAUSE TestIsValidCachePath/invalid_char_u1588=== RUN TestIsValidCachePath/random_path1589=== PAUSE TestIsValidCachePath/random_path1590=== RUN TestIsValidCachePath/empty1591=== PAUSE TestIsValidCachePath/empty1592=== RUN TestIsValidCachePath/leading_slash1593=== PAUSE TestIsValidCachePath/leading_slash1594=== RUN TestIsValidCachePath/wrong_extension1595=== PAUSE TestIsValidCachePath/wrong_extension1596=== RUN TestIsValidCachePath/short_hash1597=== PAUSE TestIsValidCachePath/short_hash1598=== CONT TestClientMultipleUploads15992026/09/29 08:15:25 OK 20260905000000_add_claims.sql (45.91ms)16002026/09/29 08:15:25 OK 20260920000000_drop_claims.sql (23.6ms)16012026/09/29 08:15:25 OK 20260923120000_add_pushes.sql (6.75ms)16022026/09/29 08:15:25 goose: successfully migrated database to version: 2026092312000016032026/09/29 08:15:25 OK 1_commit_pending_closure.sql (865.83µs)16042026/09/29 08:15:25 OK 2_object_stats_trigger.sql (216.38µs)16052026/09/29 08:15:25 OK 3_commit_push.sql (176.29µs)16062026/09/29 08:15:25 goose: up to current file version: 316072026/09/29 08:15:25 OK 20241026095416_initial_model.sql (109.91ms)16082026/09/29 08:15:25 OK 20251210153512_drop_unused_gin_index.sql (7.28ms)16092026/09/29 08:15:25 OK 20251218171726_add_pins.sql (18.65ms)16102026/09/29 08:15:25 OK 20260628120000_add_object_size_and_stats.sql (19.23ms)16112026/09/29 08:15:25 OK 20260905000000_add_claims.sql (24.39ms)16122026/09/29 08:15:26 OK 20260920000000_drop_claims.sql (21.86ms)16132026/09/29 08:15:26 OK 20260923120000_add_pushes.sql (11.9ms)16142026/09/29 08:15:26 goose: successfully migrated database to version: 2026092312000016152026/09/29 08:15:26 OK 1_commit_pending_closure.sql (995.92µs)16162026/09/29 08:15:26 OK 2_object_stats_trigger.sql (194.88µs)16172026/09/29 08:15:26 OK 3_commit_push.sql (182.88µs)16182026/09/29 08:15:26 goose: up to current file version: 316192026-09-29 08:15:26.242 UTC [2225] ERROR: relation "goose_db_version" does not exist at character 3616202026-09-29 08:15:26.242 UTC [2225] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16212026/09/29 08:15:26 INFO Received push request method=POST path=/api/pushes16222026/09/29 08:15:26 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)16232026/09/29 08:15:26 INFO Uploading cawh4vhkf02ggfinns7fiknwv22xg212-top (256B)16242026/09/29 08:15:26 INFO Uploading z8yixizzzyzzhkj50c692l5rnh13n3xj-shared-dep (136B)16252026/09/29 08:15:26 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16262026/09/29 08:15:26 WARN Failed to register uploaded object key=cawh4vhkf02ggfinns7fiknwv22xg212.ls error="server returned 404: 404 page not found\n"16272026/09/29 08:15:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16282026/09/29 08:15:26 WARN Failed to register uploaded object key=z8yixizzzyzzhkj50c692l5rnh13n3xj.ls error="server returned 404: 404 page not found\n"16292026/09/29 08:15:26 WARN Failed to register uploaded object key=nar/0gciskkj7axbr1ngx64kdg1q7gwbs2n0sc76dga98xgrhfq1x7d0.nar.zst error="server returned 404: 404 page not found\n"16302026/09/29 08:15:26 INFO Signed narinfos id=1 count=216312026/09/29 08:15:26 INFO Uploading 2 narinfos16322026/09/29 08:15:26 WARN Failed to register uploaded object key=z8yixizzzyzzhkj50c692l5rnh13n3xj.narinfo error="server returned 404: 404 page not found\n"16332026/09/29 08:15:26 INFO Received complete push request method=POST path=/api/pushes/1/complete16342026/09/29 08:15:26 WARN Failed to register uploaded object key=cawh4vhkf02ggfinns7fiknwv22xg212.narinfo error="server returned 404: 404 page not found\n"16352026/09/29 08:15:26 INFO Upload complete. (111ms)1636=== NAME TestClientSharedPathCommittedMidPush1637 client_integration_test.go:680: Retrieved narinfo from S3:1638 StorePath: /nix/var/nix/builds/nix-1883-381732109/TestClientSharedPathCommittedMidPush1639629745/001/store/z8yixizzzyzzhkj50c692l5rnh13n3xj-shared-dep1639 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1640 Compression: zstd1641 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821642 NarSize: 1361643 References: 1644 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1645 client_integration_test.go:680: Retrieved narinfo from S3:1646 StorePath: /nix/var/nix/builds/nix-1883-381732109/TestClientSharedPathCommittedMidPush1639629745/001/store/cawh4vhkf02ggfinns7fiknwv22xg212-top1647 URL: nar/0gciskkj7axbr1ngx64kdg1q7gwbs2n0sc76dga98xgrhfq1x7d0.nar.zst1648 Compression: zstd1649 NarHash: sha256:0gciskkj7axbr1ngx64kdg1q7gwbs2n0sc76dga98xgrhfq1x7d01650 NarSize: 2561651 References: /nix/var/nix/builds/nix-1883-381732109/TestClientSharedPathCommittedMidPush1639629745/001/store/z8yixizzzyzzhkj50c692l5rnh13n3xj-shared-dep1652 CA: text:sha256:09drn4nniy9w3lcdjh6y118h6lgpms2gm39jjx5x7gjqbx1rxfhz16532026/09/29 08:15:26 OK 20241026095416_initial_model.sql (104.72ms)16542026/09/29 08:15:26 OK 20251210153512_drop_unused_gin_index.sql (5.25ms)1655--- PASS: TestClientSharedPathCommittedMidPush (3.03s)1656=== CONT TestReadProxy40416572026/09/29 08:15:26 OK 20251218171726_add_pins.sql (13.35ms)16582026/09/29 08:15:26 OK 20260628120000_add_object_size_and_stats.sql (16.31ms)16592026/09/29 08:15:26 OK 20260905000000_add_claims.sql (35.61ms)16602026/09/29 08:15:26 OK 20260920000000_drop_claims.sql (8.24ms)16612026/09/29 08:15:26 OK 20260923120000_add_pushes.sql (19.54ms)16622026/09/29 08:15:26 goose: successfully migrated database to version: 2026092312000016632026/09/29 08:15:26 OK 1_commit_pending_closure.sql (1.03ms)16642026/09/29 08:15:26 OK 2_object_stats_trigger.sql (332.58µs)16652026/09/29 08:15:26 OK 3_commit_push.sql (354.5µs)16662026/09/29 08:15:26 goose: up to current file version: 316672026/09/29 08:15:26 INFO Received push request method=POST path=/api/pushes16682026-09-29 08:15:26.520 UTC [2247] ERROR: relation "goose_db_version" does not exist at character 3616692026-09-29 08:15:26.520 UTC [2247] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1670=== NAME TestPinProtectsFromGC1671 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-1883-381732109/TestPinProtectsFromGC2153464979/001/store/d7c4jqz74qf0wp82xh51rhmsbashh8bm-pinned-file.txt1672 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-1883-381732109/TestPinProtectsFromGC2153464979/001/store/15yimygi7p3dsx050skba9ga6ir25sqx-unpinned-file.txt16732026/09/29 08:15:26 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16742026/09/29 08:15:26 INFO Uploading sv1zznw5pl8v11d5sacpdvdbfmixqjw8-b (248B)16752026/09/29 08:15:26 INFO Uploading dh7mfzg10qp600915hkz5ayxgkpbc01m-shared-dep (136B)16762026/09/29 08:15:26 WARN Failed to register uploaded object key=sv1zznw5pl8v11d5sacpdvdbfmixqjw8.ls error="server returned 404: 404 page not found\n"16772026/09/29 08:15:26 WARN Failed to register uploaded object key=nar/1zzca660gv5qvc22ysbx54aczmvlqdfxykcvd95qq99vgypwgl4n.nar.zst error="server returned 404: 404 page not found\n"16782026/09/29 08:15:26 WARN Failed to register uploaded object key=ibyrh0xz22srcmqd76a5nj9g78zpi1yg.ls error="server returned 404: 404 page not found\n"16792026/09/29 08:15:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16802026/09/29 08:15:26 WARN Failed to register uploaded object key=dh7mfzg10qp600915hkz5ayxgkpbc01m.ls error="server returned 404: 404 page not found\n"16812026/09/29 08:15:26 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16822026/09/29 08:15:26 INFO Signed narinfos id=1 count=316832026/09/29 08:15:26 INFO Uploading 3 narinfos16842026/09/29 08:15:26 WARN Failed to register uploaded object key=dh7mfzg10qp600915hkz5ayxgkpbc01m.narinfo error="server returned 404: 404 page not found\n"16852026/09/29 08:15:26 INFO Received complete push request method=POST path=/api/pushes/1/complete16862026/09/29 08:15:26 WARN Failed to register uploaded object key=sv1zznw5pl8v11d5sacpdvdbfmixqjw8.narinfo error="server returned 404: 404 page not found\n"16872026/09/29 08:15:26 WARN Failed to register uploaded object key=ibyrh0xz22srcmqd76a5nj9g78zpi1yg.narinfo error="server returned 404: 404 page not found\n"16882026/09/29 08:15:26 INFO Upload complete. (120ms)1689=== NAME TestClientPushesUseOnePush1690 client_pushes_test.go:97: Retrieved narinfo from S3:1691 StorePath: /nix/var/nix/builds/nix-1883-381732109/TestClientPushesUseOnePush3939613522/001/store/dh7mfzg10qp600915hkz5ayxgkpbc01m-shared-dep1692 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1693 Compression: zstd1694 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821695 NarSize: 1361696 References: 1697 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1698 client_pushes_test.go:97: Retrieved narinfo from S3:1699 StorePath: /nix/var/nix/builds/nix-1883-381732109/TestClientPushesUseOnePush3939613522/001/store/ibyrh0xz22srcmqd76a5nj9g78zpi1yg-a1700 URL: nar/1zzca660gv5qvc22ysbx54aczmvlqdfxykcvd95qq99vgypwgl4n.nar.zst1701 Compression: zstd1702 NarHash: sha256:1zzca660gv5qvc22ysbx54aczmvlqdfxykcvd95qq99vgypwgl4n1703 NarSize: 2481704 References: /nix/var/nix/builds/nix-1883-381732109/TestClientPushesUseOnePush3939613522/001/store/dh7mfzg10qp600915hkz5ayxgkpbc01m-shared-dep1705 CA: text:sha256:0f7zrdnffjjlgpn3hjz7h331l19yh0k6ch0p3wsfb6z7fzk0r3ji1706 client_pushes_test.go:97: Retrieved narinfo from S3:1707 StorePath: /nix/var/nix/builds/nix-1883-381732109/TestClientPushesUseOnePush3939613522/001/store/sv1zznw5pl8v11d5sacpdvdbfmixqjw8-b1708 URL: nar/1zzca660gv5qvc22ysbx54aczmvlqdfxykcvd95qq99vgypwgl4n.nar.zst1709 Compression: zstd1710 NarHash: sha256:1zzca660gv5qvc22ysbx54aczmvlqdfxykcvd95qq99vgypwgl4n1711 NarSize: 2481712 References: /nix/var/nix/builds/nix-1883-381732109/TestClientPushesUseOnePush3939613522/001/store/dh7mfzg10qp600915hkz5ayxgkpbc01m-shared-dep1713 CA: text:sha256:0f7zrdnffjjlgpn3hjz7h331l19yh0k6ch0p3wsfb6z7fzk0r3ji17142026/09/29 08:15:26 INFO Received push request method=POST path=/api/pushes17152026/09/29 08:15:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17162026/09/29 08:15:26 INFO Uploading d7c4jqz74qf0wp82xh51rhmsbashh8bm-pinned-file.txt (128B)1717--- PASS: TestClientPushesUseOnePush (3.14s)1718=== CONT TestReadProxyNarinfoAlreadyDecompressed17192026/09/29 08:15:26 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"17202026/09/29 08:15:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17212026/09/29 08:15:26 WARN Failed to register uploaded object key=d7c4jqz74qf0wp82xh51rhmsbashh8bm.ls error="server returned 404: 404 page not found\n"17222026/09/29 08:15:26 INFO Signed narinfos id=1 count=117232026/09/29 08:15:26 INFO Uploading 1 narinfos17242026/09/29 08:15:26 INFO Received complete push request method=POST path=/api/pushes/1/complete17252026/09/29 08:15:26 WARN Failed to register uploaded object key=d7c4jqz74qf0wp82xh51rhmsbashh8bm.narinfo error="server returned 404: 404 page not found\n"17262026/09/29 08:15:26 INFO Upload complete. (132ms)17272026/09/29 08:15:26 OK 20241026095416_initial_model.sql (127.44ms)17282026/09/29 08:15:26 OK 20251210153512_drop_unused_gin_index.sql (7.81ms)17292026/09/29 08:15:26 OK 20251218171726_add_pins.sql (24.04ms)17302026/09/29 08:15:26 OK 20260628120000_add_object_size_and_stats.sql (26.91ms)17312026/09/29 08:15:26 OK 20260905000000_add_claims.sql (29.15ms)17322026/09/29 08:15:26 INFO Received push request method=POST path=/api/pushes17332026/09/29 08:15:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17342026/09/29 08:15:26 INFO Uploading 15yimygi7p3dsx050skba9ga6ir25sqx-unpinned-file.txt (128B)17352026/09/29 08:15:26 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17362026/09/29 08:15:26 WARN Failed to register uploaded object key=15yimygi7p3dsx050skba9ga6ir25sqx.ls error="server returned 404: 404 page not found\n"17372026/09/29 08:15:26 INFO Signed narinfos id=2 count=117382026/09/29 08:15:26 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"17392026/09/29 08:15:26 OK 20260920000000_drop_claims.sql (29.86ms)17402026/09/29 08:15:26 INFO Uploading 1 narinfos17412026/09/29 08:15:26 OK 20260923120000_add_pushes.sql (20.11ms)17422026/09/29 08:15:26 goose: successfully migrated database to version: 2026092312000017432026/09/29 08:15:26 INFO Received complete push request method=POST path=/api/pushes/2/complete17442026/09/29 08:15:26 WARN Failed to register uploaded object key=15yimygi7p3dsx050skba9ga6ir25sqx.narinfo error="server returned 404: 404 page not found\n"17452026/09/29 08:15:26 INFO Upload complete. (104ms)17462026/09/29 08:15:26 OK 1_commit_pending_closure.sql (1.63ms)17472026/09/29 08:15:26 OK 2_object_stats_trigger.sql (1.12ms)17482026/09/29 08:15:26 OK 3_commit_push.sql (384.46µs)17492026/09/29 08:15:26 goose: up to current file version: 317502026/09/29 08:15:26 INFO Received create pin request method=POST path=/api/pins/myapp17512026/09/29 08:15:26 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-1883-381732109/TestPinProtectsFromGC2153464979/001/store/d7c4jqz74qf0wp82xh51rhmsbashh8bm-pinned-file.txt narinfo_key=d7c4jqz74qf0wp82xh51rhmsbashh8bm.narinfo17522026/09/29 08:15:26 INFO Starting cleanup of old closures method=DELETE path=/api/closures17532026/09/29 08:15:26 INFO Garbage collection started17542026/09/29 08:15:26 INFO Aborted multipart uploads count=017552026/09/29 08:15:26 WARN Force mode enabled - objects will be deleted immediately without grace period17562026-09-29 08:15:26.914 UTC [2311] ERROR: relation "goose_db_version" does not exist at character 3617572026-09-29 08:15:26.914 UTC [2311] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1758=== NAME TestClientWithDependencies1759 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-1883-381732109/TestClientWithDependencies3775778772/001/store/8xz6g5kimf8wf7xs34jydkxxzd1q4xfs-test-script1760 client_integration_test.go:615: Found 1 dependencies (including self)17612026/09/29 08:15:27 INFO Received push request method=POST path=/api/pushes17622026/09/29 08:15:27 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17632026/09/29 08:15:27 INFO Uploading 8xz6g5kimf8wf7xs34jydkxxzd1q4xfs-test-script (136B)17642026/09/29 08:15:27 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"17652026/09/29 08:15:27 WARN Failed to register uploaded object key=8xz6g5kimf8wf7xs34jydkxxzd1q4xfs.ls error="server returned 404: 404 page not found\n"17662026/09/29 08:15:27 WARN Failed to register uploaded object key=log/f0yljf6580m3myh5cl7xw6ikjpspp2py-test-script.drv error="server returned 404: 404 page not found\n"17672026/09/29 08:15:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17682026/09/29 08:15:27 INFO Signed narinfos id=1 count=117692026/09/29 08:15:27 INFO Uploading 1 narinfos17702026/09/29 08:15:27 INFO Received complete push request method=POST path=/api/pushes/1/complete17712026/09/29 08:15:27 OK 20241026095416_initial_model.sql (156.06ms)17722026/09/29 08:15:27 WARN Failed to register uploaded object key=8xz6g5kimf8wf7xs34jydkxxzd1q4xfs.narinfo error="server returned 404: 404 page not found\n"17732026/09/29 08:15:27 OK 20251210153512_drop_unused_gin_index.sql (11.33ms)17742026/09/29 08:15:27 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=017752026/09/29 08:15:27 INFO Upload complete. (139ms)17762026-09-29 08:15:27.139 UTC [2379] ERROR: relation "goose_db_version" does not exist at character 3617772026-09-29 08:15:27.139 UTC [2379] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17782026/09/29 08:15:27 OK 20251218171726_add_pins.sql (11.46ms)1779 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-1883-381732109/TestClientWithDependencies3775778772/001/store) requires matching store prefix17802026/09/29 08:15:27 INFO Vacuumed table table=pending_closures17812026/09/29 08:15:27 INFO Vacuumed table table=pending_objects17822026/09/29 08:15:27 INFO Vacuumed table table=multipart_uploads17832026/09/29 08:15:27 INFO Received uploads request method=POST path=/api/pending_closures17842026/09/29 08:15:27 OK 20260628120000_add_object_size_and_stats.sql (30.68ms)17852026/09/29 08:15:27 INFO lead: acquired remote=192.0.2.1:123417862026/09/29 08:15:27 INFO lead: released remote=192.0.2.1:12341787--- PASS: TestLeadEndsOnShutdown (2.10s)1788=== CONT TestReadProxyNarinfo17892026/09/29 08:15:27 INFO Received uploads request method=POST path=/api/pending_closures17902026/09/29 08:15:27 INFO Vacuumed table table=closures17912026/09/29 08:15:27 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17922026/09/29 08:15:27 INFO Uploading imxana0ph07nd19gfnxc8aqsg054qh4q-b (248B)17932026/09/29 08:15:27 INFO Uploading nvx5q7a26vpkv92qd33k8wh3d19xxldk-shared-dep (136B)17942026/09/29 08:15:27 WARN Failed to register uploaded object key=nvx5q7a26vpkv92qd33k8wh3d19xxldk.ls error="server returned 404: 404 page not found\n"17952026/09/29 08:15:27 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1796--- PASS: TestClientWithDependencies (3.32s)1797=== CONT TestReadProxyNarStreaming17982026/09/29 08:15:27 INFO Vacuumed table table=objects17992026/09/29 08:15:27 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18002026/09/29 08:15:27 WARN Failed to register uploaded object key=nar/1aimsjawvilg7q2s69vmfxmzjrhbczvx034n3ha7bvdks28g8z4d.nar.zst error="server returned 404: 404 page not found\n"18012026/09/29 08:15:27 WARN Failed to register uploaded object key=imxana0ph07nd19gfnxc8aqsg054qh4q.ls error="server returned 404: 404 page not found\n"18022026/09/29 08:15:27 WARN Failed to register uploaded object key=31nl0x53zga4qcmbckw7dsxv620lvbyp.ls error="server returned 404: 404 page not found\n"18032026/09/29 08:15:27 INFO Signed narinfos id=1 count=218042026/09/29 08:15:27 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18052026/09/29 08:15:27 INFO Signed narinfos id=2 count=218062026/09/29 08:15:27 INFO Uploading 4 narinfos18072026/09/29 08:15:27 OK 20260905000000_add_claims.sql (61.75ms)18082026/09/29 08:15:27 WARN Failed to register uploaded object key=31nl0x53zga4qcmbckw7dsxv620lvbyp.narinfo error="server returned 404: 404 page not found\n"18092026/09/29 08:15:27 WARN Failed to register uploaded object key=nvx5q7a26vpkv92qd33k8wh3d19xxldk.narinfo error="server returned 404: 404 page not found\n"18102026/09/29 08:15:27 WARN Failed to register uploaded object key=imxana0ph07nd19gfnxc8aqsg054qh4q.narinfo error="server returned 404: 404 page not found\n"1811--- PASS: TestGCBugBareHashReferences (2.67s)1812=== CONT TestService_ReadAuthMiddleware18132026/09/29 08:15:27 OK 20260920000000_drop_claims.sql (20.67ms)18142026/09/29 08:15:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18152026/09/29 08:15:27 WARN Failed to register uploaded object key=nvx5q7a26vpkv92qd33k8wh3d19xxldk.narinfo error="server returned 404: 404 page not found\n"18162026/09/29 08:15:27 OK 20260923120000_add_pushes.sql (12.24ms)18172026/09/29 08:15:27 goose: successfully migrated database to version: 2026092312000018182026/09/29 08:15:27 OK 1_commit_pending_closure.sql (1.1ms)18192026/09/29 08:15:27 OK 2_object_stats_trigger.sql (225.13µs)18202026/09/29 08:15:27 OK 3_commit_push.sql (170.38µs)18212026/09/29 08:15:27 goose: up to current file version: 318222026/09/29 08:15:27 INFO Completed upload id=118232026/09/29 08:15:27 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18242026/09/29 08:15:27 INFO Completed upload id=218252026/09/29 08:15:27 INFO Upload complete. (162ms)1826=== NAME TestClientFallsBackToClosures1827 client_pushes_test.go:112: Retrieved narinfo from S3:1828 StorePath: /nix/var/nix/builds/nix-1883-381732109/TestClientFallsBackToClosures3951406160/001/store/nvx5q7a26vpkv92qd33k8wh3d19xxldk-shared-dep1829 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1830 Compression: zstd1831 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821832 NarSize: 1361833 References: 1834 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1835 client_pushes_test.go:112: Retrieved narinfo from S3:1836 StorePath: /nix/var/nix/builds/nix-1883-381732109/TestClientFallsBackToClosures3951406160/001/store/31nl0x53zga4qcmbckw7dsxv620lvbyp-a1837 URL: nar/1aimsjawvilg7q2s69vmfxmzjrhbczvx034n3ha7bvdks28g8z4d.nar.zst1838 Compression: zstd1839 NarHash: sha256:1aimsjawvilg7q2s69vmfxmzjrhbczvx034n3ha7bvdks28g8z4d1840 NarSize: 2481841 References: /nix/var/nix/builds/nix-1883-381732109/TestClientFallsBackToClosures3951406160/001/store/nvx5q7a26vpkv92qd33k8wh3d19xxldk-shared-dep1842 CA: text:sha256:1giv55dhdzvina2m5pjbnq6amcmxgizqx6asci0xlig9irn4pr2h1843 client_pushes_test.go:112: Retrieved narinfo from S3:1844 StorePath: /nix/var/nix/builds/nix-1883-381732109/TestClientFallsBackToClosures3951406160/001/store/imxana0ph07nd19gfnxc8aqsg054qh4q-b1845 URL: nar/1aimsjawvilg7q2s69vmfxmzjrhbczvx034n3ha7bvdks28g8z4d.nar.zst1846 Compression: zstd1847 NarHash: sha256:1aimsjawvilg7q2s69vmfxmzjrhbczvx034n3ha7bvdks28g8z4d1848 NarSize: 2481849 References: /nix/var/nix/builds/nix-1883-381732109/TestClientFallsBackToClosures3951406160/001/store/nvx5q7a26vpkv92qd33k8wh3d19xxldk-shared-dep1850 CA: text:sha256:1giv55dhdzvina2m5pjbnq6amcmxgizqx6asci0xlig9irn4pr2h1851--- PASS: TestClientFallsBackToClosures (3.11s)1852=== CONT TestService_AuthMiddleware_MTLSProxyHeader18532026/09/29 08:15:27 OK 20241026095416_initial_model.sql (137.52ms)18542026/09/29 08:15:27 OK 20251210153512_drop_unused_gin_index.sql (20.81ms)18552026/09/29 08:15:27 OK 20251218171726_add_pins.sql (27.1ms)18562026/09/29 08:15:27 OK 20260628120000_add_object_size_and_stats.sql (24.25ms)18572026/09/29 08:15:27 INFO lead: acquired remote=192.0.2.1:123418582026/09/29 08:15:27 OK 20260905000000_add_claims.sql (43.89ms)18592026/09/29 08:15:27 OK 20260920000000_drop_claims.sql (8.43ms)18602026/09/29 08:15:27 OK 20260923120000_add_pushes.sql (11.17ms)18612026/09/29 08:15:27 goose: successfully migrated database to version: 2026092312000018622026/09/29 08:15:27 OK 1_commit_pending_closure.sql (1.48ms)18632026/09/29 08:15:27 OK 2_object_stats_trigger.sql (256.17µs)18642026/09/29 08:15:27 OK 3_commit_push.sql (223.08µs)18652026/09/29 08:15:27 goose: up to current file version: 318662026/09/29 08:15:27 INFO lead: released remote=192.0.2.1:123418672026/09/29 08:15:27 INFO lead: acquired remote=192.0.2.1:123418682026/09/29 08:15:27 INFO lead: released remote=192.0.2.1:12341869--- PASS: TestLeadElectsOneAndHandsOver (2.26s)1870=== CONT TestCreatePin_ReservedPins18712026/09/29 08:15:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55887/oidc18722026-09-29 08:15:27.746 UTC [2445] ERROR: relation "goose_db_version" does not exist at character 3618732026-09-29 08:15:27.746 UTC [2445] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1874=== NAME TestClientIntegration1875 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-1883-381732109/TestClientIntegration650699573/002/store/7wdrc5qhrgpfsflkx9cl4b51ggvprkqg-test-file.txt18762026/09/29 08:15:27 OK 20241026095416_initial_model.sql (160.5ms)18772026/09/29 08:15:27 OK 20251210153512_drop_unused_gin_index.sql (12.07ms)18782026/09/29 08:15:27 INFO Received push request method=POST path=/api/pushes18792026/09/29 08:15:27 OK 20251218171726_add_pins.sql (37.94ms)18802026/09/29 08:15:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18812026/09/29 08:15:28 INFO Uploading 7wdrc5qhrgpfsflkx9cl4b51ggvprkqg-test-file.txt (152B)18822026/09/29 08:15:28 WARN Failed to register uploaded object key=7wdrc5qhrgpfsflkx9cl4b51ggvprkqg.ls error="server returned 404: 404 page not found\n"18832026/09/29 08:15:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18842026/09/29 08:15:28 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"18852026/09/29 08:15:28 INFO Signed narinfos id=1 count=118862026/09/29 08:15:28 INFO Uploading 1 narinfos18872026/09/29 08:15:28 OK 20260628120000_add_object_size_and_stats.sql (79.59ms)18882026/09/29 08:15:28 INFO Received complete push request method=POST path=/api/pushes/1/complete18892026/09/29 08:15:28 WARN Failed to register uploaded object key=7wdrc5qhrgpfsflkx9cl4b51ggvprkqg.narinfo error="server returned 404: 404 page not found\n"18902026/09/29 08:15:28 INFO Upload complete. (206ms)1891=== NAME TestClientMultipleUploads1892 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-1883-381732109/TestClientMultipleUploads1990599249/001/store/a15dknpi6l8g9sf5qyk4jqp6anad96m4-test-file-0.txt18932026/09/29 08:15:28 OK 20260905000000_add_claims.sql (55.11ms)18942026/09/29 08:15:28 OK 20260920000000_drop_claims.sql (21.42ms)18952026/09/29 08:15:28 INFO All 1 paths already cached1896=== NAME TestClientIntegration1897 client_integration_test.go:312: Retrieved narinfo from S3:1898 StorePath: /nix/var/nix/builds/nix-1883-381732109/TestClientIntegration650699573/002/store/7wdrc5qhrgpfsflkx9cl4b51ggvprkqg-test-file.txt1899 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1900 Compression: zstd1901 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11902 NarSize: 1521903 References: 1904 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11905 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1906 client_integration_test.go:313: Decompressed .ls content (64 bytes):1907 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1908 client_integration_test.go:316: Testing garbage collection...19092026/09/29 08:15:28 OK 20260923120000_add_pushes.sql (12.25ms)19102026/09/29 08:15:28 goose: successfully migrated database to version: 2026092312000019112026/09/29 08:15:28 OK 1_commit_pending_closure.sql (2.42ms)19122026/09/29 08:15:28 OK 2_object_stats_trigger.sql (1.18ms)19132026/09/29 08:15:28 OK 3_commit_push.sql (1.29ms)19142026/09/29 08:15:28 goose: up to current file version: 319152026-09-29 08:15:28.176 UTC [2460] ERROR: relation "goose_db_version" does not exist at character 3619162026-09-29 08:15:28.176 UTC [2460] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1917=== NAME TestClientMultipleUploads1918 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-1883-381732109/TestClientMultipleUploads1990599249/001/store/bdxhdir266fh6mxhnzhdvjbxbihchklr-test-file-1.txt19192026/09/29 08:15:28 INFO Starting cleanup of old closures method=DELETE path=/api/closures19202026/09/29 08:15:28 INFO Garbage collection started19212026/09/29 08:15:28 INFO Aborted multipart uploads count=019222026/09/29 08:15:28 WARN Force mode enabled - objects will be deleted immediately without grace period1923 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-1883-381732109/TestClientMultipleUploads1990599249/001/store/hlap9s4v19djbdsnhdwkn1kpgxjgxvvs-test-file-2.txt19242026/09/29 08:15:28 OK 20241026095416_initial_model.sql (61.02ms)19252026/09/29 08:15:28 OK 20251210153512_drop_unused_gin_index.sql (5.83ms)19262026/09/29 08:15:28 OK 20251218171726_add_pins.sql (23.5ms)19272026/09/29 08:15:28 OK 20260628120000_add_object_size_and_stats.sql (15.13ms)19282026/09/29 08:15:28 OK 20260905000000_add_claims.sql (29.81ms)1929--- PASS: TestReadProxy404 (1.94s)1930=== CONT TestService_AuthMiddleware_MTLSBoundSubjects19312026/09/29 08:15:28 OK 20260920000000_drop_claims.sql (18.77ms)19322026/09/29 08:15:28 INFO Received push request method=POST path=/api/pushes19332026/09/29 08:15:28 OK 20260923120000_add_pushes.sql (13.37ms)19342026/09/29 08:15:28 goose: successfully migrated database to version: 2026092312000019352026/09/29 08:15:28 OK 1_commit_pending_closure.sql (1.57ms)19362026/09/29 08:15:28 OK 2_object_stats_trigger.sql (453.21µs)19372026/09/29 08:15:28 OK 3_commit_push.sql (470.17µs)19382026/09/29 08:15:28 goose: up to current file version: 319392026/09/29 08:15:28 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)19402026/09/29 08:15:28 INFO Uploading bdxhdir266fh6mxhnzhdvjbxbihchklr-test-file-1.txt (160B)19412026/09/29 08:15:28 INFO Uploading hlap9s4v19djbdsnhdwkn1kpgxjgxvvs-test-file-2.txt (160B)19422026/09/29 08:15:28 INFO Uploading a15dknpi6l8g9sf5qyk4jqp6anad96m4-test-file-0.txt (160B)19432026/09/29 08:15:28 WARN Failed to register uploaded object key=a15dknpi6l8g9sf5qyk4jqp6anad96m4.ls error="server returned 404: 404 page not found\n"19442026/09/29 08:15:28 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"19452026/09/29 08:15:28 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"19462026/09/29 08:15:28 WARN Failed to register uploaded object key=bdxhdir266fh6mxhnzhdvjbxbihchklr.ls error="server returned 404: 404 page not found\n"19472026/09/29 08:15:28 WARN Failed to register uploaded object key=hlap9s4v19djbdsnhdwkn1kpgxjgxvvs.ls error="server returned 404: 404 page not found\n"19482026/09/29 08:15:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19492026/09/29 08:15:28 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"19502026/09/29 08:15:28 INFO Signed narinfos id=1 count=319512026/09/29 08:15:28 INFO Uploading 3 narinfos19522026/09/29 08:15:28 WARN Failed to register uploaded object key=hlap9s4v19djbdsnhdwkn1kpgxjgxvvs.narinfo error="server returned 404: 404 page not found\n"19532026/09/29 08:15:28 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=019542026/09/29 08:15:28 WARN Failed to register uploaded object key=bdxhdir266fh6mxhnzhdvjbxbihchklr.narinfo error="server returned 404: 404 page not found\n"19552026/09/29 08:15:28 INFO Received complete push request method=POST path=/api/pushes/1/complete19562026/09/29 08:15:28 WARN Failed to register uploaded object key=a15dknpi6l8g9sf5qyk4jqp6anad96m4.narinfo error="server returned 404: 404 page not found\n"19572026/09/29 08:15:28 INFO Upload complete. (179ms)1958=== NAME TestClientMultipleUploads1959 client_integration_test.go:369: Uploaded 3 paths in 221.346667ms19602026/09/29 08:15:28 INFO Vacuumed table table=pending_closures19612026/09/29 08:15:28 INFO Vacuumed table table=pending_objects19622026/09/29 08:15:28 INFO Vacuumed table table=multipart_uploads19632026/09/29 08:15:28 INFO Vacuumed table table=closures1964--- PASS: TestClientMultipleUploads (2.75s)1965=== CONT TestProxyHeadersOnlyTrustedOnSocket19662026/09/29 08:15:28 INFO Vacuumed table table=objects1967--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.98s)1968=== CONT TestService_AuthMiddleware_OIDC19692026/09/29 08:15:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55916/oidc19702026-09-29 08:15:28.682 UTC [2475] ERROR: relation "goose_db_version" does not exist at character 3619712026-09-29 08:15:28.682 UTC [2475] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19722026-09-29 08:15:28.682 UTC [2476] ERROR: relation "goose_db_version" does not exist at character 3619732026-09-29 08:15:28.682 UTC [2476] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19742026-09-29 08:15:28.685 UTC [2477] ERROR: relation "goose_db_version" does not exist at character 3619752026-09-29 08:15:28.685 UTC [2477] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19762026-09-29 08:15:28.690 UTC [2479] ERROR: relation "goose_db_version" does not exist at character 3619772026-09-29 08:15:28.690 UTC [2479] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19782026/09/29 08:15:28 OK 20241026095416_initial_model.sql (18.38ms)19792026/09/29 08:15:28 OK 20251210153512_drop_unused_gin_index.sql (635.42µs)19802026/09/29 08:15:28 OK 20251218171726_add_pins.sql (3.77ms)19812026/09/29 08:15:28 OK 20241026095416_initial_model.sql (13.8ms)19822026/09/29 08:15:28 OK 20251210153512_drop_unused_gin_index.sql (847.08µs)19832026/09/29 08:15:28 OK 20260628120000_add_object_size_and_stats.sql (3.41ms)19842026/09/29 08:15:28 OK 20241026095416_initial_model.sql (8.88ms)19852026/09/29 08:15:28 OK 20241026095416_initial_model.sql (17.3ms)19862026/09/29 08:15:28 OK 20251210153512_drop_unused_gin_index.sql (929.08µs)19872026/09/29 08:15:28 OK 20251218171726_add_pins.sql (2.68ms)19882026/09/29 08:15:28 OK 20251210153512_drop_unused_gin_index.sql (436.75µs)19892026/09/29 08:15:28 OK 20260628120000_add_object_size_and_stats.sql (3.06ms)19902026/09/29 08:15:28 OK 20251218171726_add_pins.sql (3.24ms)19912026/09/29 08:15:28 OK 20251218171726_add_pins.sql (3.97ms)19922026/09/29 08:15:28 OK 20260905000000_add_claims.sql (6.39ms)19932026/09/29 08:15:28 OK 20260905000000_add_claims.sql (2.64ms)19942026/09/29 08:15:28 OK 20260920000000_drop_claims.sql (1.52ms)19952026/09/29 08:15:28 OK 20260920000000_drop_claims.sql (1.3ms)19962026/09/29 08:15:28 OK 20260923120000_add_pushes.sql (624.96µs)19972026/09/29 08:15:28 goose: successfully migrated database to version: 2026092312000019982026/09/29 08:15:28 OK 20260628120000_add_object_size_and_stats.sql (4.96ms)19992026/09/29 08:15:28 OK 20260923120000_add_pushes.sql (2.09ms)20002026/09/29 08:15:28 goose: successfully migrated database to version: 2026092312000020012026/09/29 08:15:28 OK 1_commit_pending_closure.sql (1.59ms)20022026/09/29 08:15:28 OK 2_object_stats_trigger.sql (496.63µs)20032026/09/29 08:15:28 OK 3_commit_push.sql (382.42µs)20042026/09/29 08:15:28 goose: up to current file version: 320052026/09/29 08:15:28 OK 1_commit_pending_closure.sql (1.5ms)20062026/09/29 08:15:28 OK 2_object_stats_trigger.sql (358.5µs)20072026/09/29 08:15:28 OK 3_commit_push.sql (286.63µs)20082026/09/29 08:15:28 goose: up to current file version: 320092026/09/29 08:15:28 OK 20260628120000_add_object_size_and_stats.sql (27.73ms)20102026/09/29 08:15:28 OK 20260905000000_add_claims.sql (48.11ms)20112026/09/29 08:15:28 OK 20260905000000_add_claims.sql (25.87ms)20122026/09/29 08:15:28 OK 20260920000000_drop_claims.sql (22.19ms)20132026/09/29 08:15:28 OK 20260920000000_drop_claims.sql (22.25ms)20142026-09-29 08:15:28.794 UTC [2481] ERROR: relation "goose_db_version" does not exist at character 3620152026-09-29 08:15:28.794 UTC [2481] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20162026/09/29 08:15:28 OK 20260923120000_add_pushes.sql (7.37ms)20172026/09/29 08:15:28 goose: successfully migrated database to version: 2026092312000020182026/09/29 08:15:28 OK 20260923120000_add_pushes.sql (7.41ms)20192026/09/29 08:15:28 goose: successfully migrated database to version: 2026092312000020202026/09/29 08:15:28 OK 1_commit_pending_closure.sql (1ms)20212026/09/29 08:15:28 OK 1_commit_pending_closure.sql (1.14ms)20222026/09/29 08:15:28 OK 2_object_stats_trigger.sql (268.71µs)20232026/09/29 08:15:28 OK 2_object_stats_trigger.sql (254.83µs)20242026/09/29 08:15:28 OK 3_commit_push.sql (251.83µs)20252026/09/29 08:15:28 goose: up to current file version: 320262026/09/29 08:15:28 OK 3_commit_push.sql (261.5µs)20272026/09/29 08:15:28 goose: up to current file version: 32028--- PASS: TestReadProxyNarStreaming (1.68s)2029=== CONT TestParseSingleRange2030=== RUN TestParseSingleRange/none2031=== PAUSE TestParseSingleRange/none2032=== RUN TestParseSingleRange/unknown_unit2033=== PAUSE TestParseSingleRange/unknown_unit2034=== RUN TestParseSingleRange/multi-range_ignored2035=== PAUSE TestParseSingleRange/multi-range_ignored2036=== RUN TestParseSingleRange/malformed_no_dash2037=== PAUSE TestParseSingleRange/malformed_no_dash2038=== RUN TestParseSingleRange/malformed_both_empty2039=== PAUSE TestParseSingleRange/malformed_both_empty2040=== RUN TestParseSingleRange/malformed_end_before_start2041=== PAUSE TestParseSingleRange/malformed_end_before_start2042=== RUN TestParseSingleRange/closed2043=== PAUSE TestParseSingleRange/closed2044=== RUN TestParseSingleRange/open-ended2045=== PAUSE TestParseSingleRange/open-ended2046=== RUN TestParseSingleRange/end_clamped_to_size2047=== PAUSE TestParseSingleRange/end_clamped_to_size2048=== RUN TestParseSingleRange/suffix2049=== PAUSE TestParseSingleRange/suffix2050=== RUN TestParseSingleRange/suffix_exceeds_size2051=== PAUSE TestParseSingleRange/suffix_exceeds_size2052=== RUN TestParseSingleRange/single_byte2053=== PAUSE TestParseSingleRange/single_byte2054=== RUN TestParseSingleRange/start_past_EOF2055=== PAUSE TestParseSingleRange/start_past_EOF2056=== RUN TestParseSingleRange/start_far_past_EOF2057=== PAUSE TestParseSingleRange/start_far_past_EOF2058=== CONT TestClientErrorHandling2059=== RUN TestClientErrorHandling/InvalidStorePath2060=== PAUSE TestClientErrorHandling/InvalidStorePath2061=== RUN TestClientErrorHandling/InvalidAuthToken2062=== PAUSE TestClientErrorHandling/InvalidAuthToken2063=== RUN TestClientErrorHandling/ServerNotAvailable2064=== PAUSE TestClientErrorHandling/ServerNotAvailable2065=== CONT TestCacheConfigHandler2066=== RUN TestCacheConfigHandler/full_config,_no_issuer2067=== PAUSE TestCacheConfigHandler/full_config,_no_issuer2068=== RUN TestCacheConfigHandler/no_cache_url_configured2069=== PAUSE TestCacheConfigHandler/no_cache_url_configured2070=== RUN TestCacheConfigHandler/no_signing_keys2071=== PAUSE TestCacheConfigHandler/no_signing_keys2072=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2073=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2074=== CONT TestCacheStatsHandler20752026/09/29 08:15:28 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02076=== NAME TestPinProtectsFromGC2077 client_integration_test.go:794: Pin successfully protected closure from garbage collection20782026/09/29 08:15:28 OK 20241026095416_initial_model.sql (80.38ms)20792026/09/29 08:15:28 OK 20251210153512_drop_unused_gin_index.sql (7.53ms)20802026/09/29 08:15:28 OK 20251218171726_add_pins.sql (16.88ms)2081--- PASS: TestPinProtectsFromGC (5.31s)2082=== CONT TestResurrectedObjectNotDeleted20832026/09/29 08:15:28 OK 20260628120000_add_object_size_and_stats.sql (34.15ms)20842026/09/29 08:15:28 OK 20260905000000_add_claims.sql (17.06ms)20852026/09/29 08:15:28 OK 20260920000000_drop_claims.sql (11.63ms)20862026/09/29 08:15:28 OK 20260923120000_add_pushes.sql (5.95ms)20872026/09/29 08:15:28 goose: successfully migrated database to version: 2026092312000020882026/09/29 08:15:28 OK 1_commit_pending_closure.sql (1.09ms)20892026/09/29 08:15:28 OK 2_object_stats_trigger.sql (205.58µs)20902026/09/29 08:15:28 OK 3_commit_push.sql (166.04µs)20912026/09/29 08:15:28 goose: up to current file version: 32092--- PASS: TestService_ReadAuthMiddleware (1.83s)2093=== CONT TestService_RequireScope_OIDC20942026/09/29 08:15:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55925/oidc2095--- PASS: TestReadProxyNarinfo (2.06s)2096=== CONT TestOrphanedObjectsGCStressTest2097--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (2.09s)2098=== CONT TestClientCADerivations20992026-09-29 08:15:29.431 UTC [2554] ERROR: relation "goose_db_version" does not exist at character 3621002026-09-29 08:15:29.431 UTC [2554] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21012026/09/29 08:15:29 OK 20241026095416_initial_model.sql (68.42ms)21022026/09/29 08:15:29 OK 20251210153512_drop_unused_gin_index.sql (11.42ms)21032026/09/29 08:15:29 OK 20251218171726_add_pins.sql (7.97ms)21042026/09/29 08:15:29 OK 20260628120000_add_object_size_and_stats.sql (24.25ms)21052026-09-29 08:15:29.627 UTC [2557] ERROR: relation "goose_db_version" does not exist at character 3621062026-09-29 08:15:29.627 UTC [2557] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21072026/09/29 08:15:29 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux21082026/09/29 08:15:29 WARN Refused reserved pin name=worker-x86_64-linux21092026/09/29 08:15:29 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux21102026/09/29 08:15:29 INFO Received create pin request method=POST path=/api/pins/my-app21112026/09/29 08:15:29 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux2112--- PASS: TestCreatePin_ReservedPins (2.01s)2113=== CONT TestService_ReadScope_PublicByDefault21142026/09/29 08:15:29 OK 20260905000000_add_claims.sql (29.06ms)21152026/09/29 08:15:29 OK 20260920000000_drop_claims.sql (15.66ms)21162026/09/29 08:15:29 OK 20260923120000_add_pushes.sql (3.2ms)21172026/09/29 08:15:29 goose: successfully migrated database to version: 2026092312000021182026/09/29 08:15:29 OK 1_commit_pending_closure.sql (2.42ms)21192026/09/29 08:15:29 OK 2_object_stats_trigger.sql (492.38µs)21202026/09/29 08:15:29 OK 3_commit_push.sql (399.33µs)21212026/09/29 08:15:29 goose: up to current file version: 321222026-09-29 08:15:29.693 UTC [2560] ERROR: relation "goose_db_version" does not exist at character 3621232026-09-29 08:15:29.693 UTC [2560] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21242026/09/29 08:15:29 OK 20241026095416_initial_model.sql (53.82ms)21252026/09/29 08:15:29 OK 20251210153512_drop_unused_gin_index.sql (6.24ms)21262026/09/29 08:15:29 OK 20251218171726_add_pins.sql (14.97ms)21272026/09/29 08:15:29 OK 20260628120000_add_object_size_and_stats.sql (18.6ms)21282026/09/29 08:15:29 OK 20260905000000_add_claims.sql (17.49ms)21292026/09/29 08:15:29 OK 20241026095416_initial_model.sql (52.44ms)21302026/09/29 08:15:29 OK 20251210153512_drop_unused_gin_index.sql (6.92ms)21312026/09/29 08:15:29 OK 20260920000000_drop_claims.sql (30.98ms)21322026/09/29 08:15:29 OK 20251218171726_add_pins.sql (25.55ms)21332026/09/29 08:15:29 OK 20260923120000_add_pushes.sql (3.14ms)21342026/09/29 08:15:29 goose: successfully migrated database to version: 2026092312000021352026/09/29 08:15:29 OK 1_commit_pending_closure.sql (848.13µs)21362026/09/29 08:15:29 OK 2_object_stats_trigger.sql (180.17µs)21372026/09/29 08:15:29 OK 3_commit_push.sql (148.33µs)21382026/09/29 08:15:29 goose: up to current file version: 321392026/09/29 08:15:29 OK 20260628120000_add_object_size_and_stats.sql (32.93ms)21402026/09/29 08:15:29 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"21412026/09/29 08:15:29 WARN mTLS auth: bound subjects configured but subject DN unavailable21422026/09/29 08:15:29 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2143--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.51s)2144=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info21452026/09/29 08:15:29 INFO Received uploads request method=POST path=/2146=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key21472026/09/29 08:15:29 INFO Received complete multipart upload request method=POST path=/2148=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key21492026/09/29 08:15:29 INFO Received request for more parts method=POST path=/2150=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal21512026/09/29 08:15:29 INFO Received uploads request method=POST path=/2152--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2153 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2154 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2155 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2156 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2157=== CONT TestIsValidUploadKey/narinfo2158=== CONT TestProxyWriteTimeout/narinfo2159=== CONT TestIsValidUploadKey/unknown_type2160=== CONT TestIsValidUploadKey/empty_key2161=== CONT TestIsValidUploadKey/absolute2162=== CONT TestIsValidUploadKey/build_log_plus_in_name2163=== CONT TestIsValidUploadKey/build_log_home-manager_file2164=== CONT TestIsValidUploadKey/build_log2165=== CONT TestIsValidUploadKey/listing2166=== CONT TestIsValidUploadKey/nar_plain2167=== CONT TestIsValidUploadKey/nar_xz2168=== CONT TestIsValidUploadKey/nar_zst2169=== CONT TestIsValidUploadKey/build_log_question_mark2170=== CONT TestIsValidUploadKey/traversal_nar2171=== CONT TestIsValidUploadKey/traversal2172=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2173=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2174=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2175=== CONT TestIsValidUploadKey/index.html2176=== CONT TestIsValidUploadKey/nix-cache-info2177=== CONT TestIsValidUploadKey/realisation_plus_in_output2178=== CONT TestIsValidUploadKey/realisation2179=== CONT TestIsValidUploadKey/build_log_equals2180--- PASS: TestIsValidUploadKey (0.02s)2181 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2182 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2183 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2184 --- PASS: TestIsValidUploadKey/absolute (0.00s)2185 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2186 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2187 --- PASS: TestIsValidUploadKey/build_log (0.00s)2188 --- PASS: TestIsValidUploadKey/listing (0.00s)2189 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2190 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2191 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2192 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2193 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2194 --- PASS: TestIsValidUploadKey/traversal (0.00s)2195 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2196 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2197 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2198 --- PASS: TestIsValidUploadKey/index.html (0.00s)2199 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2200 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2201 --- PASS: TestIsValidUploadKey/realisation (0.00s)2202 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2203=== CONT TestProxyWriteTimeout/10_GiB_nar2204=== CONT TestProxyWriteTimeout/unknown_size2205=== CONT TestProxyWriteTimeout/1_GiB_nar2206--- PASS: TestProxyWriteTimeout (0.00s)2207 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2208 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2209 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2210 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2211=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure22122026/09/29 08:15:29 INFO Received uploads request method=POST path=/22132026/09/29 08:15:29 OK 20260905000000_add_claims.sql (34.94ms)22142026/09/29 08:15:29 OK 20260920000000_drop_claims.sql (24.57ms)22152026/09/29 08:15:29 OK 20260923120000_add_pushes.sql (3.13ms)22162026/09/29 08:15:29 goose: successfully migrated database to version: 2026092312000022172026/09/29 08:15:29 OK 1_commit_pending_closure.sql (848.58µs)22182026/09/29 08:15:29 OK 2_object_stats_trigger.sql (205.83µs)22192026/09/29 08:15:29 OK 3_commit_push.sql (154.71µs)22202026/09/29 08:15:29 goose: up to current file version: 322212026-09-29 08:15:29.987 UTC [2563] ERROR: relation "goose_db_version" does not exist at character 3622222026-09-29 08:15:29.987 UTC [2563] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22232026-09-29 08:15:30.008 UTC [2569] ERROR: relation "goose_db_version" does not exist at character 3622242026-09-29 08:15:30.008 UTC [2569] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22252026/09/29 08:15:30 INFO Starting HTTP server address=/nix/var/nix/builds/nix-1883-381732109/TestProxyHeadersOnlyTrustedOnSocket1979049315/001/proxy.sock22262026/09/29 08:15:30 INFO Starting HTTP server address=127.0.0.1:5593422272026/09/29 08:15:30 WARN mTLS auth: subject not in bound subjects subject="CN=someone"22282026/09/29 08:15:30 INFO Shutdown signal received, draining in-flight requests timeout=10s2229--- PASS: TestProxyHeadersOnlyTrustedOnSocket (1.48s)2230=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts22312026/09/29 08:15:30 INFO Received request for more parts method=POST path=/2232=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart22332026/09/29 08:15:30 INFO Received complete multipart upload request method=POST path=/2234=== CONT TestServerTLSConfig/no_client_CA2235=== CONT TestServerTLSConfig/missing_CA_file2236=== CONT TestServerTLSConfig/not_a_PEM_file2237--- PASS: TestServerTLSConfig (0.00s)2238 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2239 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2240 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)2241=== CONT TestPush_RejectsBadRequests/root_not_in_objects22422026/09/29 08:15:30 INFO Received push request method=POST path=/api/pushes2243=== CONT TestPush_RejectsBadRequests/no_objects22442026/09/29 08:15:30 INFO Received push request method=POST path=/api/pushes2245=== CONT TestPush_RejectsBadRequests/bad_root22462026/09/29 08:15:30 INFO Received push request method=POST path=/api/pushes2247=== CONT TestPush_RejectsBadRequests/no_roots22482026/09/29 08:15:30 INFO Received push request method=POST path=/api/pushes2249--- PASS: TestPush_RejectsBadRequests (2.47s)2250 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2251 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2252 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2253 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2254=== CONT TestResolveDBConnectionString/flag_wins2255=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2256=== CONT TestResolveDBConnectionString/nothing_configured2257=== CONT TestResolveDBConnectionString/missing_file_is_an_error2258=== CONT TestResolveDBConnectionString/file_when_flag_empty2259=== CONT TestIsValidCachePath/narinfo2260=== CONT TestIsValidCachePath/index.html2261=== CONT TestIsValidCachePath/short_hash2262=== CONT TestIsValidCachePath/wrong_extension2263=== CONT TestIsValidCachePath/leading_slash2264=== CONT TestIsValidCachePath/empty2265=== CONT TestIsValidCachePath/random_path2266=== CONT TestIsValidCachePath/invalid_char_u2267=== CONT TestIsValidCachePath/invalid_char_e2268=== CONT TestIsValidCachePath/traversal_in_middle2269=== CONT TestIsValidCachePath/traversal_parent2270=== CONT TestIsValidCachePath/nar_uncompressed2271=== CONT TestIsValidCachePath/nix-cache-info2272=== CONT TestIsValidCachePath/realisation2273=== CONT TestIsValidCachePath/log2274=== CONT TestIsValidCachePath/ls2275=== CONT TestIsValidCachePath/nar_xz2276=== CONT TestIsValidCachePath/nar_bz22277=== CONT TestIsValidCachePath/nar_zst2278=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2279--- PASS: TestIsValidCachePath (0.00s)2280 --- PASS: TestIsValidCachePath/narinfo (0.00s)2281 --- PASS: TestIsValidCachePath/index.html (0.00s)2282 --- PASS: TestIsValidCachePath/short_hash (0.00s)2283 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2284 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2285 --- PASS: TestIsValidCachePath/empty (0.00s)2286 --- PASS: TestIsValidCachePath/random_path (0.00s)2287 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2288 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2289 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2290 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2291 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2292 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2293 --- PASS: TestIsValidCachePath/realisation (0.00s)2294 --- PASS: TestIsValidCachePath/log (0.00s)2295 --- PASS: TestIsValidCachePath/ls (0.00s)2296 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2297 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2298 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2299 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2300=== CONT TestParseSingleRange/none2301=== CONT TestClientErrorHandling/InvalidStorePath2302--- PASS: TestResolveDBConnectionString (0.02s)2303 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2304 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2305 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2306 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2307 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)23082026/09/29 08:15:30 OK 20241026095416_initial_model.sql (88.31ms)23092026/09/29 08:15:30 OK 20251210153512_drop_unused_gin_index.sql (3.11ms)23102026/09/29 08:15:30 OK 20251218171726_add_pins.sql (12.56ms)23112026/09/29 08:15:30 OK 20260628120000_add_object_size_and_stats.sql (20.91ms)2312=== CONT TestParseSingleRange/closed2313--- PASS: TestUploadHandlersRejectOversizedBody (0.03s)2314 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)2315 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)2316 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.32s)2317=== CONT TestParseSingleRange/malformed_end_before_start2318=== CONT TestParseSingleRange/malformed_both_empty2319=== CONT TestParseSingleRange/malformed_no_dash2320=== CONT TestParseSingleRange/multi-range_ignored2321=== CONT TestParseSingleRange/open-ended2322=== CONT TestParseSingleRange/start_far_past_EOF2323=== CONT TestParseSingleRange/unknown_unit2324=== CONT TestParseSingleRange/start_past_EOF2325=== CONT TestClientErrorHandling/InvalidAuthToken23262026/09/29 08:15:30 OK 20241026095416_initial_model.sql (79.01ms)23272026/09/29 08:15:30 OK 20251210153512_drop_unused_gin_index.sql (6.85ms)23282026/09/29 08:15:30 OK 20260905000000_add_claims.sql (29.34ms)23292026/09/29 08:15:30 OK 20251218171726_add_pins.sql (13.4ms)23302026/09/29 08:15:30 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02331=== NAME TestClientIntegration2332 client_integration_test.go:323: Objects in database after GC:2333 client_integration_test.go:323: Successfully deleted all objects with GC --force23342026/09/29 08:15:30 OK 20260920000000_drop_claims.sql (17.23ms)23352026/09/29 08:15:30 OK 20260628120000_add_object_size_and_stats.sql (35.87ms)23362026/09/29 08:15:30 OK 20260923120000_add_pushes.sql (18.76ms)23372026/09/29 08:15:30 goose: successfully migrated database to version: 2026092312000023382026/09/29 08:15:30 OK 1_commit_pending_closure.sql (1.21ms)23392026/09/29 08:15:30 OK 2_object_stats_trigger.sql (211.71µs)23402026/09/29 08:15:30 OK 3_commit_push.sql (152.75µs)23412026/09/29 08:15:30 goose: up to current file version: 32342--- PASS: TestClientIntegration (4.64s)2343=== CONT TestParseSingleRange/single_byte2344=== CONT TestParseSingleRange/end_clamped_to_size2345=== CONT TestParseSingleRange/suffix_exceeds_size2346=== CONT TestParseSingleRange/suffix2347--- PASS: TestParseSingleRange (0.00s)2348 --- PASS: TestParseSingleRange/none (0.00s)2349 --- PASS: TestParseSingleRange/closed (0.00s)2350 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2351 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2352 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2353 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2354 --- PASS: TestParseSingleRange/open-ended (0.00s)2355 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2356 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2357 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2358 --- PASS: TestParseSingleRange/single_byte (0.00s)2359 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2360 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2361 --- PASS: TestParseSingleRange/suffix (0.00s)2362=== CONT TestClientErrorHandling/ServerNotAvailable23632026/09/29 08:15:30 OK 20260905000000_add_claims.sql (35.5ms)2364=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2365=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2366=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2367=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2368=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2369=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2370=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2371=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2372=== CONT TestCacheConfigHandler/full_config,_no_issuer2373=== CONT TestCacheConfigHandler/no_signing_keys2374=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2375=== CONT TestCacheConfigHandler/no_cache_url_configured2376--- PASS: TestCacheConfigHandler (0.00s)2377 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2378 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2379 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2380 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2381=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2382=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected23832026/09/29 08:15:30 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]2384=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2385=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected23862026/09/29 08:15:30 WARN Authentication failed token_preview=eyJhbGciOi...Vv4Sp2-_Ww token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2387--- PASS: TestService_AuthMiddleware_OIDC (1.65s)2388 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2389 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2390 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2391 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)23922026/09/29 08:15:30 OK 20260920000000_drop_claims.sql (45.81ms)23932026/09/29 08:15:30 OK 20260923120000_add_pushes.sql (15.55ms)23942026/09/29 08:15:30 goose: successfully migrated database to version: 2026092312000023952026/09/29 08:15:30 OK 1_commit_pending_closure.sql (1.93ms)23962026/09/29 08:15:30 OK 2_object_stats_trigger.sql (557.58µs)23972026/09/29 08:15:30 OK 3_commit_push.sql (510.67µs)23982026/09/29 08:15:30 goose: up to current file version: 323992026-09-29 08:15:30.401 UTC [2595] ERROR: relation "goose_db_version" does not exist at character 3624002026-09-29 08:15:30.401 UTC [2595] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24012026-09-29 08:15:30.402 UTC [2596] ERROR: relation "goose_db_version" does not exist at character 3624022026-09-29 08:15:30.402 UTC [2596] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24032026/09/29 08:15:30 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present24042026/09/29 08:15:30 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=218.404999ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2405--- PASS: TestCacheStatsHandler (1.67s)24062026/09/29 08:15:30 OK 20241026095416_initial_model.sql (125.01ms)24072026/09/29 08:15:30 OK 20241026095416_initial_model.sql (123.66ms)24082026/09/29 08:15:30 OK 20251210153512_drop_unused_gin_index.sql (2.39ms)24092026/09/29 08:15:30 OK 20251218171726_add_pins.sql (1.73ms)24102026/09/29 08:15:30 OK 20251210153512_drop_unused_gin_index.sql (7.12ms)24112026-09-29 08:15:30.573 UTC [2602] ERROR: relation "goose_db_version" does not exist at character 3624122026-09-29 08:15:30.573 UTC [2602] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24132026/09/29 08:15:30 OK 20251218171726_add_pins.sql (16.33ms)24142026/09/29 08:15:30 OK 20260628120000_add_object_size_and_stats.sql (27.29ms)24152026/09/29 08:15:30 OK 20260628120000_add_object_size_and_stats.sql (23.43ms)24162026/09/29 08:15:30 OK 20260905000000_add_claims.sql (32.44ms)24172026/09/29 08:15:30 OK 20260905000000_add_claims.sql (29.35ms)24182026/09/29 08:15:30 OK 20260920000000_drop_claims.sql (22.23ms)24192026/09/29 08:15:30 OK 20260920000000_drop_claims.sql (11.25ms)24202026/09/29 08:15:30 OK 20260923120000_add_pushes.sql (5.09ms)24212026/09/29 08:15:30 goose: successfully migrated database to version: 2026092312000024222026/09/29 08:15:30 OK 20260923120000_add_pushes.sql (5.66ms)24232026/09/29 08:15:30 goose: successfully migrated database to version: 2026092312000024242026/09/29 08:15:30 OK 1_commit_pending_closure.sql (2.3ms)24252026/09/29 08:15:30 OK 2_object_stats_trigger.sql (1.19ms)24262026/09/29 08:15:30 OK 1_commit_pending_closure.sql (2.02ms)24272026/09/29 08:15:30 OK 3_commit_push.sql (974.08µs)24282026/09/29 08:15:30 goose: up to current file version: 324292026/09/29 08:15:30 OK 2_object_stats_trigger.sql (1.88ms)24302026/09/29 08:15:30 OK 3_commit_push.sql (347.13µs)24312026/09/29 08:15:30 goose: up to current file version: 324322026/09/29 08:15:30 OK 20241026095416_initial_model.sql (96.81ms)24332026/09/29 08:15:30 OK 20251210153512_drop_unused_gin_index.sql (5.9ms)24342026/09/29 08:15:30 OK 20251218171726_add_pins.sql (9.75ms)24352026/09/29 08:15:30 OK 20260628120000_add_object_size_and_stats.sql (40.23ms)24362026/09/29 08:15:30 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=400.724433ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present24372026/09/29 08:15:30 OK 20260905000000_add_claims.sql (59.63ms)24382026-09-29 08:15:30.818 UTC [2650] ERROR: relation "goose_db_version" does not exist at character 3624392026-09-29 08:15:30.818 UTC [2650] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24402026/09/29 08:15:30 OK 20260920000000_drop_claims.sql (10.06ms)24412026/09/29 08:15:30 OK 20260923120000_add_pushes.sql (6.81ms)24422026/09/29 08:15:30 goose: successfully migrated database to version: 2026092312000024432026/09/29 08:15:30 OK 1_commit_pending_closure.sql (1.67ms)24442026/09/29 08:15:30 OK 2_object_stats_trigger.sql (632µs)24452026/09/29 08:15:30 OK 3_commit_push.sql (288.42µs)24462026/09/29 08:15:30 goose: up to current file version: 32447--- PASS: TestResurrectedObjectNotDeleted (1.96s)24482026/09/29 08:15:31 OK 20241026095416_initial_model.sql (156.56ms)24492026/09/29 08:15:31 OK 20251210153512_drop_unused_gin_index.sql (3.89ms)24502026/09/29 08:15:31 OK 20251218171726_add_pins.sql (13.63ms)24512026/09/29 08:15:31 OK 20260628120000_add_object_size_and_stats.sql (31.45ms)24522026/09/29 08:15:31 OK 20260905000000_add_claims.sql (68.63ms)24532026/09/29 08:15:31 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=808.041903ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present24542026/09/29 08:15:31 OK 20260920000000_drop_claims.sql (41.73ms)24552026/09/29 08:15:31 OK 20260923120000_add_pushes.sql (28.98ms)24562026/09/29 08:15:31 goose: successfully migrated database to version: 2026092312000024572026/09/29 08:15:31 OK 1_commit_pending_closure.sql (1.28ms)24582026/09/29 08:15:31 OK 2_object_stats_trigger.sql (308.67µs)24592026/09/29 08:15:31 OK 3_commit_push.sql (259.83µs)24602026/09/29 08:15:31 goose: up to current file version: 324612026-09-29 08:15:31.370 UTC [2691] ERROR: relation "goose_db_version" does not exist at character 3624622026-09-29 08:15:31.370 UTC [2691] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2463=== RUN TestService_RequireScope_OIDC/builder_may_write2464=== PAUSE TestService_RequireScope_OIDC/builder_may_write2465=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2466=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2467=== RUN TestService_RequireScope_OIDC/ops_may_admin2468=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2469=== RUN TestService_RequireScope_OIDC/ops_may_not_write2470=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2471=== RUN TestService_RequireScope_OIDC/reader_may_not_write2472=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2473=== RUN TestService_RequireScope_OIDC/static_token_may_admin2474=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2475=== RUN TestService_RequireScope_OIDC/static_token_may_write2476=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2477=== RUN TestService_RequireScope_OIDC/reader_may_read2478=== PAUSE TestService_RequireScope_OIDC/reader_may_read2479=== RUN TestService_RequireScope_OIDC/writer_implies_read2480=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2481=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2482=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2483=== CONT TestService_RequireScope_OIDC/builder_may_write2484=== CONT TestService_RequireScope_OIDC/static_token_may_admin2485=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2486=== CONT TestService_RequireScope_OIDC/writer_implies_read2487=== CONT TestService_RequireScope_OIDC/reader_may_read2488=== CONT TestService_RequireScope_OIDC/static_token_may_write2489=== CONT TestService_RequireScope_OIDC/reader_may_not_write2490=== CONT TestService_RequireScope_OIDC/ops_may_not_write2491=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2492=== CONT TestService_RequireScope_OIDC/ops_may_admin2493--- PASS: TestService_RequireScope_OIDC (2.32s)2494 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2495 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2496 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2497 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2498 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2499 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2500 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2501 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2502 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2503 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)25042026-09-29 08:15:31.497 UTC [2694] ERROR: relation "goose_db_version" does not exist at character 3625052026-09-29 08:15:31.497 UTC [2694] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25062026/09/29 08:15:31 OK 20241026095416_initial_model.sql (87.89ms)25072026/09/29 08:15:31 OK 20251210153512_drop_unused_gin_index.sql (1.35ms)25082026/09/29 08:15:31 OK 20251218171726_add_pins.sql (10.6ms)25092026/09/29 08:15:31 OK 20260628120000_add_object_size_and_stats.sql (11.88ms)25102026/09/29 08:15:31 OK 20241026095416_initial_model.sql (14.6ms)25112026/09/29 08:15:31 OK 20260905000000_add_claims.sql (11.61ms)25122026/09/29 08:15:31 OK 20251210153512_drop_unused_gin_index.sql (7.07ms)25132026/09/29 08:15:31 OK 20260920000000_drop_claims.sql (31.04ms)25142026/09/29 08:15:31 OK 20251218171726_add_pins.sql (29.55ms)25152026/09/29 08:15:31 OK 20260923120000_add_pushes.sql (6.3ms)25162026/09/29 08:15:31 goose: successfully migrated database to version: 2026092312000025172026/09/29 08:15:31 OK 1_commit_pending_closure.sql (975.71µs)25182026/09/29 08:15:31 OK 2_object_stats_trigger.sql (247.96µs)25192026/09/29 08:15:31 OK 3_commit_push.sql (189.67µs)25202026/09/29 08:15:31 goose: up to current file version: 325212026/09/29 08:15:31 OK 20260628120000_add_object_size_and_stats.sql (15.58ms)25222026/09/29 08:15:31 OK 20260905000000_add_claims.sql (54.35ms)25232026/09/29 08:15:31 OK 20260920000000_drop_claims.sql (26.42ms)25242026/09/29 08:15:31 OK 20260923120000_add_pushes.sql (11.17ms)25252026/09/29 08:15:31 goose: successfully migrated database to version: 2026092312000025262026/09/29 08:15:31 OK 1_commit_pending_closure.sql (932.25µs)25272026/09/29 08:15:31 OK 2_object_stats_trigger.sql (221.71µs)25282026/09/29 08:15:31 OK 3_commit_push.sql (173.21µs)25292026/09/29 08:15:31 goose: up to current file version: 32530--- PASS: TestService_ReadScope_PublicByDefault (2.24s)25312026/09/29 08:15:31 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.611271015s error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2532=== NAME TestClientCADerivations2533 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-1883-381732109/TestClientCADerivations2898422466/001/store/4pb42ba2zm3azgwmvw08a7bmnas6hpjv-ca-test2534 client_ca_test.go:139: Found 1 dependencies (including self)25352026/09/29 08:15:32 INFO Received push request method=POST path=/api/pushes25362026/09/29 08:15:32 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)25372026/09/29 08:15:32 INFO Uploading 4pb42ba2zm3azgwmvw08a7bmnas6hpjv-ca-test (144B)25382026/09/29 08:15:32 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"25392026/09/29 08:15:32 WARN Failed to register uploaded object key=4pb42ba2zm3azgwmvw08a7bmnas6hpjv.ls error="server returned 404: 404 page not found\n"25402026/09/29 08:15:32 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign25412026/09/29 08:15:32 WARN Failed to register uploaded object key=log/36r8hr6ggmb3n0bf8c7xwa5ajmwf3lrm-ca-test.drv error="server returned 404: 404 page not found\n"25422026/09/29 08:15:32 INFO Signed narinfos id=1 count=125432026/09/29 08:15:32 INFO Uploading 1 narinfos25442026/09/29 08:15:32 INFO Received complete push request method=POST path=/api/pushes/1/complete25452026/09/29 08:15:32 WARN Failed to register uploaded object key=4pb42ba2zm3azgwmvw08a7bmnas6hpjv.narinfo error="server returned 404: 404 page not found\n"25462026/09/29 08:15:32 INFO Upload complete. (155ms)2547 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-1883-381732109/TestClientCADerivations2898422466/001/store/4pb42ba2zm3azgwmvw08a7bmnas6hpjv-ca-test2548 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2549 Compression: zstd2550 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2551 NarSize: 1442552 References: 2553 Deriver: /nix/var/nix/builds/nix-1883-381732109/TestClientCADerivations2898422466/001/store/36r8hr6ggmb3n0bf8c7xwa5ajmwf3lrm-ca-test.drv2554 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2555 client_ca_test.go:185: Checking for realisation files in S3...2556 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2557 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache25582026/09/29 08:15:32 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2559 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket62?endpoint=http://localhost:55691®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-1883-381732109/TestClientCADerivations2898422466/001/store'2560 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 125612026/09/29 08:15:32 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2562--- PASS: TestClientCADerivations (3.02s)25632026/09/29 08:15:33 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25642026/09/29 08:15:33 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=215.326479ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2565=== NAME TestOrphanedObjectsGCStressTest2566 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2567 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion25682026/09/29 08:15:34 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=434.061385ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25692026/09/29 08:15:34 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=780.229538ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2570 orphaned_objects_gc_test.go:509: Stress test completed successfully:2571 orphaned_objects_gc_test.go:510: - Active objects preserved: 202572 orphaned_objects_gc_test.go:511: - Objects deleted: 2102573 orphaned_objects_gc_test.go:512: - Total GC'd: 2102574--- PASS: TestOrphanedObjectsGCStressTest (5.28s)25752026/09/29 08:15:35 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.453816692s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25762026/09/29 08:15:36 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 127.0.0.1:19999: connect: connection refused"25772026/09/29 08:15:36 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25782026/09/29 08:15:36 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=188.855145ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25792026/09/29 08:15:36 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=384.093214ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25802026/09/29 08:15:37 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=782.239576ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25812026/09/29 08:15:38 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.534360775s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25822026/09/29 08:15:39 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures25832026/09/29 08:15:39 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=209.540795ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures25842026/09/29 08:15:40 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=437.158273ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures25852026/09/29 08:15:40 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=859.295541ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures25862026/09/29 08:15:41 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.71514858s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2587--- PASS: TestClientErrorHandling (0.00s)2588 --- PASS: TestClientErrorHandling/InvalidStorePath (2.01s)2589 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.30s)2590 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.77s)2591PASS2592{"timestamp":"2026-09-29T08:15:43.030406Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:55753","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(5)"}25932026-09-29 08:15:43.375 UTC [1960] LOG: received smart shutdown request25942026-09-29 08:15:43.377 UTC [1960] LOG: background worker "logical replication launcher" (PID 1970) exited with exit code 125952026-09-29 08:15:43.381 UTC [1965] LOG: shutting down25962026-09-29 08:15:43.384 UTC [1965] LOG: checkpoint starting: shutdown immediate25972026-09-29 08:15:46.835 UTC [1965] LOG: checkpoint complete: wrote 12764 buffers (77.9%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 18 recycled; write=1.063 s, sync=2.316 s, total=3.454 s; sync files=21874, longest=0.070 s, average=0.001 s; distance=302638 kB, estimate=302638 kB; lsn=0/13F18778, redo lsn=0/13F1877825982026-09-29 08:15:46.848 UTC [1960] LOG: database system is shut down2599Running OIDC tests...2600=== RUN TestAudienceForIssuer2601=== PAUSE TestAudienceForIssuer2602=== RUN TestGlobMatch2603=== PAUSE TestGlobMatch2604=== RUN TestValidateToken_ValidToken2605=== PAUSE TestValidateToken_ValidToken2606=== RUN TestValidateToken_WrongAudience2607=== PAUSE TestValidateToken_WrongAudience2608=== RUN TestValidateToken_Expired2609=== PAUSE TestValidateToken_Expired2610=== RUN TestValidateToken_BoundClaimsMismatch2611=== PAUSE TestValidateToken_BoundClaimsMismatch2612=== RUN TestValidateToken_BoundSubjectMismatch2613=== PAUSE TestValidateToken_BoundSubjectMismatch2614=== RUN TestValidateToken_MultipleProviders2615=== PAUSE TestValidateToken_MultipleProviders2616=== RUN TestValidateToken_NoMatchingProvider2617=== PAUSE TestValidateToken_NoMatchingProvider2618=== RUN TestValidateToken_KubernetesServiceAccount2619=== PAUSE TestValidateToken_KubernetesServiceAccount2620=== RUN TestNewValidator_KubernetesRequiresCA2621=== PAUSE TestNewValidator_KubernetesRequiresCA2622=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2623=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2624=== RUN TestPins_ReservedForMatchingRule2625=== PAUSE TestPins_ReservedForMatchingRule2626=== RUN TestPins_TopLevelShorthand2627=== PAUSE TestPins_TopLevelShorthand2628=== RUN TestPins_ConfigValidation2629=== PAUSE TestPins_ConfigValidation2630=== RUN TestScopes_LegacyProviderDefaultsToWrite2631=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2632=== RUN TestScopes_Rules2633=== PAUSE TestScopes_Rules2634=== RUN TestScopes_ConfigValidation2635=== PAUSE TestScopes_ConfigValidation2636=== CONT TestAudienceForIssuer2637=== CONT TestValidateToken_BoundClaimsMismatch2638--- PASS: TestAudienceForIssuer (0.00s)2639=== CONT TestValidateToken_KubernetesServiceAccount2640=== CONT TestScopes_ConfigValidation2641=== CONT TestScopes_Rules2642=== CONT TestScopes_LegacyProviderDefaultsToWrite2643=== CONT TestPins_ConfigValidation2644=== CONT TestPins_TopLevelShorthand2645=== CONT TestPins_ReservedForMatchingRule2646=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2647=== CONT TestNewValidator_KubernetesRequiresCA2648--- PASS: TestScopes_ConfigValidation (0.00s)2649=== CONT TestValidateToken_Expired2650--- PASS: TestPins_ConfigValidation (0.00s)2651=== CONT TestValidateToken_MultipleProviders26522026/09/29 08:15:53 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:560202653--- PASS: TestValidateToken_KubernetesServiceAccount (0.04s)2654=== CONT TestValidateToken_NoMatchingProvider26552026/09/29 08:15:53 http: TLS handshake error from 127.0.0.1:56023: read tcp 127.0.0.1:56021->127.0.0.1:56023: use of closed network connection2656--- PASS: TestNewValidator_KubernetesRequiresCA (0.04s)2657=== CONT TestValidateToken_ValidToken26582026/09/29 08:15:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56024/oidc26592026/09/29 08:15:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56025/oidc2660--- PASS: TestPins_TopLevelShorthand (0.19s)2661=== CONT TestGlobMatch2662=== RUN TestGlobMatch/foo_foo2663=== PAUSE TestGlobMatch/foo_foo2664=== RUN TestGlobMatch/foo_bar2665=== PAUSE TestGlobMatch/foo_bar2666=== RUN TestGlobMatch/*_2667=== PAUSE TestGlobMatch/*_2668=== RUN TestGlobMatch/*_anything2669=== PAUSE TestGlobMatch/*_anything2670=== RUN TestGlobMatch/foo*_foo2671=== PAUSE TestGlobMatch/foo*_foo2672=== RUN TestGlobMatch/foo*_foobar2673=== PAUSE TestGlobMatch/foo*_foobar2674=== RUN TestGlobMatch/foo*_bar2675=== PAUSE TestGlobMatch/foo*_bar2676=== RUN TestGlobMatch/*bar_bar2677=== PAUSE TestGlobMatch/*bar_bar2678=== RUN TestGlobMatch/*bar_foobar2679=== PAUSE TestGlobMatch/*bar_foobar2680=== RUN TestGlobMatch/*bar_foo2681=== PAUSE TestGlobMatch/*bar_foo2682=== RUN TestGlobMatch/foo*bar_foobar2683=== PAUSE TestGlobMatch/foo*bar_foobar2684=== RUN TestGlobMatch/foo*bar_foo123bar2685=== PAUSE TestGlobMatch/foo*bar_foo123bar2686=== RUN TestGlobMatch/foo*bar_foobarbaz2687=== PAUSE TestGlobMatch/foo*bar_foobarbaz2688=== RUN TestGlobMatch/*/*_foo/bar2689=== PAUSE TestGlobMatch/*/*_foo/bar2690=== RUN TestGlobMatch/*/*_foo2691=== PAUSE TestGlobMatch/*/*_foo2692=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2693=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2694=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02695=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02696=== RUN TestGlobMatch/refs/*/main_refs/heads/main2697=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2698=== RUN TestGlobMatch/fo?_foo2699=== PAUSE TestGlobMatch/fo?_foo2700=== RUN TestGlobMatch/fo?_fo2701=== PAUSE TestGlobMatch/fo?_fo2702=== RUN TestGlobMatch/fo?_fooo2703=== PAUSE TestGlobMatch/fo?_fooo2704=== RUN TestGlobMatch/?oo_foo2705=== PAUSE TestGlobMatch/?oo_foo2706=== RUN TestGlobMatch/?oo_boo2707=== PAUSE TestGlobMatch/?oo_boo2708=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2709=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2710=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2711=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2712=== CONT TestValidateToken_BoundSubjectMismatch2713--- PASS: TestScopes_Rules (0.20s)2714=== CONT TestValidateToken_WrongAudience27152026/09/29 08:15:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56029/oidc2716--- PASS: TestPins_ReservedForMatchingRule (0.30s)2717=== CONT TestGlobMatch/foo_foo2718=== CONT TestGlobMatch/*/*_foo/bar2719=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2720=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2721=== CONT TestGlobMatch/?oo_boo2722=== CONT TestGlobMatch/?oo_foo2723=== CONT TestGlobMatch/fo?_fooo2724=== CONT TestGlobMatch/fo?_fo2725=== CONT TestGlobMatch/fo?_foo2726=== CONT TestGlobMatch/refs/*/main_refs/heads/main2727=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02728=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2729=== CONT TestGlobMatch/*/*_foo2730=== CONT TestGlobMatch/foo*bar_foobarbaz2731=== CONT TestGlobMatch/foo*bar_foo123bar2732=== CONT TestGlobMatch/foo*bar_foobar2733=== CONT TestGlobMatch/*bar_foo2734=== CONT TestGlobMatch/*bar_foobar2735=== CONT TestGlobMatch/*bar_bar2736=== CONT TestGlobMatch/foo*_bar2737=== CONT TestGlobMatch/foo*_foobar2738=== CONT TestGlobMatch/foo*_foo2739=== CONT TestGlobMatch/*_anything2740=== CONT TestGlobMatch/*_2741=== CONT TestGlobMatch/foo_bar2742--- PASS: TestGlobMatch (0.00s)2743 --- PASS: TestGlobMatch/foo_foo (0.00s)2744 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2745 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2746 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2747 --- PASS: TestGlobMatch/?oo_boo (0.00s)2748 --- PASS: TestGlobMatch/?oo_foo (0.00s)2749 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2750 --- PASS: TestGlobMatch/fo?_fo (0.00s)2751 --- PASS: TestGlobMatch/fo?_foo (0.00s)2752 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2753 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2754 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2755 --- PASS: TestGlobMatch/*/*_foo (0.00s)2756 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2757 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2758 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2759 --- PASS: TestGlobMatch/*bar_foo (0.00s)2760 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2761 --- PASS: TestGlobMatch/*bar_bar (0.00s)2762 --- PASS: TestGlobMatch/foo*_bar (0.00s)2763 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2764 --- PASS: TestGlobMatch/foo*_foo (0.00s)2765 --- PASS: TestGlobMatch/*_anything (0.00s)2766 --- PASS: TestGlobMatch/*_ (0.00s)2767 --- PASS: TestGlobMatch/foo_bar (0.00s)27682026/09/29 08:15:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56031/oidc2769--- PASS: TestValidateToken_Expired (0.31s)27702026/09/29 08:15:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56033/oidc27712026/09/29 08:15:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56035/oidc2772--- PASS: TestValidateToken_ValidToken (0.37s)2773--- PASS: TestValidateToken_BoundSubjectMismatch (0.22s)27742026/09/29 08:15:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56037/oidc27752026/09/29 08:15:53 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:56028/oidc2776--- PASS: TestValidateToken_BoundClaimsMismatch (0.48s)27772026/09/29 08:15:53 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:56039/oidc2778--- PASS: TestValidateToken_MultipleProviders (0.49s)27792026/09/29 08:15:53 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232780--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.54s)27812026/09/29 08:15:53 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:56042/oidc2782--- PASS: TestValidateToken_NoMatchingProvider (0.54s)27832026/09/29 08:15:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56047/oidc2784--- PASS: TestScopes_LegacyProviderDefaultsToWrite (1.38s)27852026/09/29 08:15:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56049/oidc2786--- PASS: TestValidateToken_WrongAudience (1.22s)2787PASS2788Running hook tests...2789=== RUN TestSendPathsEmpty2790=== PAUSE TestSendPathsEmpty2791=== RUN TestQueueEnqueueAndFetch2792=== PAUSE TestQueueEnqueueAndFetch2793=== RUN TestQueueDeduplication2794=== PAUSE TestQueueDeduplication2795=== RUN TestQueueRemove2796=== PAUSE TestQueueRemove2797=== RUN TestQueueFetchBatchLimit2798=== PAUSE TestQueueFetchBatchLimit2799=== RUN TestQueueRetryMovesToBack2800=== PAUSE TestQueueRetryMovesToBack2801=== RUN TestQueueFetchRemoveLifecycle2802=== PAUSE TestQueueFetchRemoveLifecycle2803=== RUN TestQueueConcurrentWriters2804=== PAUSE TestQueueConcurrentWriters2805=== RUN TestQueueRemoveLargeClosure2806=== PAUSE TestQueueRemoveLargeClosure2807=== RUN TestServerClientIntegration2808=== PAUSE TestServerClientIntegration2809=== RUN TestServerQueueError2810=== PAUSE TestServerQueueError2811=== RUN TestGetListenerSocketActivation2812 server_test.go:210: === RUN TestGetListenerSocketActivation2813 --- PASS: TestGetListenerSocketActivation (0.00s)2814 PASS2815 2816--- PASS: TestGetListenerSocketActivation (0.01s)2817=== RUN TestDrainIsolatesPoisonPath2818=== PAUSE TestDrainIsolatesPoisonPath2819=== RUN TestRunNotBlockedByPoisonHead2820=== PAUSE TestRunNotBlockedByPoisonHead2821=== RUN TestDrainGivesUpWhenServerDown2822=== PAUSE TestDrainGivesUpWhenServerDown2823=== RUN TestFailedPathPrunedByLaterClosure2824=== PAUSE TestFailedPathPrunedByLaterClosure2825=== RUN TestWorkerUploadsAndRemoves2826=== PAUSE TestWorkerUploadsAndRemoves2827=== RUN TestWorkerSkipsGCdPaths2828=== PAUSE TestWorkerSkipsGCdPaths2829=== RUN TestWorkerPrunesClosureDeps2830=== PAUSE TestWorkerPrunesClosureDeps2831=== RUN TestDrainTimeout2832=== PAUSE TestDrainTimeout2833=== CONT TestSendPathsEmpty2834=== CONT TestServerQueueError2835--- PASS: TestSendPathsEmpty (0.00s)2836=== CONT TestServerClientIntegration2837=== CONT TestQueueRemoveLargeClosure28382026/09/29 08:15:54 ERROR Failed to queue paths error="permission denied" count=12839--- PASS: TestServerQueueError (0.00s)2840=== CONT TestWorkerUploadsAndRemoves2841=== CONT TestQueueConcurrentWriters2842=== CONT TestQueueFetchRemoveLifecycle2843=== CONT TestQueueRetryMovesToBack2844=== CONT TestQueueFetchBatchLimit2845=== CONT TestQueueRemove2846=== CONT TestQueueDeduplication2847=== CONT TestQueueEnqueueAndFetch2848--- PASS: TestServerClientIntegration (0.00s)2849=== CONT TestDrainTimeout2850--- PASS: TestQueueRemove (0.00s)2851=== CONT TestWorkerPrunesClosureDeps28522026/09/29 08:15:54 INFO Upload queue status pending=228532026/09/29 08:15:54 INFO Uploading batch count=228542026/09/29 08:15:54 INFO Uploading batch count=22855--- PASS: TestQueueFetchBatchLimit (0.00s)2856=== CONT TestWorkerSkipsGCdPaths2857--- PASS: TestQueueEnqueueAndFetch (0.01s)2858=== CONT TestDrainGivesUpWhenServerDown2859--- PASS: TestQueueDeduplication (0.01s)2860=== CONT TestFailedPathPrunedByLaterClosure2861--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2862=== CONT TestRunNotBlockedByPoisonHead2863--- PASS: TestQueueRetryMovesToBack (0.01s)2864=== CONT TestDrainIsolatesPoisonPath28652026/09/29 08:15:54 INFO Upload queue status pending=228662026/09/29 08:15:54 INFO Uploading batch count=128672026/09/29 08:15:54 INFO Uploading batch count=128682026/09/29 08:15:54 ERROR Upload failed error="upload failed" count=128692026/09/29 08:15:54 INFO Uploading batch count=128702026/09/29 08:15:54 INFO Upload queue status pending=228712026/09/29 08:15:54 INFO Uploading batch count=128722026/09/29 08:15:54 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-1883-381732109/TestWorkerSkipsGCdPaths2271421457/002/nonexistent28732026/09/29 08:15:54 INFO Uploading batch count=128742026/09/29 08:15:54 INFO Upload queue status pending=328752026/09/29 08:15:54 INFO Uploading batch count=128762026/09/29 08:15:54 ERROR Upload failed error="upload failed" count=12877--- PASS: TestFailedPathPrunedByLaterClosure (0.00s)28782026/09/29 08:15:54 INFO Uploading batch count=228792026/09/29 08:15:54 ERROR Upload failed error="upload failed" count=228802026/09/29 08:15:54 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-1883-381732109/TestDrainGivesUpWhenServerDown2560109849/002/a28812026/09/29 08:15:54 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-1883-381732109/TestDrainGivesUpWhenServerDown2560109849/002/b28822026/09/29 08:15:54 INFO Uploading batch count=428832026/09/29 08:15:54 ERROR Upload failed error="upload failed" count=428842026/09/29 08:15:54 INFO Uploading batch count=228852026/09/29 08:15:54 ERROR Upload failed error="upload failed" count=228862026/09/29 08:15:54 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-1883-381732109/TestDrainGivesUpWhenServerDown2560109849/002/c28872026/09/29 08:15:54 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-1883-381732109/TestDrainIsolatesPoisonPath2483240344/002/bbb28882026/09/29 08:15:54 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-1883-381732109/TestDrainGivesUpWhenServerDown2560109849/002/d28892026/09/29 08:15:54 INFO Uploading batch count=228902026/09/29 08:15:54 ERROR Upload failed error="upload failed" count=228912026/09/29 08:15:54 INFO Uploading batch count=128922026/09/29 08:15:54 ERROR Upload failed error="upload failed" count=128932026/09/29 08:15:54 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-1883-381732109/TestDrainGivesUpWhenServerDown2560109849/002/e28942026/09/29 08:15:54 INFO Uploading batch count=128952026/09/29 08:15:54 ERROR Upload failed error="upload failed" count=128962026/09/29 08:15:54 INFO Uploading batch count=128972026/09/29 08:15:54 ERROR Upload failed error="upload failed" count=128982026/09/29 08:15:54 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-1883-381732109/TestDrainGivesUpWhenServerDown2560109849/002/f28992026/09/29 08:15:54 ERROR Drain finished with paths left in queue remaining=129002026/09/29 08:15:54 ERROR Drain finished with paths left in queue remaining=102901--- PASS: TestDrainIsolatesPoisonPath (0.00s)2902--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2903--- PASS: TestWorkerUploadsAndRemoves (0.03s)2904--- PASS: TestWorkerPrunesClosureDeps (0.02s)2905--- PASS: TestWorkerSkipsGCdPaths (0.02s)2906--- PASS: TestQueueRemoveLargeClosure (0.06s)2907--- PASS: TestQueueConcurrentWriters (0.10s)29082026/09/29 08:15:54 ERROR Upload failed error="context deadline exceeded" count=229092026/09/29 08:15:54 ERROR Drain finished with paths left in queue remaining=42910--- PASS: TestDrainTimeout (0.21s)29112026/09/29 08:15:55 INFO Uploading batch count=129122026/09/29 08:15:55 INFO Uploading batch count=129132026/09/29 08:15:55 INFO Uploading batch count=129142026/09/29 08:15:55 ERROR Upload failed error="upload failed" count=129152026/09/29 08:15:55 INFO Uploading batch count=129162026/09/29 08:15:55 ERROR Upload failed error="upload failed" count=129172026/09/29 08:15:55 INFO Uploading batch count=129182026/09/29 08:15:55 ERROR Upload failed error="upload failed" count=129192026/09/29 08:15:55 INFO Uploading batch count=129202026/09/29 08:15:55 ERROR Upload failed error="upload failed" count=129212026/09/29 08:15:55 ERROR Drain finished with paths left in queue remaining=12922--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2923PASS