niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #338
· 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.07s)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 TestSetClientTLS95=== CONT TestDoServerRequestAttachesToken96=== CONT TestClientSignaturesByStorePath97--- PASS: TestClientSignaturesByStorePath (0.00s)98=== CONT TestShellSplit99=== CONT TestStreamPushReportsSignatures100=== CONT TestStreamPushRequestLine101=== CONT TestStreamPushGivesUpOnDeadServer102=== CONT TestStreamPushIsolatesFailures103=== CONT TestStreamPushBatchesUnderLoad104=== CONT TestStreamPushReportsEveryPath105=== CONT TestShellSplitErrors106=== CONT TestResolveStorePath107--- PASS: TestShellSplit (0.00s)108=== CONT TestDoWithRetry_BodyReplayedViaGetBody109--- PASS: TestShellSplitErrors (0.00s)110--- PASS: TestStreamPushReportsEveryPath (0.00s)111=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1122026/10/01 10:24:34 ERROR Upload failed error=boom count=11132026/10/01 10:24:34 ERROR Upload failed error="bad path" count=3114--- PASS: TestStreamPushIsolatesFailures (0.00s)115=== CONT TestRateLimiterFeedback116=== RUN TestRateLimiterFeedback/429_enables_limiter117=== PAUSE TestRateLimiterFeedback/429_enables_limiter118=== RUN TestRateLimiterFeedback/503_enables_limiter119=== PAUSE TestRateLimiterFeedback/503_enables_limiter120=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter121=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter122=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter123=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter1242026/10/01 10:24:34 ERROR Upload failed error="connection refused" count=20125=== CONT TestPathInfoCACompatibility126=== RUN TestPathInfoCACompatibility/null_ca_field1272026/10/01 10:24:34 ERROR Server seems unavailable, giving up on batch untried=17128=== PAUSE TestPathInfoCACompatibility/null_ca_field129=== RUN TestPathInfoCACompatibility/old_string_format_-_text130=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text1312026/10/01 10:24:34 ERROR Upload failed error=boom count=1132--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)133--- PASS: TestResolveStorePath (0.00s)134=== CONT TestParsePathInfoJSONMultiplePaths135=== CONT TestParsePathInfoJSON136=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths137=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive138=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive139=== RUN TestPathInfoCACompatibility/new_structured_format_-_text1402026/10/01 10:24:34 WARN Rate limiter enabled after throttle name=server-test rate=51412026/10/01 10:24:34 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:61202142=== RUN TestParsePathInfoJSON/Nix_format1432026/10/01 10:24:34 WARN Rate limiter enabled after throttle name=server-test rate=5144--- PASS: TestStreamPushReportsSignatures (0.00s)145=== CONT TestPathInfoHashCompatibility146=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)147=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)148=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon149=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon150=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI151=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text152=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method153=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method154=== CONT TestGetStorePathHash155=== RUN TestGetStorePathHash/valid_store_path156=== PAUSE TestGetStorePathHash/valid_store_path157=== RUN TestGetStorePathHash/basename_without_hyphen_should_error158=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error159=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error160=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error161=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error162=== PAUSE TestParsePathInfoJSON/Nix_format163=== RUN TestParsePathInfoJSON/Lix_format164=== PAUSE TestParsePathInfoJSON/Lix_format165=== RUN TestParsePathInfoJSON/empty_input166=== PAUSE TestParsePathInfoJSON/empty_input167=== RUN TestParsePathInfoJSON/whitespace_only168=== PAUSE TestParsePathInfoJSON/whitespace_only169=== RUN TestParsePathInfoJSON/invalid_JSON170=== PAUSE TestParsePathInfoJSON/invalid_JSON171=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error172=== CONT TestConvertHashToNix32173=== RUN TestConvertHashToNix32/SRI_format_to_Nix32174=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32175=== RUN TestConvertHashToNix32/already_Nix32_format176=== PAUSE TestConvertHashToNix32/already_Nix32_format177=== RUN TestConvertHashToNix32/invalid_format178=== PAUSE TestConvertHashToNix32/invalid_format179=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths180=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths181=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths182=== CONT TestEncodeNixBase32WithRealHash183--- PASS: TestEncodeNixBase32WithRealHash (0.00s)184=== CONT TestDumpPathSingleFile185=== CONT TestEncodeNixBase32186=== RUN TestEncodeNixBase32/test_string_hash187=== PAUSE TestEncodeNixBase32/test_string_hash188=== RUN TestEncodeNixBase32/empty_input189=== PAUSE TestEncodeNixBase32/empty_input190=== CONT TestDumpPathMatchesNix191=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI192=== CONT TestDumpPathWriterError193--- PASS: TestDoServerRequestAttachesToken (0.01s)194=== CONT TestUploadMultipart_SupersededByPeer195=== RUN TestUploadMultipart_SupersededByPeer/exists196=== PAUSE TestUploadMultipart_SupersededByPeer/exists197=== RUN TestUploadMultipart_SupersededByPeer/missing198=== PAUSE TestUploadMultipart_SupersededByPeer/missing199=== CONT TestPartSizeForNAR200=== RUN TestPartSizeForNAR/zero_stays_at_minimum201=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum202=== RUN TestPartSizeForNAR/small_stays_at_minimum203=== PAUSE TestPartSizeForNAR/small_stays_at_minimum204=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum205=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum206=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts207=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts208=== RUN TestPartSizeForNAR/1_TiB209=== PAUSE TestPartSizeForNAR/1_TiB210=== RUN TestPartSizeForNAR/5_TiB_S3_max_object211=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object212=== RUN TestPartSizeForNAR/capped_at_5_GiB213=== PAUSE TestPartSizeForNAR/capped_at_5_GiB214=== CONT TestUploadMultipart_PartsInParallel2152026/10/01 10:24:34 WARN Rate limiter backed off name=server-test rate=52162026/10/01 10:24:34 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:61202217=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512218=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512219=== CONT TestFilterOversizedClosures220=== RUN TestFilterOversizedClosures/no_limit_keeps_everything221=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything222=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped223=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped224=== RUN TestFilterOversizedClosures/all_closures_skipped225=== PAUSE TestFilterOversizedClosures/all_closures_skipped226=== CONT TestCaseHackSuffix227=== RUN TestSetClientTLS/rejects_connection_without_client_cert228--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)229=== CONT TestRegisterUploadedObjectReusesConnections230=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert231=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA232=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA233=== RUN TestSetClientTLS/preserves_debug_logging_transport234=== PAUSE TestSetClientTLS/preserves_debug_logging_transport235=== CONT TestScriptTokenBadJSON236--- PASS: TestStreamPushRequestLine (0.03s)237=== CONT TestScriptTokenEmptyCommand238--- PASS: TestScriptTokenEmptyCommand (0.00s)239=== CONT TestScriptTokenScriptFails240--- PASS: TestScriptTokenScriptFails (0.01s)241=== CONT TestFileTokenReadsAndCaches242--- PASS: TestFileTokenReadsAndCaches (0.00s)243=== CONT TestFileTokenEmpty244--- PASS: TestFileTokenEmpty (0.00s)245=== CONT TestFileTokenMissing246--- PASS: TestFileTokenMissing (0.00s)247=== CONT TestSetClientTLSErrors248=== RUN TestSetClientTLSErrors/missing_cert_file249=== PAUSE TestSetClientTLSErrors/missing_cert_file250=== RUN TestSetClientTLSErrors/missing_key_file251=== PAUSE TestSetClientTLSErrors/missing_key_file252=== RUN TestSetClientTLSErrors/missing_ca_file253=== PAUSE TestSetClientTLSErrors/missing_ca_file254=== RUN TestSetClientTLSErrors/invalid_ca_file255=== PAUSE TestSetClientTLSErrors/invalid_ca_file256=== CONT TestStaticToken257--- PASS: TestStaticToken (0.00s)258=== CONT TestSetClientTLSDoesNotMutateDefaultTransport259--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)260=== CONT TestScriptTokenEmptyToken261--- PASS: TestScriptTokenBadJSON (0.03s)262=== CONT TestScriptTokenCachesUntilRefresh263--- PASS: TestRegisterUploadedObjectReusesConnections (0.05s)264=== CONT TestScriptTokenNoExpiryRerunsEveryCall265--- PASS: TestScriptTokenEmptyToken (0.02s)266=== CONT TestRateLimiterFeedback/429_enables_limiter2672026/10/01 10:24:34 WARN Rate limiter enabled after throttle name=server-test rate=52682026/10/01 10:24:34 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:612782692026/10/01 10:24:34 WARN Rate limiter backed off name=server-test rate=5270=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter271=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter272=== CONT TestRateLimiterFeedback/503_enables_limiter2732026/10/01 10:24:34 WARN Rate limiter enabled after throttle name=server-test rate=52742026/10/01 10:24:34 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:612842752026/10/01 10:24:34 WARN Rate limiter backed off name=server-test rate=5276--- PASS: TestRateLimiterFeedback (0.00s)277 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)278 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)279 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)280 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)281=== CONT TestPathInfoCACompatibility/null_ca_field282=== CONT TestPathInfoCACompatibility/new_structured_format_-_text283=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive284=== CONT TestPathInfoCACompatibility/old_string_format_-_text285=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method286--- PASS: TestPathInfoCACompatibility (0.00s)287 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)288 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)289 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)290 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)291 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)292=== CONT TestParsePathInfoJSON/Nix_format293=== CONT TestGetStorePathHash/valid_store_path294=== CONT TestConvertHashToNix32/SRI_format_to_Nix32295=== CONT TestParsePathInfoJSON/invalid_JSON296=== CONT TestParsePathInfoJSON/whitespace_only297=== CONT TestParsePathInfoJSON/empty_input298=== CONT TestParsePathInfoJSON/Lix_format299--- PASS: TestParsePathInfoJSON (0.00s)300 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)301 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)302 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)303 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)304 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)305=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths306=== CONT TestConvertHashToNix32/invalid_format307=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error308=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error309=== CONT TestGetStorePathHash/basename_without_hyphen_should_error310--- PASS: TestGetStorePathHash (0.00s)311 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)312 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)313 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)314 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)315=== CONT TestEncodeNixBase32/test_string_hash316=== CONT TestEncodeNixBase32/empty_input317--- PASS: TestEncodeNixBase32 (0.00s)318 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)319 --- PASS: TestEncodeNixBase32/empty_input (0.00s)320=== CONT TestConvertHashToNix32/already_Nix32_format321--- PASS: TestConvertHashToNix32 (0.00s)322 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)323 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)324 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)325=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths326=== CONT TestUploadMultipart_SupersededByPeer/exists327--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)328 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)329 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)330=== CONT TestPartSizeForNAR/zero_stays_at_minimum331=== CONT TestUploadMultipart_SupersededByPeer/missing332--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)333 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)334 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)335=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts336=== CONT TestPartSizeForNAR/capped_at_5_GiB337=== CONT TestPartSizeForNAR/5_TiB_S3_max_object338=== CONT TestPartSizeForNAR/1_TiB339=== CONT TestPartSizeForNAR/small_stays_at_minimum340=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum341--- PASS: TestPartSizeForNAR (0.00s)342 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)343 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)344 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)345 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)346 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)347 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)348 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)349=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)350=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI351=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512352=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon353--- PASS: TestPathInfoHashCompatibility (0.01s)354 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)355 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)356 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)357 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)358=== CONT TestFilterOversizedClosures/no_limit_keeps_everything359=== CONT TestFilterOversizedClosures/all_closures_skipped3602026/10/01 10:24:34 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-small nar_size=1000 max_nar_size=50361=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3622026/10/01 10:24:34 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=2000363--- PASS: TestFilterOversizedClosures (0.00s)364 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)365 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)366 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)367=== CONT TestSetClientTLS/rejects_connection_without_client_cert368--- PASS: TestDumpPathWriterError (0.06s)369=== CONT TestSetClientTLS/preserves_debug_logging_transport370=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA371=== CONT TestSetClientTLSErrors/missing_cert_file372=== CONT TestSetClientTLSErrors/missing_ca_file373=== CONT TestSetClientTLSErrors/invalid_ca_file374=== CONT TestSetClientTLSErrors/missing_key_file375--- PASS: TestSetClientTLSErrors (0.00s)376 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)377 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)378 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)379 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)3802026/10/01 10:24:34 http: TLS handshake error from 127.0.0.1:61290: remote error: tls: bad certificate381--- PASS: TestSetClientTLS (0.02s)382 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)383 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)384 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)385--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)386--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)387--- PASS: TestStreamPushBatchesUnderLoad (0.10s)388--- PASS: TestCaseHackSuffix (0.09s)389--- PASS: TestDumpPathSingleFile (0.11s)390--- PASS: TestDumpPathMatchesNix (0.13s)391--- PASS: TestUploadMultipart_PartsInParallel (0.64s)392--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)393PASS394Running server tests...395The files belonging to this database system will be owned by user "_nixbld10".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-41045-2866623493/postgres921588054/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-41045-2866623493/postgres921588054/data -l logfile start421422/nix/var/nix/builds/nix-41045-2866623493/postgres921588054:5432 - no response4232026-10-01 10:24:36.798 UTC [41262] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4242026-10-01 10:24:36.798 UTC [41262] LOG: listening on Unix socket "/nix/var/nix/builds/nix-41045-2866623493/postgres921588054/.s.PGSQL.5432"4252026-10-01 10:24:36.801 UTC [41269] LOG: database system was shut down at 2026-10-01 10:24:36 UTC4262026-10-01 10:24:36.802 UTC [41262] LOG: database system is ready to accept connections427/nix/var/nix/builds/nix-41045-2866623493/postgres921588054:5432 - accepting connections428{"timestamp":"2026-10-01T10:24:37.079663Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"15e64436-2c9b-4e0f-8ba5-81a020549794","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(3)"}429=== RUN TestService_AuthMiddleware430=== PAUSE TestService_AuthMiddleware431=== RUN TestService_AuthMiddleware_MTLSProxyHeader432=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader433=== RUN TestService_AuthMiddleware_MTLSBoundSubjects434=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects435=== RUN TestService_ReadAuthMiddleware436=== PAUSE TestService_ReadAuthMiddleware437=== RUN TestService_AuthMiddleware_OIDC438=== PAUSE TestService_AuthMiddleware_OIDC439=== RUN TestService_RequireScope_OIDC440=== PAUSE TestService_RequireScope_OIDC441=== RUN TestService_ReadScope_PublicByDefault442=== PAUSE TestService_ReadScope_PublicByDefault443=== RUN TestCacheConfigHandler444=== PAUSE TestCacheConfigHandler445=== RUN TestCacheStatsHandler446=== PAUSE TestCacheStatsHandler447=== RUN TestClientCADerivations448=== PAUSE TestClientCADerivations449=== RUN TestClientErrorHandling450=== PAUSE TestClientErrorHandling451=== RUN TestClientIntegration452=== PAUSE TestClientIntegration453=== RUN TestClientMultipleUploads454=== PAUSE TestClientMultipleUploads455=== RUN TestClientWithDependencies456=== PAUSE TestClientWithDependencies457=== RUN TestClientSharedPathCommittedMidPush458=== PAUSE TestClientSharedPathCommittedMidPush459=== RUN TestPinProtectsFromGC460=== PAUSE TestPinProtectsFromGC461=== RUN TestClientPushesUseOnePush462=== PAUSE TestClientPushesUseOnePush463=== RUN TestClientFallsBackToClosures464=== PAUSE TestClientFallsBackToClosures465=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock466=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock467=== RUN TestResolveDBConnectionString468=== PAUSE TestResolveDBConnectionString469=== RUN TestLeadElectsOneAndHandsOver470=== PAUSE TestLeadElectsOneAndHandsOver471=== RUN TestLeadIncumbentWinsAfterRestart4722026-10-01 10:24:37.389 UTC [41311] ERROR: relation "goose_db_version" does not exist at character 364732026-10-01 10:24:37.389 UTC [41311] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4742026/10/01 10:24:37 OK 20241026095416_initial_model.sql (4.24ms)4752026/10/01 10:24:37 OK 20251210153512_drop_unused_gin_index.sql (573.88µs)4762026/10/01 10:24:37 OK 20251218171726_add_pins.sql (1.01ms)4772026/10/01 10:24:37 OK 20260628120000_add_object_size_and_stats.sql (2.27ms)4782026/10/01 10:24:37 OK 20260905000000_add_claims.sql (1.09ms)4792026/10/01 10:24:37 OK 20260920000000_drop_claims.sql (732.88µs)4802026/10/01 10:24:37 OK 20260923120000_add_pushes.sql (431.25µs)4812026/10/01 10:24:37 goose: successfully migrated database to version: 202609231200004822026/10/01 10:24:37 OK 1_commit_pending_closure.sql (999.04µs)4832026/10/01 10:24:37 OK 2_object_stats_trigger.sql (245.63µs)4842026/10/01 10:24:37 OK 3_commit_push.sql (204.33µs)4852026/10/01 10:24:37 goose: up to current file version: 34862026/10/01 10:24:37 INFO lead: acquired remote=192.0.2.1:12344872026/10/01 10:24:38 INFO lead: released remote=192.0.2.1:12344882026/10/01 10:24:38 INFO lead: acquired remote=192.0.2.1:12344892026/10/01 10:24:38 INFO lead: released remote=192.0.2.1:1234490--- PASS: TestLeadIncumbentWinsAfterRestart (0.98s)491=== RUN TestLeadEndsOnShutdown492=== PAUSE TestLeadEndsOnShutdown493=== RUN TestGCAdvisoryLockBlocksConcurrentRun4942026-10-01 10:24:38.228 UTC [41406] ERROR: relation "goose_db_version" does not exist at character 364952026-10-01 10:24:38.228 UTC [41406] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4962026/10/01 10:24:38 OK 20241026095416_initial_model.sql (3.81ms)4972026/10/01 10:24:38 OK 20251210153512_drop_unused_gin_index.sql (413.79µs)4982026/10/01 10:24:38 OK 20251218171726_add_pins.sql (781.25µs)4992026/10/01 10:24:38 OK 20260628120000_add_object_size_and_stats.sql (864.54µs)5002026/10/01 10:24:38 OK 20260905000000_add_claims.sql (1.08ms)5012026/10/01 10:24:38 OK 20260920000000_drop_claims.sql (599.29µs)5022026/10/01 10:24:38 OK 20260923120000_add_pushes.sql (372.25µs)5032026/10/01 10:24:38 goose: successfully migrated database to version: 202609231200005042026/10/01 10:24:38 OK 1_commit_pending_closure.sql (841.71µs)5052026/10/01 10:24:38 OK 2_object_stats_trigger.sql (194.04µs)5062026/10/01 10:24:38 OK 3_commit_push.sql (191µs)5072026/10/01 10:24:38 goose: up to current file version: 3508--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.18s)509=== RUN TestGCBugBareHashReferences510=== PAUSE TestGCBugBareHashReferences511=== RUN TestGCMetrics512=== PAUSE TestGCMetrics513=== RUN TestPushDedupSurvivesConcurrentGC514=== PAUSE TestPushDedupSurvivesConcurrentGC515=== RUN TestDeduplicatedObjectsRecordedAsPending516=== PAUSE TestDeduplicatedObjectsRecordedAsPending517=== RUN TestGCSweepSkipsPendingObjects518=== PAUSE TestGCSweepSkipsPendingObjects519=== RUN TestTombstonedObjectOfferedWithoutWaiting520=== PAUSE TestTombstonedObjectOfferedWithoutWaiting521=== RUN TestGCSweepDeliversEachKeyOnce522=== PAUSE TestGCSweepDeliversEachKeyOnce523=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection524=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection525=== RUN TestForceGCDuringPushOffersSweptObject526=== PAUSE TestForceGCDuringPushOffersSweptObject527=== RUN TestFailedS3DeleteKeepsTombstone528=== PAUSE TestFailedS3DeleteKeepsTombstone529=== RUN TestSweepSkipsRowsLockedByPush530=== PAUSE TestSweepSkipsRowsLockedByPush531=== RUN TestRegisterCompletedObjectNeedsPendingRow532=== PAUSE TestRegisterCompletedObjectNeedsPendingRow533=== RUN TestGetExistingObjectsLocksRows534=== PAUSE TestGetExistingObjectsLocksRows535=== RUN TestSweepRechecksPendingAfterLocking536=== PAUSE TestSweepRechecksPendingAfterLocking537=== RUN TestPushWaitsForSweepHoldingRow538=== PAUSE TestPushWaitsForSweepHoldingRow539=== RUN TestCommitRacingPendingCleanupKeepsObjects540=== PAUSE TestCommitRacingPendingCleanupKeepsObjects541=== RUN TestGCEndsOnShutdown542=== PAUSE TestGCEndsOnShutdown543=== RUN TestGCTaskStore_StartNew544=== PAUSE TestGCTaskStore_StartNew545=== RUN TestGCTaskStore_DeduplicateSameParams546=== PAUSE TestGCTaskStore_DeduplicateSameParams547=== RUN TestGCTaskStore_ConflictDifferentParams548=== PAUSE TestGCTaskStore_ConflictDifferentParams549=== RUN TestGCTaskStore_GetEmpty550=== PAUSE TestGCTaskStore_GetEmpty551=== RUN TestGCTaskStore_GetReturnsLatest552=== PAUSE TestGCTaskStore_GetReturnsLatest553=== RUN TestGCTaskStore_CompletedAllowsNewTask554=== PAUSE TestGCTaskStore_CompletedAllowsNewTask555=== RUN TestGCTaskStore_PhaseUpdates556=== PAUSE TestGCTaskStore_PhaseUpdates557=== RUN TestGCTaskStore_Fail558=== PAUSE TestGCTaskStore_Fail559=== RUN TestGracefulShutdownDrainsInflight560=== PAUSE TestGracefulShutdownDrainsInflight561=== RUN TestService_healthCheckHandler562=== PAUSE TestService_healthCheckHandler563=== RUN TestService_readinessHandler564=== PAUSE TestService_readinessHandler565=== RUN TestGenerateLandingPage566=== PAUSE TestGenerateLandingPage567=== RUN TestCacheConfigHandlerMaxNarSize568=== PAUSE TestCacheConfigHandlerMaxNarSize569=== RUN TestCreatePendingClosureRejectsOversizedNAR570=== PAUSE TestCreatePendingClosureRejectsOversizedNAR571=== RUN TestNARDeduplicationMetadataUploadBug572=== PAUSE TestNARDeduplicationMetadataUploadBug573=== RUN TestMetricsInventory574=== PAUSE TestMetricsInventory575=== RUN TestService_NativeMTLS576=== PAUSE TestService_NativeMTLS577=== RUN TestServerTLSConfig578=== PAUSE TestServerTLSConfig579=== RUN TestMultipartCleanup580=== PAUSE TestMultipartCleanup581=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded582=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded583=== RUN TestPendingCleanupUsesOneCutoff584=== PAUSE TestPendingCleanupUsesOneCutoff585=== RUN TestObjectStatsTrigger586=== PAUSE TestObjectStatsTrigger587=== RUN TestOrphanedObjectsGC588=== PAUSE TestOrphanedObjectsGC589=== RUN TestOrphanedObjectsGCStressTest590=== PAUSE TestOrphanedObjectsGCStressTest591=== RUN TestCreatePin_ReservedPins592=== PAUSE TestCreatePin_ReservedPins593=== RUN TestPresentReportsOnlyClosureRoots594=== PAUSE TestPresentReportsOnlyClosureRoots595=== RUN TestPresentNotReportedWhileGCDeletesClosure596=== PAUSE TestPresentNotReportedWhileGCDeletesClosure597=== RUN TestParseSingleRange598=== PAUSE TestParseSingleRange599=== RUN TestProxyHeadersOnlyTrustedOnSocket600=== PAUSE TestProxyHeadersOnlyTrustedOnSocket601=== RUN TestIsValidCachePath602=== PAUSE TestIsValidCachePath603=== RUN TestReadProxyNarinfo604=== PAUSE TestReadProxyNarinfo605=== RUN TestReadProxyNarinfoAlreadyDecompressed606=== PAUSE TestReadProxyNarinfoAlreadyDecompressed607=== RUN TestReadProxyNarStreaming608=== PAUSE TestReadProxyNarStreaming609=== RUN TestReadProxy404610=== PAUSE TestReadProxy404611=== RUN TestReadProxyInvalidPath612=== PAUSE TestReadProxyInvalidPath613=== RUN TestReadProxyHead614=== PAUSE TestReadProxyHead615=== RUN TestReadProxyConditionalGet616=== PAUSE TestReadProxyConditionalGet617=== RUN TestReadProxyRootRedirectsToIndexHTML618=== PAUSE TestReadProxyRootRedirectsToIndexHTML619=== RUN TestReadProxyDisabled620=== PAUSE TestReadProxyDisabled621=== RUN TestReadRedirectNar622=== PAUSE TestReadRedirectNar623=== RUN TestReadRedirectKeepsNarinfoProxied624=== PAUSE TestReadRedirectKeepsNarinfoProxied625=== RUN TestReadProxyRangeRequest626=== PAUSE TestReadProxyRangeRequest627=== RUN TestReadRedirectUsesPublicS3URL628=== PAUSE TestReadRedirectUsesPublicS3URL629=== RUN TestPush_OverlappingRootsStoreOneRowPerKey630=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey631=== RUN TestPush_CompleteCommitsEveryRoot632=== PAUSE TestPush_CompleteCommitsEveryRoot633=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit634=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit635=== RUN TestPush_RejectsBadRequests636=== PAUSE TestPush_RejectsBadRequests637=== RUN TestPush_SignsNarinfosOfItsPendingObjects638=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects639=== RUN TestRedundantMultipartUpload640=== PAUSE TestRedundantMultipartUpload641=== RUN TestCompleteMultipartUpload_ErrorButObjectExists642=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists643=== RUN TestCompletedNarNotReofferedAcrossClosures644=== PAUSE TestCompletedNarNotReofferedAcrossClosures645=== RUN TestPresignedUploadRegisteredBeforeCommit646=== PAUSE TestPresignedUploadRegisteredBeforeCommit647=== RUN TestService_Rustfstest648=== PAUSE TestService_Rustfstest649=== RUN TestParseSize650=== PAUSE TestParseSize651=== RUN TestSkippedUploadsHandler652=== PAUSE TestSkippedUploadsHandler653=== RUN TestSystemdListenerNotActivated654--- PASS: TestSystemdListenerNotActivated (0.00s)655=== RUN TestWatchdogBeatsWhenHealthy656--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)657=== RUN TestWatchdogSkipsWhenUnhealthy6582026/10/01 10:24:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6592026/10/01 10:24:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/01 10:24:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/01 10:24:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/01 10:24:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/01 10:24:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/01 10:24:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/01 10:24:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/01 10:24:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/01 10:24:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"668--- PASS: TestWatchdogSkipsWhenUnhealthy (0.21s)669=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle670=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle671=== RUN TestProxyWriteTimeout672=== PAUSE TestProxyWriteTimeout673=== RUN TestPendingClosureWriteTimeout674=== PAUSE TestPendingClosureWriteTimeout675=== RUN TestIsValidUploadKey676=== PAUSE TestIsValidUploadKey677=== RUN TestUploadHandlersRejectInvalidKeys678=== PAUSE TestUploadHandlersRejectInvalidKeys679=== RUN TestUploadHandlersRejectOversizedBody680=== PAUSE TestUploadHandlersRejectOversizedBody681=== RUN TestService_cleanupPendingClosuresHandler682=== PAUSE TestService_cleanupPendingClosuresHandler683=== RUN TestService_createPendingClosureHandler684=== PAUSE TestService_createPendingClosureHandler685=== RUN TestService_verifyS3Integrity686=== PAUSE TestService_verifyS3Integrity687=== RUN TestCompleteMultipartUnregistered688=== PAUSE TestCompleteMultipartUnregistered689=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT690=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT691=== CONT TestService_cleanupPendingClosuresHandler692=== CONT TestService_AuthMiddleware693=== CONT TestGenerateLandingPage694=== CONT TestReadProxyConditionalGet695=== CONT TestCompleteMultipartUnregistered696=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT697=== CONT TestCompleteMultipartUpload_ErrorButObjectExists698=== CONT TestUploadHandlersRejectOversizedBody699=== CONT TestUploadHandlersRejectInvalidKeys700=== CONT TestIsValidUploadKey701=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info702=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info703=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal704=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal705=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key706=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key707=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key708=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key709=== CONT TestPendingClosureWriteTimeout710=== RUN TestPendingClosureWriteTimeout/empty711=== PAUSE TestPendingClosureWriteTimeout/empty712=== RUN TestPendingClosureWriteTimeout/400_objects713=== PAUSE TestPendingClosureWriteTimeout/400_objects714=== RUN TestPendingClosureWriteTimeout/670k_objects715=== PAUSE TestPendingClosureWriteTimeout/670k_objects716=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline717=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline718=== CONT TestProxyWriteTimeout719=== RUN TestProxyWriteTimeout/narinfo720=== PAUSE TestProxyWriteTimeout/narinfo721=== RUN TestProxyWriteTimeout/1_GiB_nar722=== PAUSE TestProxyWriteTimeout/1_GiB_nar723=== RUN TestProxyWriteTimeout/10_GiB_nar724=== PAUSE TestProxyWriteTimeout/10_GiB_nar725=== RUN TestProxyWriteTimeout/unknown_size726=== PAUSE TestProxyWriteTimeout/unknown_size727=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle728=== RUN TestIsValidUploadKey/narinfo729=== PAUSE TestIsValidUploadKey/narinfo730=== RUN TestIsValidUploadKey/nar_zst731=== PAUSE TestIsValidUploadKey/nar_zst732=== RUN TestIsValidUploadKey/nar_xz733=== PAUSE TestIsValidUploadKey/nar_xz734=== RUN TestIsValidUploadKey/nar_plain735=== PAUSE TestIsValidUploadKey/nar_plain736=== RUN TestIsValidUploadKey/listing737=== PAUSE TestIsValidUploadKey/listing738=== RUN TestIsValidUploadKey/build_log739=== PAUSE TestIsValidUploadKey/build_log740=== RUN TestIsValidUploadKey/build_log_home-manager_file741=== PAUSE TestIsValidUploadKey/build_log_home-manager_file742=== RUN TestIsValidUploadKey/build_log_plus_in_name743=== PAUSE TestIsValidUploadKey/build_log_plus_in_name744=== RUN TestIsValidUploadKey/build_log_question_mark745=== PAUSE TestIsValidUploadKey/build_log_question_mark746=== RUN TestIsValidUploadKey/build_log_equals747=== PAUSE TestIsValidUploadKey/build_log_equals748=== RUN TestIsValidUploadKey/realisation749=== PAUSE TestIsValidUploadKey/realisation750=== RUN TestIsValidUploadKey/realisation_plus_in_output751=== PAUSE TestIsValidUploadKey/realisation_plus_in_output752=== RUN TestIsValidUploadKey/nix-cache-info753=== PAUSE TestIsValidUploadKey/nix-cache-info754=== RUN TestIsValidUploadKey/index.html755=== PAUSE TestIsValidUploadKey/index.html756=== RUN TestIsValidUploadKey/narinfo_key,_nar_type757=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type758=== RUN TestIsValidUploadKey/nar_key,_narinfo_type759=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type760=== RUN TestIsValidUploadKey/listing_key,_narinfo_type761--- PASS: TestGenerateLandingPage (0.03s)762=== CONT TestSkippedUploadsHandler763=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type764=== RUN TestIsValidUploadKey/traversal765=== PAUSE TestIsValidUploadKey/traversal766=== RUN TestIsValidUploadKey/traversal_nar767=== PAUSE TestIsValidUploadKey/traversal_nar768=== RUN TestIsValidUploadKey/absolute769=== PAUSE TestIsValidUploadKey/absolute770=== RUN TestIsValidUploadKey/empty_key771=== PAUSE TestIsValidUploadKey/empty_key772=== RUN TestIsValidUploadKey/unknown_type773=== PAUSE TestIsValidUploadKey/unknown_type774=== CONT TestParseSize775--- PASS: TestParseSize (0.00s)776=== CONT TestService_Rustfstest7772026/10/01 10:24:38 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000778--- PASS: TestSkippedUploadsHandler (0.00s)779=== CONT TestPresignedUploadRegisteredBeforeCommit780=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure781=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure782=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart783=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart784=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts785=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts786=== CONT TestCompletedNarNotReofferedAcrossClosures7872026-10-01 10:24:38.863 UTC [41470] ERROR: relation "goose_db_version" does not exist at character 367882026-10-01 10:24:38.863 UTC [41470] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7892026-10-01 10:24:38.865 UTC [41471] ERROR: relation "goose_db_version" does not exist at character 367902026-10-01 10:24:38.865 UTC [41471] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7912026-10-01 10:24:38.866 UTC [41472] ERROR: relation "goose_db_version" does not exist at character 367922026-10-01 10:24:38.866 UTC [41472] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7932026-10-01 10:24:38.867 UTC [41474] ERROR: relation "goose_db_version" does not exist at character 367942026-10-01 10:24:38.867 UTC [41474] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7952026-10-01 10:24:38.869 UTC [41473] ERROR: relation "goose_db_version" does not exist at character 367962026-10-01 10:24:38.869 UTC [41473] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7972026-10-01 10:24:38.869 UTC [41475] ERROR: relation "goose_db_version" does not exist at character 367982026-10-01 10:24:38.869 UTC [41475] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7992026-10-01 10:24:38.870 UTC [41476] ERROR: relation "goose_db_version" does not exist at character 368002026-10-01 10:24:38.870 UTC [41476] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8012026-10-01 10:24:38.871 UTC [41477] ERROR: relation "goose_db_version" does not exist at character 368022026-10-01 10:24:38.871 UTC [41477] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8032026-10-01 10:24:38.872 UTC [41478] ERROR: relation "goose_db_version" does not exist at character 368042026-10-01 10:24:38.872 UTC [41478] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8052026-10-01 10:24:38.872 UTC [41479] ERROR: relation "goose_db_version" does not exist at character 368062026-10-01 10:24:38.872 UTC [41479] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8072026/10/01 10:24:38 OK 20241026095416_initial_model.sql (8.94ms)8082026/10/01 10:24:38 OK 20251210153512_drop_unused_gin_index.sql (1.15ms)8092026/10/01 10:24:38 OK 20241026095416_initial_model.sql (8.65ms)8102026/10/01 10:24:38 OK 20241026095416_initial_model.sql (9.18ms)8112026/10/01 10:24:38 OK 20251210153512_drop_unused_gin_index.sql (1.42ms)8122026/10/01 10:24:38 OK 20241026095416_initial_model.sql (7.36ms)8132026/10/01 10:24:38 OK 20241026095416_initial_model.sql (9.24ms)8142026/10/01 10:24:38 OK 20241026095416_initial_model.sql (10.87ms)8152026/10/01 10:24:38 OK 20251210153512_drop_unused_gin_index.sql (948.25µs)8162026/10/01 10:24:38 OK 20251218171726_add_pins.sql (2.83ms)8172026/10/01 10:24:38 OK 20251210153512_drop_unused_gin_index.sql (1.02ms)8182026/10/01 10:24:38 OK 20241026095416_initial_model.sql (10.34ms)8192026/10/01 10:24:38 OK 20241026095416_initial_model.sql (9.62ms)8202026/10/01 10:24:38 OK 20251210153512_drop_unused_gin_index.sql (1.55ms)8212026/10/01 10:24:38 OK 20251218171726_add_pins.sql (2.06ms)8222026/10/01 10:24:38 OK 20251210153512_drop_unused_gin_index.sql (1.67ms)8232026/10/01 10:24:38 OK 20251210153512_drop_unused_gin_index.sql (894.67µs)8242026/10/01 10:24:38 OK 20241026095416_initial_model.sql (7.88ms)8252026/10/01 10:24:38 OK 20251210153512_drop_unused_gin_index.sql (1.15ms)8262026/10/01 10:24:38 OK 20260628120000_add_object_size_and_stats.sql (2.09ms)8272026/10/01 10:24:38 OK 20251218171726_add_pins.sql (2.6ms)8282026/10/01 10:24:38 OK 20251210153512_drop_unused_gin_index.sql (837.92µs)8292026/10/01 10:24:38 OK 20251218171726_add_pins.sql (2.38ms)8302026/10/01 10:24:38 OK 20251218171726_add_pins.sql (2.06ms)8312026/10/01 10:24:38 OK 20241026095416_initial_model.sql (8.39ms)8322026/10/01 10:24:38 OK 20260628120000_add_object_size_and_stats.sql (2.04ms)8332026/10/01 10:24:38 OK 20251218171726_add_pins.sql (1.86ms)8342026/10/01 10:24:38 OK 20251218171726_add_pins.sql (1.95ms)8352026/10/01 10:24:38 OK 20251210153512_drop_unused_gin_index.sql (655.42µs)8362026/10/01 10:24:38 OK 20251218171726_add_pins.sql (1.75ms)8372026/10/01 10:24:38 OK 20260628120000_add_object_size_and_stats.sql (1.42ms)8382026/10/01 10:24:38 OK 20260905000000_add_claims.sql (2.59ms)8392026/10/01 10:24:38 OK 20260628120000_add_object_size_and_stats.sql (1.36ms)8402026/10/01 10:24:38 OK 20251218171726_add_pins.sql (2.31ms)8412026/10/01 10:24:38 OK 20260628120000_add_object_size_and_stats.sql (2.36ms)8422026/10/01 10:24:38 OK 20260628120000_add_object_size_and_stats.sql (2.47ms)8432026/10/01 10:24:38 OK 20251218171726_add_pins.sql (1.62ms)8442026/10/01 10:24:38 OK 20260628120000_add_object_size_and_stats.sql (2.59ms)8452026/10/01 10:24:38 OK 20260905000000_add_claims.sql (2.86ms)8462026/10/01 10:24:38 OK 20260920000000_drop_claims.sql (1.65ms)8472026/10/01 10:24:38 OK 20260628120000_add_object_size_and_stats.sql (2.81ms)8482026/10/01 10:24:38 OK 20260628120000_add_object_size_and_stats.sql (2.53ms)8492026/10/01 10:24:38 OK 20260905000000_add_claims.sql (2.58ms)8502026/10/01 10:24:38 OK 20260905000000_add_claims.sql (2.61ms)8512026/10/01 10:24:38 OK 20260905000000_add_claims.sql (2.8ms)8522026/10/01 10:24:38 OK 20260905000000_add_claims.sql (2.19ms)8532026/10/01 10:24:38 OK 20260920000000_drop_claims.sql (1.76ms)8542026/10/01 10:24:38 OK 20260905000000_add_claims.sql (3.06ms)8552026/10/01 10:24:38 OK 20260628120000_add_object_size_and_stats.sql (2.52ms)8562026/10/01 10:24:38 OK 20260923120000_add_pushes.sql (1.59ms)8572026/10/01 10:24:38 goose: successfully migrated database to version: 202609231200008582026/10/01 10:24:38 OK 20260905000000_add_claims.sql (1.62ms)8592026/10/01 10:24:38 OK 20260923120000_add_pushes.sql (1.2ms)8602026/10/01 10:24:38 goose: successfully migrated database to version: 202609231200008612026/10/01 10:24:38 OK 20260920000000_drop_claims.sql (1.81ms)8622026/10/01 10:24:38 OK 20260920000000_drop_claims.sql (2.07ms)8632026/10/01 10:24:38 OK 20260905000000_add_claims.sql (3.06ms)8642026/10/01 10:24:38 OK 20260920000000_drop_claims.sql (1.81ms)8652026/10/01 10:24:38 OK 20260920000000_drop_claims.sql (1.78ms)8662026/10/01 10:24:38 OK 20260920000000_drop_claims.sql (2.13ms)8672026/10/01 10:24:38 OK 1_commit_pending_closure.sql (2.15ms)8682026/10/01 10:24:38 OK 20260923120000_add_pushes.sql (767.54µs)8692026/10/01 10:24:38 goose: successfully migrated database to version: 202609231200008702026/10/01 10:24:38 OK 20260920000000_drop_claims.sql (1.32ms)8712026/10/01 10:24:38 OK 20260905000000_add_claims.sql (2.55ms)8722026/10/01 10:24:38 OK 20260923120000_add_pushes.sql (1.06ms)8732026/10/01 10:24:38 goose: successfully migrated database to version: 202609231200008742026/10/01 10:24:38 OK 20260923120000_add_pushes.sql (977.33µs)8752026/10/01 10:24:38 goose: successfully migrated database to version: 202609231200008762026/10/01 10:24:38 OK 2_object_stats_trigger.sql (503.79µs)8772026/10/01 10:24:38 OK 20260923120000_add_pushes.sql (1.06ms)8782026/10/01 10:24:38 goose: successfully migrated database to version: 202609231200008792026/10/01 10:24:38 OK 1_commit_pending_closure.sql (1.77ms)8802026/10/01 10:24:38 OK 20260923120000_add_pushes.sql (1.31ms)8812026/10/01 10:24:38 goose: successfully migrated database to version: 202609231200008822026/10/01 10:24:38 OK 20260923120000_add_pushes.sql (1.07ms)8832026/10/01 10:24:38 goose: successfully migrated database to version: 202609231200008842026/10/01 10:24:38 OK 3_commit_push.sql (717.29µs)8852026/10/01 10:24:38 goose: up to current file version: 38862026/10/01 10:24:38 OK 1_commit_pending_closure.sql (1.1ms)8872026/10/01 10:24:38 OK 20260920000000_drop_claims.sql (2.06ms)8882026/10/01 10:24:38 OK 20260920000000_drop_claims.sql (1.2ms)8892026/10/01 10:24:38 OK 1_commit_pending_closure.sql (1.08ms)8902026/10/01 10:24:38 OK 2_object_stats_trigger.sql (849.92µs)8912026/10/01 10:24:38 OK 1_commit_pending_closure.sql (1.22ms)8922026/10/01 10:24:38 OK 1_commit_pending_closure.sql (1.79ms)8932026/10/01 10:24:38 OK 2_object_stats_trigger.sql (510.96µs)8942026/10/01 10:24:38 OK 3_commit_push.sql (541.33µs)8952026/10/01 10:24:38 goose: up to current file version: 38962026/10/01 10:24:38 OK 2_object_stats_trigger.sql (635.42µs)8972026/10/01 10:24:38 OK 1_commit_pending_closure.sql (1.33ms)8982026/10/01 10:24:38 OK 2_object_stats_trigger.sql (357.08µs)8992026/10/01 10:24:38 OK 3_commit_push.sql (253.71µs)9002026/10/01 10:24:38 goose: up to current file version: 39012026/10/01 10:24:38 OK 20260923120000_add_pushes.sql (805.08µs)9022026/10/01 10:24:38 goose: successfully migrated database to version: 202609231200009032026/10/01 10:24:38 OK 1_commit_pending_closure.sql (1.09ms)9042026/10/01 10:24:38 OK 2_object_stats_trigger.sql (428.17µs)9052026/10/01 10:24:38 OK 3_commit_push.sql (347.63µs)9062026/10/01 10:24:38 goose: up to current file version: 39072026/10/01 10:24:38 OK 3_commit_push.sql (347.54µs)9082026/10/01 10:24:38 goose: up to current file version: 39092026/10/01 10:24:38 OK 2_object_stats_trigger.sql (292.63µs)9102026/10/01 10:24:38 OK 20260923120000_add_pushes.sql (1.19ms)9112026/10/01 10:24:38 goose: successfully migrated database to version: 202609231200009122026/10/01 10:24:38 OK 2_object_stats_trigger.sql (578.75µs)9132026/10/01 10:24:38 OK 3_commit_push.sql (297.88µs)9142026/10/01 10:24:38 goose: up to current file version: 39152026/10/01 10:24:38 OK 3_commit_push.sql (231.67µs)9162026/10/01 10:24:38 goose: up to current file version: 39172026/10/01 10:24:38 OK 3_commit_push.sql (263.38µs)9182026/10/01 10:24:38 goose: up to current file version: 39192026/10/01 10:24:38 OK 1_commit_pending_closure.sql (1.17ms)9202026/10/01 10:24:38 OK 1_commit_pending_closure.sql (859.33µs)9212026/10/01 10:24:38 OK 2_object_stats_trigger.sql (260.96µs)9222026/10/01 10:24:38 OK 2_object_stats_trigger.sql (268µs)9232026/10/01 10:24:38 OK 3_commit_push.sql (178.5µs)9242026/10/01 10:24:38 goose: up to current file version: 39252026/10/01 10:24:38 OK 3_commit_push.sql (192.83µs)9262026/10/01 10:24:38 goose: up to current file version: 39272026/10/01 10:24:38 INFO Received cleanup request method=DELETE path=/api/pending_closures9282026/10/01 10:24:38 INFO Aborted multipart uploads count=0 kept=09292026/10/01 10:24:38 INFO Received uploads request method=POST path=/api/pending_closures9302026/10/01 10:24:39 INFO Received cleanup request method=DELETE path=/api/pending_closures9312026/10/01 10:24:39 INFO Aborted multipart uploads count=1 kept=09322026/10/01 10:24:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9332026-10-01 10:24:39.055 UTC [41470] ERROR: Closure does not exist: id=19342026-10-01 10:24:39.055 UTC [41470] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE9352026-10-01 10:24:39.055 UTC [41470] STATEMENT: -- name: CommitPendingClosure :exec936 SELECT commit_pending_closure($1::bigint)937 938--- PASS: TestService_cleanupPendingClosuresHandler (0.48s)939=== CONT TestDeduplicatedObjectsRecordedAsPending9402026/10/01 10:24:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9412026/10/01 10:24:39 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst942--- PASS: TestCompleteMultipartUnregistered (0.56s)943=== CONT TestService_readinessHandler9442026/10/01 10:24:39 INFO Received uploads request method=POST path=/api/pending_closures9452026/10/01 10:24:39 INFO Received uploads request method=POST path=/api/pending_closures9462026/10/01 10:24:39 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"947--- PASS: TestService_AuthMiddleware (1.12s)948=== CONT TestService_healthCheckHandler9492026/10/01 10:24:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9502026-10-01 10:24:39.890 UTC [41523] ERROR: relation "goose_db_version" does not exist at character 369512026-10-01 10:24:39.890 UTC [41523] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC952--- PASS: TestReadProxyConditionalGet (1.36s)953=== CONT TestGracefulShutdownDrainsInflight9542026/10/01 10:24:39 INFO Starting HTTP server address=127.0.0.1:613349552026/10/01 10:24:39 INFO Shutdown signal received, draining in-flight requests timeout=10s956--- PASS: TestGracefulShutdownDrainsInflight (0.07s)957=== CONT TestGCTaskStore_Fail958--- PASS: TestGCTaskStore_Fail (0.00s)959=== CONT TestGCTaskStore_PhaseUpdates960--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)961=== CONT TestGCTaskStore_CompletedAllowsNewTask962--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)963=== CONT TestGCTaskStore_GetReturnsLatest964--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)965=== CONT TestGCTaskStore_GetEmpty966--- PASS: TestGCTaskStore_GetEmpty (0.00s)967=== CONT TestGCTaskStore_ConflictDifferentParams968--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)969=== CONT TestGCTaskStore_DeduplicateSameParams970--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)971=== CONT TestGCTaskStore_StartNew972--- PASS: TestGCTaskStore_StartNew (0.00s)973=== CONT TestGCEndsOnShutdown9742026-10-01 10:24:40.028 UTC [41525] ERROR: relation "goose_db_version" does not exist at character 369752026-10-01 10:24:40.028 UTC [41525] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9762026/10/01 10:24:40 OK 20241026095416_initial_model.sql (111.66ms)9772026/10/01 10:24:40 OK 20251210153512_drop_unused_gin_index.sql (11.79ms)9782026/10/01 10:24:40 OK 20251218171726_add_pins.sql (17.49ms)9792026/10/01 10:24:40 OK 20260628120000_add_object_size_and_stats.sql (13.37ms)9802026/10/01 10:24:40 OK 20260905000000_add_claims.sql (21.54ms)981--- PASS: TestService_Rustfstest (1.52s)982=== CONT TestCommitRacingPendingCleanupKeepsObjects9832026/10/01 10:24:40 OK 20260920000000_drop_claims.sql (23.45ms)9842026/10/01 10:24:40 OK 20260923120000_add_pushes.sql (18.16ms)9852026/10/01 10:24:40 goose: successfully migrated database to version: 202609231200009862026/10/01 10:24:40 OK 1_commit_pending_closure.sql (952.33µs)9872026/10/01 10:24:40 OK 2_object_stats_trigger.sql (215.46µs)9882026/10/01 10:24:40 OK 3_commit_push.sql (193.38µs)9892026/10/01 10:24:40 goose: up to current file version: 39902026/10/01 10:24:40 OK 20241026095416_initial_model.sql (83.99ms)9912026/10/01 10:24:40 OK 20251210153512_drop_unused_gin_index.sql (9.49ms)9922026/10/01 10:24:40 OK 20251218171726_add_pins.sql (16.25ms)9932026/10/01 10:24:40 OK 20260628120000_add_object_size_and_stats.sql (9.7ms)9942026/10/01 10:24:40 OK 20260905000000_add_claims.sql (13.21ms)9952026/10/01 10:24:40 OK 20260920000000_drop_claims.sql (23.73ms)9962026/10/01 10:24:40 OK 20260923120000_add_pushes.sql (9.12ms)9972026/10/01 10:24:40 goose: successfully migrated database to version: 202609231200009982026/10/01 10:24:40 OK 1_commit_pending_closure.sql (934.46µs)9992026/10/01 10:24:40 OK 2_object_stats_trigger.sql (251.96µs)10002026/10/01 10:24:40 OK 3_commit_push.sql (188.83µs)10012026/10/01 10:24:40 goose: up to current file version: 310022026/10/01 10:24:40 INFO Received uploads request method=POST path=/api/pending_closures1003--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.80s)1004=== CONT TestPushWaitsForSweepHoldingRow10052026-10-01 10:24:40.497 UTC [41548] ERROR: relation "goose_db_version" does not exist at character 3610062026-10-01 10:24:40.497 UTC [41548] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10072026/10/01 10:24:40 INFO Received uploads request method=POST path=/api/pending_closures10082026/10/01 10:24:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10092026/10/01 10:24:40 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZGZiNWUwNjEtNmQ4OC00MmZlLTk2OTUtNGRkYzUxNTRhNDhmLmMxOTI4MmNmLTE0NGQtNDQ5OC1iODBlLTZiNGE4ZjJjMTI3YngxNzkwODUwMjc5MzQ1MDc1MDAw parts=1210102026/10/01 10:24:40 INFO Received uploads request method=POST path=/api/pending_closures1011--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.97s)1012=== CONT TestSweepRechecksPendingAfterLocking10132026/10/01 10:24:40 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10142026/10/01 10:24:40 INFO Received uploads request method=POST path=/api/pending_closures1015--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.00s)1016=== CONT TestGetExistingObjectsLocksRows10172026/10/01 10:24:40 OK 20241026095416_initial_model.sql (94.97ms)10182026/10/01 10:24:40 OK 20251210153512_drop_unused_gin_index.sql (6.22ms)10192026/10/01 10:24:40 OK 20251218171726_add_pins.sql (19ms)10202026/10/01 10:24:40 OK 20260628120000_add_object_size_and_stats.sql (21.35ms)10212026/10/01 10:24:40 INFO Received uploads request method=POST path=/api/pending_closures10222026/10/01 10:24:40 OK 20260905000000_add_claims.sql (18.51ms)10232026/10/01 10:24:40 OK 20260920000000_drop_claims.sql (35.1ms)10242026/10/01 10:24:40 OK 20260923120000_add_pushes.sql (6.83ms)10252026/10/01 10:24:40 goose: successfully migrated database to version: 2026092312000010262026/10/01 10:24:40 OK 1_commit_pending_closure.sql (2.82ms)10272026/10/01 10:24:40 OK 2_object_stats_trigger.sql (298.88µs)10282026/10/01 10:24:40 OK 3_commit_push.sql (183.96µs)10292026/10/01 10:24:40 goose: up to current file version: 310302026/10/01 10:24:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10312026/10/01 10:24:40 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZGZiNWUwNjEtNmQ4OC00MmZlLTk2OTUtNGRkYzUxNTRhNDhmLmIxMmNiMGFjLTYxMzEtNGU4YS1hYjdjLTQ1MjgxZDAxYTUyN3gxNzkwODUwMjgwNzU0Mjg2MDAw10322026/10/01 10:24:40 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZGZiNWUwNjEtNmQ4OC00MmZlLTk2OTUtNGRkYzUxNTRhNDhmLmIxMmNiMGFjLTYxMzEtNGU4YS1hYjdjLTQ1MjgxZDAxYTUyN3gxNzkwODUwMjgwNzU0Mjg2MDAw parts=11033--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.34s)1034=== CONT TestRegisterCompletedObjectNeedsPendingRow10352026/10/01 10:24:40 INFO Received uploads request method=POST path=/api/pending_closures1036--- PASS: TestDeduplicatedObjectsRecordedAsPending (1.89s)1037=== CONT TestSweepSkipsRowsLockedByPush10382026-10-01 10:24:41.026 UTC [41596] ERROR: relation "goose_db_version" does not exist at character 3610392026-10-01 10:24:41.026 UTC [41596] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10402026/10/01 10:24:41 WARN readiness check failed error="closed pool"1041--- PASS: TestService_readinessHandler (1.96s)1042=== CONT TestFailedS3DeleteKeepsTombstone10432026-10-01 10:24:41.111 UTC [41598] ERROR: relation "goose_db_version" does not exist at character 3610442026-10-01 10:24:41.111 UTC [41598] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10452026/10/01 10:24:41 OK 20241026095416_initial_model.sql (83.87ms)10462026/10/01 10:24:41 OK 20251210153512_drop_unused_gin_index.sql (1.05ms)10472026/10/01 10:24:41 OK 20251218171726_add_pins.sql (11.89ms)10482026/10/01 10:24:41 OK 20260628120000_add_object_size_and_stats.sql (47.37ms)10492026/10/01 10:24:41 OK 20241026095416_initial_model.sql (66.77ms)10502026/10/01 10:24:41 OK 20251210153512_drop_unused_gin_index.sql (1.31ms)10512026/10/01 10:24:41 OK 20251218171726_add_pins.sql (16.13ms)10522026/10/01 10:24:41 OK 20260905000000_add_claims.sql (31.53ms)10532026/10/01 10:24:41 OK 20260628120000_add_object_size_and_stats.sql (25.27ms)10542026/10/01 10:24:41 OK 20260920000000_drop_claims.sql (24.81ms)10552026/10/01 10:24:41 OK 20260923120000_add_pushes.sql (9.21ms)10562026/10/01 10:24:41 goose: successfully migrated database to version: 202609231200001057--- PASS: TestService_healthCheckHandler (1.56s)1058=== CONT TestForceGCDuringPushOffersSweptObject1059=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1060=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1061=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1062=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1063=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10642026/10/01 10:24:41 OK 1_commit_pending_closure.sql (3.77ms)10652026/10/01 10:24:41 OK 2_object_stats_trigger.sql (524.33µs)10662026/10/01 10:24:41 OK 3_commit_push.sql (382.08µs)10672026/10/01 10:24:41 goose: up to current file version: 310682026/10/01 10:24:41 OK 20260905000000_add_claims.sql (24.55ms)10692026/10/01 10:24:41 OK 20260920000000_drop_claims.sql (25.48ms)10702026/10/01 10:24:41 OK 20260923120000_add_pushes.sql (5.47ms)10712026/10/01 10:24:41 goose: successfully migrated database to version: 2026092312000010722026/10/01 10:24:41 OK 1_commit_pending_closure.sql (1.9ms)10732026/10/01 10:24:41 OK 2_object_stats_trigger.sql (327.29µs)10742026/10/01 10:24:41 OK 3_commit_push.sql (284.13µs)10752026/10/01 10:24:41 goose: up to current file version: 31076--- PASS: TestGCEndsOnShutdown (1.45s)1077=== CONT TestGCSweepDeliversEachKeyOnce10782026-10-01 10:24:41.620 UTC [41613] ERROR: relation "goose_db_version" does not exist at character 3610792026-10-01 10:24:41.620 UTC [41613] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10802026-10-01 10:24:41.691 UTC [41615] ERROR: relation "goose_db_version" does not exist at character 3610812026-10-01 10:24:41.691 UTC [41615] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10822026-10-01 10:24:41.691 UTC [41616] ERROR: relation "goose_db_version" does not exist at character 3610832026-10-01 10:24:41.691 UTC [41616] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10842026/10/01 10:24:41 OK 20241026095416_initial_model.sql (56.73ms)10852026/10/01 10:24:41 INFO Aborted multipart uploads count=0 kept=010862026/10/01 10:24:41 WARN Force mode enabled - objects will be deleted immediately without grace period10872026/10/01 10:24:41 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=010882026/10/01 10:24:41 OK 20251210153512_drop_unused_gin_index.sql (9.65ms)10892026/10/01 10:24:41 INFO Vacuumed table table=pending_closures10902026/10/01 10:24:41 OK 20251218171726_add_pins.sql (19.64ms)10912026/10/01 10:24:41 INFO Vacuumed table table=pending_objects10922026/10/01 10:24:41 INFO Vacuumed table table=multipart_uploads10932026/10/01 10:24:41 INFO Vacuumed table table=closures10942026/10/01 10:24:41 INFO Vacuumed table table=objects10952026/10/01 10:24:41 OK 20260628120000_add_object_size_and_stats.sql (22.65ms)10962026/10/01 10:24:41 OK 20260905000000_add_claims.sql (8.99ms)1097--- PASS: TestCommitRacingPendingCleanupKeepsObjects (1.66s)1098=== CONT TestTombstonedObjectOfferedWithoutWaiting10992026/10/01 10:24:41 OK 20241026095416_initial_model.sql (62.39ms)11002026/10/01 10:24:41 OK 20260920000000_drop_claims.sql (3.19ms)11012026/10/01 10:24:41 OK 20251210153512_drop_unused_gin_index.sql (1.41ms)11022026/10/01 10:24:41 OK 20260923120000_add_pushes.sql (1.02ms)11032026/10/01 10:24:41 goose: successfully migrated database to version: 2026092312000011042026/10/01 10:24:41 OK 20251218171726_add_pins.sql (1.31ms)11052026/10/01 10:24:41 OK 1_commit_pending_closure.sql (1.35ms)11062026/10/01 10:24:41 OK 2_object_stats_trigger.sql (382.88µs)11072026/10/01 10:24:41 OK 3_commit_push.sql (395.58µs)11082026/10/01 10:24:41 goose: up to current file version: 311092026/10/01 10:24:41 OK 20241026095416_initial_model.sql (79.65ms)11102026/10/01 10:24:41 OK 20260628120000_add_object_size_and_stats.sql (14.68ms)11112026-10-01 10:24:41.805 UTC [41626] ERROR: relation "goose_db_version" does not exist at character 3611122026-10-01 10:24:41.805 UTC [41626] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11132026-10-01 10:24:41.811 UTC [41627] ERROR: relation "goose_db_version" does not exist at character 3611142026-10-01 10:24:41.811 UTC [41627] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11152026/10/01 10:24:41 OK 20251210153512_drop_unused_gin_index.sql (7.01ms)11162026/10/01 10:24:41 OK 20251218171726_add_pins.sql (7.29ms)11172026/10/01 10:24:41 OK 20260905000000_add_claims.sql (14.98ms)11182026/10/01 10:24:41 OK 20260920000000_drop_claims.sql (14.5ms)11192026/10/01 10:24:41 OK 20260628120000_add_object_size_and_stats.sql (16.55ms)11202026/10/01 10:24:41 OK 20260923120000_add_pushes.sql (1.67ms)11212026/10/01 10:24:41 goose: successfully migrated database to version: 2026092312000011222026/10/01 10:24:41 OK 1_commit_pending_closure.sql (2.23ms)11232026/10/01 10:24:41 OK 2_object_stats_trigger.sql (218.13µs)11242026/10/01 10:24:41 OK 3_commit_push.sql (170.29µs)11252026/10/01 10:24:41 goose: up to current file version: 311262026/10/01 10:24:41 OK 20260905000000_add_claims.sql (16.45ms)11272026/10/01 10:24:41 OK 20260920000000_drop_claims.sql (11.71ms)11282026/10/01 10:24:41 OK 20260923120000_add_pushes.sql (1.82ms)11292026/10/01 10:24:41 goose: successfully migrated database to version: 2026092312000011302026/10/01 10:24:41 OK 20241026095416_initial_model.sql (31.34ms)11312026/10/01 10:24:41 OK 1_commit_pending_closure.sql (1.19ms)11322026/10/01 10:24:41 OK 2_object_stats_trigger.sql (203.96µs)11332026/10/01 10:24:41 OK 3_commit_push.sql (148.67µs)11342026/10/01 10:24:41 goose: up to current file version: 311352026/10/01 10:24:41 OK 20251210153512_drop_unused_gin_index.sql (6.51ms)11362026/10/01 10:24:41 OK 20251218171726_add_pins.sql (5.82ms)11372026/10/01 10:24:41 OK 20241026095416_initial_model.sql (55.83ms)11382026/10/01 10:24:41 OK 20260628120000_add_object_size_and_stats.sql (13.4ms)11392026/10/01 10:24:41 OK 20251210153512_drop_unused_gin_index.sql (1.31ms)11402026/10/01 10:24:41 OK 20251218171726_add_pins.sql (7.89ms)11412026/10/01 10:24:41 OK 20260628120000_add_object_size_and_stats.sql (14.86ms)11422026/10/01 10:24:41 OK 20260905000000_add_claims.sql (23.01ms)11432026/10/01 10:24:41 OK 20260920000000_drop_claims.sql (12.15ms)11442026/10/01 10:24:41 OK 20260923120000_add_pushes.sql (12.54ms)11452026/10/01 10:24:41 goose: successfully migrated database to version: 2026092312000011462026/10/01 10:24:41 OK 1_commit_pending_closure.sql (926.5µs)11472026/10/01 10:24:41 OK 2_object_stats_trigger.sql (212.08µs)11482026/10/01 10:24:41 OK 3_commit_push.sql (163.92µs)11492026/10/01 10:24:41 goose: up to current file version: 311502026/10/01 10:24:41 OK 20260905000000_add_claims.sql (35.9ms)11512026/10/01 10:24:41 INFO Received uploads request method=POST path=/api/pending_closures11522026/10/01 10:24:41 OK 20260920000000_drop_claims.sql (12.49ms)11532026/10/01 10:24:41 OK 20260923120000_add_pushes.sql (12.73ms)11542026/10/01 10:24:41 goose: successfully migrated database to version: 2026092312000011552026/10/01 10:24:41 OK 1_commit_pending_closure.sql (841.25µs)11562026/10/01 10:24:41 OK 2_object_stats_trigger.sql (208.79µs)11572026/10/01 10:24:41 OK 3_commit_push.sql (167.13µs)11582026/10/01 10:24:41 goose: up to current file version: 311592026-10-01 10:24:42.102 UTC [41648] ERROR: relation "goose_db_version" does not exist at character 3611602026-10-01 10:24:42.102 UTC [41648] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11612026/10/01 10:24:42 INFO Aborted multipart uploads count=0 kept=011622026/10/01 10:24:42 WARN Force mode enabled - objects will be deleted immediately without grace period11632026-10-01 10:24:42.189 UTC [41650] ERROR: relation "goose_db_version" does not exist at character 3611642026-10-01 10:24:42.189 UTC [41650] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11652026/10/01 10:24:42 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=011662026/10/01 10:24:42 INFO Vacuumed table table=pending_closures11672026/10/01 10:24:42 INFO Vacuumed table table=pending_objects11682026/10/01 10:24:42 INFO Vacuumed table table=multipart_uploads11692026/10/01 10:24:42 INFO Vacuumed table table=closures11702026/10/01 10:24:42 INFO Vacuumed table table=objects11712026/10/01 10:24:42 OK 20241026095416_initial_model.sql (98.15ms)1172--- PASS: TestSweepRechecksPendingAfterLocking (1.65s)1173=== CONT TestGCSweepSkipsPendingObjects11742026/10/01 10:24:42 OK 20251210153512_drop_unused_gin_index.sql (2.02ms)11752026/10/01 10:24:42 OK 20251218171726_add_pins.sql (19ms)11762026/10/01 10:24:42 OK 20260628120000_add_object_size_and_stats.sql (15.05ms)11772026/10/01 10:24:42 OK 20260905000000_add_claims.sql (25.27ms)11782026/10/01 10:24:42 OK 20241026095416_initial_model.sql (68.83ms)11792026/10/01 10:24:42 OK 20251210153512_drop_unused_gin_index.sql (6.33ms)11802026/10/01 10:24:42 OK 20260920000000_drop_claims.sql (18.68ms)11812026/10/01 10:24:42 OK 20251218171726_add_pins.sql (17.66ms)11822026/10/01 10:24:42 OK 20260923120000_add_pushes.sql (12.31ms)11832026/10/01 10:24:42 goose: successfully migrated database to version: 2026092312000011842026/10/01 10:24:42 OK 1_commit_pending_closure.sql (2.35ms)11852026/10/01 10:24:42 OK 2_object_stats_trigger.sql (509.5µs)11862026/10/01 10:24:42 OK 3_commit_push.sql (313.08µs)11872026/10/01 10:24:42 goose: up to current file version: 31188--- PASS: TestGetExistingObjectsLocksRows (1.75s)1189=== CONT TestCreatePin_ReservedPins11902026/10/01 10:24:42 OK 20260628120000_add_object_size_and_stats.sql (39.74ms)11912026-10-01 10:24:42.385 UTC [41660] ERROR: relation "goose_db_version" does not exist at character 3611922026-10-01 10:24:42.385 UTC [41660] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11932026/10/01 10:24:42 OK 20260905000000_add_claims.sql (18.26ms)11942026/10/01 10:24:42 OK 20260920000000_drop_claims.sql (1.76ms)11952026/10/01 10:24:42 OK 20260923120000_add_pushes.sql (1.69ms)11962026/10/01 10:24:42 goose: successfully migrated database to version: 2026092312000011972026/10/01 10:24:42 OK 1_commit_pending_closure.sql (967.54µs)11982026/10/01 10:24:42 OK 2_object_stats_trigger.sql (208.42µs)11992026/10/01 10:24:42 OK 3_commit_push.sql (164.88µs)12002026/10/01 10:24:42 goose: up to current file version: 312012026/10/01 10:24:42 OK 20241026095416_initial_model.sql (38.05ms)12022026/10/01 10:24:42 OK 20251210153512_drop_unused_gin_index.sql (5.72ms)12032026/10/01 10:24:42 OK 20251218171726_add_pins.sql (8.55ms)1204--- PASS: TestPushWaitsForSweepHoldingRow (2.09s)1205=== CONT TestReadProxyHead12062026/10/01 10:24:42 OK 20260628120000_add_object_size_and_stats.sql (28.23ms)12072026/10/01 10:24:42 OK 20260905000000_add_claims.sql (10.11ms)12082026/10/01 10:24:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61460/oidc12092026-10-01 10:24:42.498 UTC [41667] ERROR: relation "goose_db_version" does not exist at character 3612102026-10-01 10:24:42.498 UTC [41667] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12112026/10/01 10:24:42 OK 20260920000000_drop_claims.sql (16.9ms)12122026/10/01 10:24:42 OK 20260923120000_add_pushes.sql (5.66ms)12132026/10/01 10:24:42 goose: successfully migrated database to version: 2026092312000012142026/10/01 10:24:42 OK 1_commit_pending_closure.sql (1.47ms)1215--- PASS: TestRegisterCompletedObjectNeedsPendingRow (1.60s)1216=== CONT TestReadProxyInvalidPath12172026/10/01 10:24:42 OK 2_object_stats_trigger.sql (504.33µs)12182026/10/01 10:24:42 OK 3_commit_push.sql (593.67µs)12192026/10/01 10:24:42 goose: up to current file version: 312202026/10/01 10:24:42 OK 20241026095416_initial_model.sql (58.2ms)12212026/10/01 10:24:42 OK 20251210153512_drop_unused_gin_index.sql (17.96ms)12222026/10/01 10:24:42 OK 20251218171726_add_pins.sql (12.51ms)12232026/10/01 10:24:42 OK 20260628120000_add_object_size_and_stats.sql (22.62ms)12242026/10/01 10:24:42 OK 20260905000000_add_claims.sql (17.37ms)12252026/10/01 10:24:42 OK 20260920000000_drop_claims.sql (18.76ms)12262026/10/01 10:24:42 OK 20260923120000_add_pushes.sql (1.36ms)12272026/10/01 10:24:42 goose: successfully migrated database to version: 2026092312000012282026/10/01 10:24:42 OK 1_commit_pending_closure.sql (1.44ms)12292026/10/01 10:24:42 OK 2_object_stats_trigger.sql (267.88µs)12302026/10/01 10:24:42 OK 3_commit_push.sql (178.54µs)12312026/10/01 10:24:42 goose: up to current file version: 312322026/10/01 10:24:42 INFO Aborted multipart uploads count=0 kept=012332026/10/01 10:24:42 WARN Force mode enabled - objects will be deleted immediately without grace period12342026/10/01 10:24:42 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=012352026/10/01 10:24:42 INFO Vacuumed table table=pending_closures12362026/10/01 10:24:42 INFO Vacuumed table table=pending_objects12372026/10/01 10:24:42 INFO Vacuumed table table=multipart_uploads12382026/10/01 10:24:42 INFO Vacuumed table table=closures12392026/10/01 10:24:42 INFO Vacuumed table table=objects12402026/10/01 10:24:42 INFO Aborted multipart uploads count=0 kept=012412026/10/01 10:24:42 WARN Force mode enabled - objects will be deleted immediately without grace period12422026/10/01 10:24:42 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=1 objects-failed-to-delete=012432026/10/01 10:24:42 INFO Vacuumed table table=pending_closures12442026/10/01 10:24:42 INFO Vacuumed table table=pending_objects12452026/10/01 10:24:42 INFO Vacuumed table table=multipart_uploads12462026/10/01 10:24:42 INFO Vacuumed table table=closures12472026/10/01 10:24:42 INFO Vacuumed table table=objects1248--- PASS: TestSweepSkipsRowsLockedByPush (1.82s)1249=== CONT TestReadProxy40412502026/10/01 10:24:42 INFO Received uploads request method=POST path=/api/pending_closures12512026/10/01 10:24:42 INFO Aborted multipart uploads count=0 kept=012522026/10/01 10:24:42 WARN Force mode enabled - objects will be deleted immediately without grace period12532026/10/01 10:24:42 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12542026/10/01 10:24:42 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1255--- PASS: TestFailedS3DeleteKeepsTombstone (1.90s)1256=== CONT TestReadProxyNarStreaming12572026/10/01 10:24:43 INFO Received uploads request method=POST path=/api/pending_closures12582026-10-01 10:24:43.093 UTC [41695] ERROR: relation "goose_db_version" does not exist at character 3612592026-10-01 10:24:43.093 UTC [41695] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12602026/10/01 10:24:43 OK 20241026095416_initial_model.sql (109.46ms)12612026/10/01 10:24:43 OK 20251210153512_drop_unused_gin_index.sql (8.24ms)12622026/10/01 10:24:43 OK 20251218171726_add_pins.sql (2.4ms)1263--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (2.00s)1264=== CONT TestReadProxyNarinfoAlreadyDecompressed12652026/10/01 10:24:43 OK 20260628120000_add_object_size_and_stats.sql (36.08ms)12662026/10/01 10:24:43 INFO Aborted multipart uploads count=0 kept=012672026/10/01 10:24:43 WARN Force mode enabled - objects will be deleted immediately without grace period12682026/10/01 10:24:43 OK 20260905000000_add_claims.sql (52.16ms)12692026/10/01 10:24:43 OK 20260920000000_drop_claims.sql (27.09ms)12702026/10/01 10:24:43 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=012712026/10/01 10:24:43 INFO Vacuumed table table=pending_closures12722026/10/01 10:24:43 INFO Vacuumed table table=pending_objects12732026/10/01 10:24:43 INFO Vacuumed table table=multipart_uploads12742026/10/01 10:24:43 INFO Vacuumed table table=closures12752026/10/01 10:24:43 OK 20260923120000_add_pushes.sql (24.87ms)12762026/10/01 10:24:43 goose: successfully migrated database to version: 2026092312000012772026/10/01 10:24:43 OK 1_commit_pending_closure.sql (1.43ms)12782026/10/01 10:24:43 OK 2_object_stats_trigger.sql (288.46µs)12792026/10/01 10:24:43 OK 3_commit_push.sql (229.75µs)12802026/10/01 10:24:43 goose: up to current file version: 312812026/10/01 10:24:43 INFO Vacuumed table table=objects1282--- PASS: TestGCSweepDeliversEachKeyOnce (1.93s)1283=== CONT TestReadProxyNarinfo12842026/10/01 10:24:43 INFO Received uploads request method=POST path=/api/pending_closures1285--- PASS: TestTombstonedObjectOfferedWithoutWaiting (1.69s)1286=== CONT TestIsValidCachePath1287=== RUN TestIsValidCachePath/narinfo1288=== PAUSE TestIsValidCachePath/narinfo1289=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1290=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1291=== RUN TestIsValidCachePath/nar_zst1292=== PAUSE TestIsValidCachePath/nar_zst1293=== RUN TestIsValidCachePath/nar_xz1294=== PAUSE TestIsValidCachePath/nar_xz1295=== RUN TestIsValidCachePath/nar_bz21296=== PAUSE TestIsValidCachePath/nar_bz21297=== RUN TestIsValidCachePath/nar_uncompressed1298=== PAUSE TestIsValidCachePath/nar_uncompressed1299=== RUN TestIsValidCachePath/ls1300=== PAUSE TestIsValidCachePath/ls1301=== RUN TestIsValidCachePath/log1302=== PAUSE TestIsValidCachePath/log1303=== RUN TestIsValidCachePath/realisation1304=== PAUSE TestIsValidCachePath/realisation1305=== RUN TestIsValidCachePath/nix-cache-info1306=== PAUSE TestIsValidCachePath/nix-cache-info1307=== RUN TestIsValidCachePath/index.html1308=== PAUSE TestIsValidCachePath/index.html1309=== RUN TestIsValidCachePath/traversal_parent1310=== PAUSE TestIsValidCachePath/traversal_parent1311=== RUN TestIsValidCachePath/traversal_in_middle1312=== PAUSE TestIsValidCachePath/traversal_in_middle1313=== RUN TestIsValidCachePath/invalid_char_e1314=== PAUSE TestIsValidCachePath/invalid_char_e1315=== RUN TestIsValidCachePath/invalid_char_u1316=== PAUSE TestIsValidCachePath/invalid_char_u1317=== RUN TestIsValidCachePath/random_path1318=== PAUSE TestIsValidCachePath/random_path1319=== RUN TestIsValidCachePath/empty1320=== PAUSE TestIsValidCachePath/empty1321=== RUN TestIsValidCachePath/leading_slash1322=== PAUSE TestIsValidCachePath/leading_slash1323=== RUN TestIsValidCachePath/wrong_extension1324=== PAUSE TestIsValidCachePath/wrong_extension1325=== RUN TestIsValidCachePath/short_hash1326=== PAUSE TestIsValidCachePath/short_hash1327=== CONT TestProxyHeadersOnlyTrustedOnSocket13282026-10-01 10:24:43.537 UTC [41718] ERROR: relation "goose_db_version" does not exist at character 3613292026-10-01 10:24:43.537 UTC [41718] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13302026-10-01 10:24:43.582 UTC [41721] ERROR: relation "goose_db_version" does not exist at character 3613312026-10-01 10:24:43.582 UTC [41721] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13322026-10-01 10:24:43.628 UTC [41725] ERROR: relation "goose_db_version" does not exist at character 3613332026-10-01 10:24:43.628 UTC [41725] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13342026/10/01 10:24:43 OK 20241026095416_initial_model.sql (68.16ms)13352026/10/01 10:24:43 INFO Received uploads request method=POST path=/api/pending_closures13362026/10/01 10:24:43 OK 20251210153512_drop_unused_gin_index.sql (1.38ms)13372026/10/01 10:24:43 OK 20251218171726_add_pins.sql (13.87ms)13382026/10/01 10:24:43 OK 20260628120000_add_object_size_and_stats.sql (10.52ms)13392026/10/01 10:24:43 OK 20241026095416_initial_model.sql (59.37ms)13402026/10/01 10:24:43 INFO Aborted multipart uploads count=0 kept=013412026/10/01 10:24:43 WARN Force mode enabled - objects will be deleted immediately without grace period13422026/10/01 10:24:43 OK 20251210153512_drop_unused_gin_index.sql (9.45ms)13432026/10/01 10:24:43 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=013442026/10/01 10:24:43 OK 20260905000000_add_claims.sql (17.55ms)13452026/10/01 10:24:43 INFO Vacuumed table table=pending_closures13462026/10/01 10:24:43 OK 20251218171726_add_pins.sql (16.04ms)13472026/10/01 10:24:43 OK 20260920000000_drop_claims.sql (16.65ms)13482026/10/01 10:24:43 INFO Vacuumed table table=pending_objects13492026/10/01 10:24:43 INFO Vacuumed table table=multipart_uploads13502026/10/01 10:24:43 OK 20260923120000_add_pushes.sql (2.08ms)13512026/10/01 10:24:43 goose: successfully migrated database to version: 2026092312000013522026/10/01 10:24:43 OK 20260628120000_add_object_size_and_stats.sql (10.3ms)13532026/10/01 10:24:43 INFO Vacuumed table table=closures13542026/10/01 10:24:43 OK 20241026095416_initial_model.sql (45.97ms)13552026/10/01 10:24:43 OK 1_commit_pending_closure.sql (1.55ms)13562026/10/01 10:24:43 OK 20251210153512_drop_unused_gin_index.sql (699.5µs)13572026/10/01 10:24:43 OK 2_object_stats_trigger.sql (438.13µs)13582026/10/01 10:24:43 OK 3_commit_push.sql (407.75µs)13592026/10/01 10:24:43 goose: up to current file version: 313602026/10/01 10:24:43 INFO Vacuumed table table=objects13612026-10-01 10:24:43.709 UTC [41728] ERROR: relation "goose_db_version" does not exist at character 3613622026-10-01 10:24:43.709 UTC [41728] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13632026/10/01 10:24:43 OK 20260905000000_add_claims.sql (8.42ms)13642026/10/01 10:24:43 OK 20251218171726_add_pins.sql (12.56ms)1365--- PASS: TestGCSweepSkipsPendingObjects (1.48s)1366=== CONT TestParseSingleRange1367=== RUN TestParseSingleRange/none1368=== PAUSE TestParseSingleRange/none1369=== RUN TestParseSingleRange/unknown_unit1370=== PAUSE TestParseSingleRange/unknown_unit1371=== RUN TestParseSingleRange/multi-range_ignored1372=== PAUSE TestParseSingleRange/multi-range_ignored1373=== RUN TestParseSingleRange/malformed_no_dash1374=== PAUSE TestParseSingleRange/malformed_no_dash1375=== RUN TestParseSingleRange/malformed_both_empty1376=== PAUSE TestParseSingleRange/malformed_both_empty1377=== RUN TestParseSingleRange/malformed_end_before_start1378=== PAUSE TestParseSingleRange/malformed_end_before_start1379=== RUN TestParseSingleRange/closed1380=== PAUSE TestParseSingleRange/closed1381=== RUN TestParseSingleRange/open-ended1382=== PAUSE TestParseSingleRange/open-ended1383=== RUN TestParseSingleRange/end_clamped_to_size1384=== PAUSE TestParseSingleRange/end_clamped_to_size1385=== RUN TestParseSingleRange/suffix1386=== PAUSE TestParseSingleRange/suffix1387=== RUN TestParseSingleRange/suffix_exceeds_size1388=== PAUSE TestParseSingleRange/suffix_exceeds_size1389=== RUN TestParseSingleRange/single_byte1390=== PAUSE TestParseSingleRange/single_byte1391=== RUN TestParseSingleRange/start_past_EOF1392=== PAUSE TestParseSingleRange/start_past_EOF1393=== RUN TestParseSingleRange/start_far_past_EOF1394=== PAUSE TestParseSingleRange/start_far_past_EOF1395=== CONT TestPresentNotReportedWhileGCDeletesClosure13962026/10/01 10:24:43 OK 20260920000000_drop_claims.sql (13.89ms)13972026/10/01 10:24:43 OK 20260923120000_add_pushes.sql (7.4ms)13982026/10/01 10:24:43 goose: successfully migrated database to version: 2026092312000013992026/10/01 10:24:43 OK 1_commit_pending_closure.sql (1.5ms)14002026/10/01 10:24:43 OK 2_object_stats_trigger.sql (233µs)14012026/10/01 10:24:43 OK 3_commit_push.sql (174.54µs)14022026/10/01 10:24:43 goose: up to current file version: 314032026/10/01 10:24:43 OK 20260628120000_add_object_size_and_stats.sql (22.86ms)14042026/10/01 10:24:43 OK 20260905000000_add_claims.sql (2.48ms)14052026/10/01 10:24:43 OK 20260920000000_drop_claims.sql (13.17ms)14062026/10/01 10:24:43 OK 20260923120000_add_pushes.sql (10.95ms)14072026/10/01 10:24:43 goose: successfully migrated database to version: 2026092312000014082026/10/01 10:24:43 OK 1_commit_pending_closure.sql (1.95ms)14092026/10/01 10:24:43 OK 2_object_stats_trigger.sql (492.17µs)14102026/10/01 10:24:43 OK 3_commit_push.sql (186.21µs)14112026/10/01 10:24:43 goose: up to current file version: 314122026/10/01 10:24:43 OK 20241026095416_initial_model.sql (40.93ms)14132026/10/01 10:24:43 OK 20251210153512_drop_unused_gin_index.sql (7.48ms)14142026/10/01 10:24:43 OK 20251218171726_add_pins.sql (15.83ms)14152026/10/01 10:24:43 OK 20260628120000_add_object_size_and_stats.sql (26.14ms)14162026/10/01 10:24:43 OK 20260905000000_add_claims.sql (19.57ms)14172026/10/01 10:24:43 OK 20260920000000_drop_claims.sql (25.67ms)14182026/10/01 10:24:43 OK 20260923120000_add_pushes.sql (1.45ms)14192026/10/01 10:24:43 goose: successfully migrated database to version: 202609231200001420--- PASS: TestReadProxyInvalidPath (1.37s)1421=== CONT TestPresentReportsOnlyClosureRoots14222026/10/01 10:24:43 OK 1_commit_pending_closure.sql (1.9ms)14232026/10/01 10:24:43 OK 2_object_stats_trigger.sql (322.04µs)14242026/10/01 10:24:43 OK 3_commit_push.sql (222.54µs)14252026/10/01 10:24:43 goose: up to current file version: 314262026-10-01 10:24:43.955 UTC [41744] ERROR: relation "goose_db_version" does not exist at character 3614272026-10-01 10:24:43.955 UTC [41744] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14282026/10/01 10:24:44 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14292026/10/01 10:24:44 WARN Refused reserved pin name=worker-x86_64-linux14302026/10/01 10:24:44 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14312026/10/01 10:24:44 INFO Received create pin request method=POST path=/api/pins/my-app14322026/10/01 10:24:44 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1433--- PASS: TestCreatePin_ReservedPins (1.68s)1434=== CONT TestMultipartCleanup14352026/10/01 10:24:44 OK 20241026095416_initial_model.sql (97.85ms)14362026/10/01 10:24:44 OK 20251210153512_drop_unused_gin_index.sql (8.61ms)14372026/10/01 10:24:44 OK 20251218171726_add_pins.sql (3.31ms)14382026/10/01 10:24:44 OK 20260628120000_add_object_size_and_stats.sql (22.88ms)14392026/10/01 10:24:44 OK 20260905000000_add_claims.sql (18.41ms)14402026/10/01 10:24:44 OK 20260920000000_drop_claims.sql (16.95ms)14412026/10/01 10:24:44 OK 20260923120000_add_pushes.sql (7.83ms)14422026/10/01 10:24:44 goose: successfully migrated database to version: 2026092312000014432026/10/01 10:24:44 OK 1_commit_pending_closure.sql (2.03ms)14442026/10/01 10:24:44 OK 2_object_stats_trigger.sql (350.67µs)14452026/10/01 10:24:44 OK 3_commit_push.sql (316.42µs)14462026/10/01 10:24:44 goose: up to current file version: 31447--- PASS: TestReadProxyHead (1.79s)1448=== CONT TestOrphanedObjectsGCStressTest14492026-10-01 10:24:44.285 UTC [41754] ERROR: relation "goose_db_version" does not exist at character 3614502026-10-01 10:24:44.285 UTC [41754] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14512026-10-01 10:24:44.353 UTC [41758] ERROR: relation "goose_db_version" does not exist at character 3614522026-10-01 10:24:44.353 UTC [41758] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14532026/10/01 10:24:44 OK 20241026095416_initial_model.sql (73.33ms)14542026/10/01 10:24:44 OK 20251210153512_drop_unused_gin_index.sql (7.89ms)14552026-10-01 10:24:44.432 UTC [41766] ERROR: relation "goose_db_version" does not exist at character 3614562026-10-01 10:24:44.432 UTC [41766] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14572026/10/01 10:24:44 OK 20251218171726_add_pins.sql (29.29ms)14582026/10/01 10:24:44 OK 20260628120000_add_object_size_and_stats.sql (46.29ms)14592026/10/01 10:24:44 OK 20241026095416_initial_model.sql (128.02ms)14602026/10/01 10:24:44 OK 20251210153512_drop_unused_gin_index.sql (7.3ms)14612026/10/01 10:24:44 OK 20260905000000_add_claims.sql (56.52ms)14622026/10/01 10:24:44 OK 20251218171726_add_pins.sql (33.54ms)1463--- PASS: TestReadProxy404 (1.78s)1464=== CONT TestOrphanedObjectsGC14652026/10/01 10:24:44 OK 20260920000000_drop_claims.sql (33.39ms)14662026/10/01 10:24:44 OK 20260628120000_add_object_size_and_stats.sql (40.75ms)14672026/10/01 10:24:44 OK 20260923120000_add_pushes.sql (25.39ms)14682026/10/01 10:24:44 goose: successfully migrated database to version: 2026092312000014692026/10/01 10:24:44 OK 1_commit_pending_closure.sql (1.63ms)14702026/10/01 10:24:44 OK 2_object_stats_trigger.sql (293.92µs)14712026/10/01 10:24:44 OK 3_commit_push.sql (234.42µs)14722026/10/01 10:24:44 goose: up to current file version: 314732026/10/01 10:24:44 OK 20260905000000_add_claims.sql (62.23ms)14742026/10/01 10:24:44 OK 20241026095416_initial_model.sql (187.6ms)14752026/10/01 10:24:44 OK 20260920000000_drop_claims.sql (44.27ms)14762026/10/01 10:24:44 OK 20251210153512_drop_unused_gin_index.sql (9.82ms)14772026/10/01 10:24:44 OK 20260923120000_add_pushes.sql (14.2ms)14782026/10/01 10:24:44 goose: successfully migrated database to version: 2026092312000014792026/10/01 10:24:44 OK 1_commit_pending_closure.sql (1.06ms)14802026/10/01 10:24:44 OK 2_object_stats_trigger.sql (247.13µs)14812026/10/01 10:24:44 OK 3_commit_push.sql (219.75µs)14822026/10/01 10:24:44 goose: up to current file version: 314832026/10/01 10:24:44 OK 20251218171726_add_pins.sql (35.23ms)1484--- PASS: TestReadProxyNarStreaming (1.74s)1485=== CONT TestObjectStatsTrigger14862026/10/01 10:24:44 OK 20260628120000_add_object_size_and_stats.sql (37.54ms)14872026/10/01 10:24:44 OK 20260905000000_add_claims.sql (22.97ms)14882026/10/01 10:24:44 OK 20260920000000_drop_claims.sql (30.23ms)14892026/10/01 10:24:44 OK 20260923120000_add_pushes.sql (18.13ms)14902026/10/01 10:24:44 goose: successfully migrated database to version: 2026092312000014912026/10/01 10:24:44 OK 1_commit_pending_closure.sql (1.23ms)14922026/10/01 10:24:44 OK 2_object_stats_trigger.sql (220.38µs)14932026/10/01 10:24:44 OK 3_commit_push.sql (166.79µs)14942026/10/01 10:24:44 goose: up to current file version: 31495--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.73s)1496=== CONT TestPendingCleanupUsesOneCutoff14972026-10-01 10:24:45.166 UTC [41783] ERROR: relation "goose_db_version" does not exist at character 3614982026-10-01 10:24:45.166 UTC [41783] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14992026/10/01 10:24:45 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"15002026/10/01 10:24:45 WARN Rate limiter enabled after throttle name=s3-test rate=515012026/10/01 10:24:45 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1502=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1503 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101504 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001505--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.81s)1506=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded15072026/10/01 10:24:45 OK 20241026095416_initial_model.sql (263.67ms)15082026/10/01 10:24:45 OK 20251210153512_drop_unused_gin_index.sql (17.8ms)15092026/10/01 10:24:45 OK 20251218171726_add_pins.sql (48.8ms)15102026/10/01 10:24:45 OK 20260628120000_add_object_size_and_stats.sql (51.4ms)15112026/10/01 10:24:45 INFO Starting HTTP server address=/nix/var/nix/builds/nix-41045-2866623493/TestProxyHeadersOnlyTrustedOnSocket3918544407/001/proxy.sock15122026/10/01 10:24:45 INFO Starting HTTP server address=127.0.0.1:6151815132026/10/01 10:24:45 WARN mTLS auth: subject not in bound subjects subject="CN=someone"15142026/10/01 10:24:45 INFO Shutdown signal received, draining in-flight requests timeout=10s1515--- PASS: TestProxyHeadersOnlyTrustedOnSocket (2.19s)1516=== CONT TestClientWithDependencies15172026/10/01 10:24:45 OK 20260905000000_add_claims.sql (91.75ms)15182026/10/01 10:24:45 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772161519--- PASS: TestReadProxyNarinfo (2.34s)1520=== CONT TestPushDedupSurvivesConcurrentGC15212026/10/01 10:24:45 OK 20260920000000_drop_claims.sql (51.9ms)15222026/10/01 10:24:45 OK 20260923120000_add_pushes.sql (11.88ms)15232026/10/01 10:24:45 goose: successfully migrated database to version: 2026092312000015242026/10/01 10:24:45 OK 1_commit_pending_closure.sql (1.35ms)15252026/10/01 10:24:45 OK 2_object_stats_trigger.sql (297.21µs)15262026/10/01 10:24:45 OK 3_commit_push.sql (249.63µs)15272026/10/01 10:24:45 goose: up to current file version: 315282026-10-01 10:24:45.900 UTC [41799] ERROR: relation "goose_db_version" does not exist at character 3615292026-10-01 10:24:45.900 UTC [41799] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15302026-10-01 10:24:46.089 UTC [41801] ERROR: relation "goose_db_version" does not exist at character 3615312026-10-01 10:24:46.089 UTC [41801] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15322026/10/01 10:24:46 OK 20241026095416_initial_model.sql (168.44ms)15332026/10/01 10:24:46 OK 20251210153512_drop_unused_gin_index.sql (9.48ms)15342026/10/01 10:24:46 OK 20251218171726_add_pins.sql (33.12ms)15352026/10/01 10:24:46 OK 20260628120000_add_object_size_and_stats.sql (22.96ms)15362026-10-01 10:24:46.223 UTC [41804] ERROR: relation "goose_db_version" does not exist at character 3615372026-10-01 10:24:46.223 UTC [41804] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15382026/10/01 10:24:46 OK 20241026095416_initial_model.sql (73.06ms)15392026/10/01 10:24:46 OK 20251210153512_drop_unused_gin_index.sql (10.2ms)15402026/10/01 10:24:46 OK 20260905000000_add_claims.sql (28.1ms)15412026/10/01 10:24:46 OK 20260920000000_drop_claims.sql (18.97ms)15422026/10/01 10:24:46 OK 20251218171726_add_pins.sql (19.34ms)15432026/10/01 10:24:46 OK 20260923120000_add_pushes.sql (1.76ms)15442026/10/01 10:24:46 goose: successfully migrated database to version: 2026092312000015452026/10/01 10:24:46 OK 1_commit_pending_closure.sql (2.07ms)15462026/10/01 10:24:46 OK 2_object_stats_trigger.sql (890.08µs)15472026/10/01 10:24:46 OK 20260628120000_add_object_size_and_stats.sql (4.84ms)15482026/10/01 10:24:46 OK 3_commit_push.sql (431.96µs)15492026/10/01 10:24:46 goose: up to current file version: 315502026/10/01 10:24:46 OK 20260905000000_add_claims.sql (2.22ms)15512026/10/01 10:24:46 OK 20260920000000_drop_claims.sql (1.32ms)15522026/10/01 10:24:46 OK 20260923120000_add_pushes.sql (674µs)15532026/10/01 10:24:46 goose: successfully migrated database to version: 2026092312000015542026/10/01 10:24:46 OK 1_commit_pending_closure.sql (981.88µs)15552026/10/01 10:24:46 OK 2_object_stats_trigger.sql (240.83µs)15562026/10/01 10:24:46 OK 3_commit_push.sql (150.67µs)15572026/10/01 10:24:46 goose: up to current file version: 315582026/10/01 10:24:46 OK 20241026095416_initial_model.sql (83.63ms)15592026/10/01 10:24:46 OK 20251210153512_drop_unused_gin_index.sql (16.01ms)15602026/10/01 10:24:46 OK 20251218171726_add_pins.sql (42.31ms)15612026/10/01 10:24:46 OK 20260628120000_add_object_size_and_stats.sql (34.76ms)15622026-10-01 10:24:46.434 UTC [41811] ERROR: relation "goose_db_version" does not exist at character 3615632026-10-01 10:24:46.434 UTC [41811] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15642026/10/01 10:24:46 OK 20260905000000_add_claims.sql (49.12ms)15652026/10/01 10:24:46 OK 20260920000000_drop_claims.sql (46.09ms)1566--- PASS: TestPresentReportsOnlyClosureRoots (2.65s)1567=== CONT TestGCMetrics15682026/10/01 10:24:46 OK 20260923120000_add_pushes.sql (19.19ms)15692026/10/01 10:24:46 goose: successfully migrated database to version: 2026092312000015702026/10/01 10:24:46 OK 1_commit_pending_closure.sql (850.63µs)15712026/10/01 10:24:46 OK 2_object_stats_trigger.sql (184.29µs)15722026/10/01 10:24:46 OK 3_commit_push.sql (134.17µs)15732026/10/01 10:24:46 goose: up to current file version: 31574--- PASS: TestPresentNotReportedWhileGCDeletesClosure (2.87s)1575=== CONT TestGCBugBareHashReferences15762026/10/01 10:24:46 OK 20241026095416_initial_model.sql (215.32ms)15772026/10/01 10:24:46 OK 20251210153512_drop_unused_gin_index.sql (12.48ms)15782026/10/01 10:24:46 OK 20251218171726_add_pins.sql (20.82ms)15792026/10/01 10:24:46 INFO Received uploads request method=POST path=/api/pending_closures15802026/10/01 10:24:46 OK 20260628120000_add_object_size_and_stats.sql (51.41ms)15812026/10/01 10:24:46 OK 20260905000000_add_claims.sql (66.53ms)15822026/10/01 10:24:46 OK 20260920000000_drop_claims.sql (46.53ms)15832026/10/01 10:24:46 OK 20260923120000_add_pushes.sql (13.43ms)15842026/10/01 10:24:46 goose: successfully migrated database to version: 2026092312000015852026/10/01 10:24:46 OK 1_commit_pending_closure.sql (995.46µs)15862026/10/01 10:24:46 OK 2_object_stats_trigger.sql (223.42µs)15872026/10/01 10:24:46 OK 3_commit_push.sql (176.63µs)15882026/10/01 10:24:46 goose: up to current file version: 315892026-10-01 10:24:46.947 UTC [41817] ERROR: relation "goose_db_version" does not exist at character 3615902026-10-01 10:24:46.947 UTC [41817] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15912026/10/01 10:24:46 INFO Received cleanup request method=DELETE path=/api/pending_closures15922026/10/01 10:24:46 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket38/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""15932026/10/01 10:24:46 INFO Aborted multipart uploads count=0 kept=115942026/10/01 10:24:46 INFO Received cleanup request method=DELETE path=/api/pending_closures15952026/10/01 10:24:46 INFO Aborted multipart uploads count=1 kept=01596--- PASS: TestMultipartCleanup (2.93s)1597=== CONT TestLeadEndsOnShutdown15982026/10/01 10:24:47 OK 20241026095416_initial_model.sql (223.57ms)15992026/10/01 10:24:47 OK 20251210153512_drop_unused_gin_index.sql (19.73ms)16002026/10/01 10:24:47 OK 20251218171726_add_pins.sql (38.87ms)16012026/10/01 10:24:47 OK 20260628120000_add_object_size_and_stats.sql (62.4ms)16022026-10-01 10:24:47.386 UTC [41834] ERROR: relation "goose_db_version" does not exist at character 3616032026-10-01 10:24:47.386 UTC [41834] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16042026/10/01 10:24:47 OK 20260905000000_add_claims.sql (70.88ms)16052026/10/01 10:24:47 OK 20260920000000_drop_claims.sql (80.99ms)16062026/10/01 10:24:47 OK 20260923120000_add_pushes.sql (41.3ms)16072026/10/01 10:24:47 goose: successfully migrated database to version: 2026092312000016082026/10/01 10:24:47 OK 1_commit_pending_closure.sql (5.48ms)16092026/10/01 10:24:47 OK 2_object_stats_trigger.sql (1.35ms)16102026/10/01 10:24:47 OK 3_commit_push.sql (1.78ms)16112026/10/01 10:24:47 goose: up to current file version: 316122026/10/01 10:24:47 OK 20241026095416_initial_model.sql (359.91ms)16132026/10/01 10:24:47 OK 20251210153512_drop_unused_gin_index.sql (11.1ms)16142026/10/01 10:24:47 OK 20251218171726_add_pins.sql (59.24ms)16152026/10/01 10:24:47 OK 20260628120000_add_object_size_and_stats.sql (57.45ms)1616--- PASS: TestObjectStatsTrigger (3.34s)1617=== CONT TestLeadElectsOneAndHandsOver1618{"timestamp":"2026-10-01T10:24:48.092634Z","level":"ERROR","message":"Scanner cycle completed without a durable data usage snapshot","event":"scanner_persist_state","component":"scanner","subsystem":"runtime","cycle":4,"outcome":"NoUpdate","state":"usage_not_durable","target":"rustfs::scanner","filename":"crates/scanner/src/scanner.rs","line_number":2350,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}16192026/10/01 10:24:48 OK 20260905000000_add_claims.sql (112.1ms)16202026/10/01 10:24:48 OK 20260920000000_drop_claims.sql (78.22ms)16212026/10/01 10:24:48 OK 20260923120000_add_pushes.sql (27.65ms)16222026/10/01 10:24:48 goose: successfully migrated database to version: 2026092312000016232026/10/01 10:24:48 OK 1_commit_pending_closure.sql (1.52ms)16242026/10/01 10:24:48 OK 2_object_stats_trigger.sql (346.88µs)16252026/10/01 10:24:48 OK 3_commit_push.sql (296.79µs)16262026/10/01 10:24:48 goose: up to current file version: 316272026-10-01 10:24:48.206 UTC [41858] ERROR: relation "goose_db_version" does not exist at character 3616282026-10-01 10:24:48.206 UTC [41858] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1629=== NAME TestOrphanedObjectsGC1630 orphaned_objects_gc_test.go:290: GC Test Summary:1631 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1632 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1633 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1634 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1635 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1636--- PASS: TestOrphanedObjectsGC (4.03s)1637=== CONT TestResolveDBConnectionString1638=== RUN TestResolveDBConnectionString/flag_wins1639=== PAUSE TestResolveDBConnectionString/flag_wins1640=== RUN TestResolveDBConnectionString/file_when_flag_empty1641=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1642=== RUN TestResolveDBConnectionString/missing_file_is_an_error1643=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1644=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1645=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1646=== RUN TestResolveDBConnectionString/nothing_configured1647=== PAUSE TestResolveDBConnectionString/nothing_configured1648=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock16492026/10/01 10:24:48 OK 20241026095416_initial_model.sql (311.26ms)16502026/10/01 10:24:48 OK 20251210153512_drop_unused_gin_index.sql (16.95ms)16512026/10/01 10:24:48 INFO Received uploads request method=POST path=/api/pending_closures16522026-10-01 10:24:48.660 UTC [41863] ERROR: relation "goose_db_version" does not exist at character 3616532026-10-01 10:24:48.660 UTC [41863] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16542026-10-01 10:24:48.668 UTC [41866] ERROR: relation "goose_db_version" does not exist at character 3616552026-10-01 10:24:48.668 UTC [41866] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16562026/10/01 10:24:48 OK 20251218171726_add_pins.sql (52.19ms)16572026/10/01 10:24:48 OK 20260628120000_add_object_size_and_stats.sql (53.53ms)16582026/10/01 10:24:48 INFO Received uploads request method=POST path=/api/pending_closures16592026/10/01 10:24:48 OK 20260905000000_add_claims.sql (33.46ms)16602026/10/01 10:24:48 OK 20260920000000_drop_claims.sql (39.67ms)16612026/10/01 10:24:48 INFO Received cleanup request method=DELETE path=/api/pending_closures16622026/10/01 10:24:48 OK 20260923120000_add_pushes.sql (15.67ms)16632026/10/01 10:24:48 goose: successfully migrated database to version: 2026092312000016642026/10/01 10:24:48 OK 1_commit_pending_closure.sql (3.83ms)16652026/10/01 10:24:48 OK 2_object_stats_trigger.sql (941.5µs)16662026/10/01 10:24:48 OK 3_commit_push.sql (679.17µs)16672026/10/01 10:24:48 goose: up to current file version: 316682026/10/01 10:24:48 OK 20241026095416_initial_model.sql (122.89ms)16692026/10/01 10:24:48 OK 20251210153512_drop_unused_gin_index.sql (22.76ms)16702026/10/01 10:24:48 OK 20241026095416_initial_model.sql (177.63ms)16712026/10/01 10:24:48 OK 20251218171726_add_pins.sql (48.87ms)16722026/10/01 10:24:48 OK 20251210153512_drop_unused_gin_index.sql (23.06ms)16732026/10/01 10:24:48 OK 20260628120000_add_object_size_and_stats.sql (45.15ms)16742026/10/01 10:24:48 OK 20251218171726_add_pins.sql (58.2ms)16752026/10/01 10:24:49 OK 20260628120000_add_object_size_and_stats.sql (55.37ms)16762026/10/01 10:24:49 OK 20260905000000_add_claims.sql (88.07ms)16772026/10/01 10:24:49 OK 20260920000000_drop_claims.sql (46.15ms)16782026/10/01 10:24:49 OK 20260905000000_add_claims.sql (64.32ms)16792026/10/01 10:24:49 OK 20260923120000_add_pushes.sql (7.67ms)16802026/10/01 10:24:49 goose: successfully migrated database to version: 2026092312000016812026/10/01 10:24:49 OK 1_commit_pending_closure.sql (2.75ms)16822026/10/01 10:24:49 OK 2_object_stats_trigger.sql (571.17µs)16832026/10/01 10:24:49 OK 3_commit_push.sql (407.71µs)16842026/10/01 10:24:49 goose: up to current file version: 316852026/10/01 10:24:49 OK 20260920000000_drop_claims.sql (69.91ms)16862026/10/01 10:24:49 OK 20260923120000_add_pushes.sql (27.67ms)16872026/10/01 10:24:49 goose: successfully migrated database to version: 2026092312000016882026/10/01 10:24:49 OK 1_commit_pending_closure.sql (5.14ms)16892026/10/01 10:24:49 OK 2_object_stats_trigger.sql (947.08µs)16902026/10/01 10:24:49 OK 3_commit_push.sql (585.5µs)16912026/10/01 10:24:49 goose: up to current file version: 316922026/10/01 10:24:49 INFO Received uploads request method=POST path=/api/pending_closures1693--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (3.97s)1694=== CONT TestClientFallsBackToClosures16952026-10-01 10:24:49.643 UTC [41879] ERROR: relation "goose_db_version" does not exist at character 3616962026-10-01 10:24:49.643 UTC [41879] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16972026-10-01 10:24:49.649 UTC [41881] ERROR: relation "goose_db_version" does not exist at character 3616982026-10-01 10:24:49.649 UTC [41881] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16992026/10/01 10:24:49 INFO Received uploads request method=POST path=/api/pending_closures17002026/10/01 10:24:49 INFO Aborted multipart uploads count=0 kept=017012026/10/01 10:24:49 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=017022026/10/01 10:24:49 INFO Vacuumed table table=pending_closures17032026/10/01 10:24:49 INFO Vacuumed table table=pending_objects17042026/10/01 10:24:49 INFO Vacuumed table table=multipart_uploads17052026/10/01 10:24:49 OK 20241026095416_initial_model.sql (237.23ms)17062026/10/01 10:24:49 INFO Vacuumed table table=closures17072026/10/01 10:24:49 OK 20251210153512_drop_unused_gin_index.sql (23.16ms)17082026/10/01 10:24:49 OK 20241026095416_initial_model.sql (263.94ms)17092026/10/01 10:24:49 OK 20251210153512_drop_unused_gin_index.sql (8.09ms)17102026/10/01 10:24:49 INFO Vacuumed table table=objects17112026/10/01 10:24:49 INFO Aborted multipart uploads count=0 kept=017122026/10/01 10:24:49 WARN Force mode enabled - objects will be deleted immediately without grace period17132026/10/01 10:24:49 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=017142026/10/01 10:24:50 OK 20251218171726_add_pins.sql (43.06ms)17152026/10/01 10:24:50 INFO Vacuumed table table=pending_closures17162026/10/01 10:24:50 OK 20251218171726_add_pins.sql (30ms)17172026/10/01 10:24:50 INFO Vacuumed table table=pending_objects17182026/10/01 10:24:50 INFO Vacuumed table table=multipart_uploads17192026/10/01 10:24:50 OK 20260628120000_add_object_size_and_stats.sql (21.02ms)17202026/10/01 10:24:50 INFO Vacuumed table table=closures17212026/10/01 10:24:50 INFO Vacuumed table table=objects1722--- PASS: TestPushDedupSurvivesConcurrentGC (4.31s)1723=== CONT TestClientPushesUseOnePush17242026/10/01 10:24:50 OK 20260628120000_add_object_size_and_stats.sql (31.47ms)17252026-10-01 10:24:50.051 UTC [41895] ERROR: relation "goose_db_version" does not exist at character 3617262026-10-01 10:24:50.051 UTC [41895] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17272026/10/01 10:24:50 OK 20260905000000_add_claims.sql (29.1ms)17282026/10/01 10:24:50 OK 20260920000000_drop_claims.sql (28.3ms)17292026/10/01 10:24:50 OK 20260905000000_add_claims.sql (45.32ms)17302026/10/01 10:24:50 OK 20260923120000_add_pushes.sql (32.75ms)17312026/10/01 10:24:50 goose: successfully migrated database to version: 2026092312000017322026/10/01 10:24:50 OK 20260920000000_drop_claims.sql (33.51ms)17332026/10/01 10:24:50 OK 1_commit_pending_closure.sql (1.69ms)17342026/10/01 10:24:50 OK 2_object_stats_trigger.sql (271.08µs)17352026/10/01 10:24:50 OK 3_commit_push.sql (203.29µs)17362026/10/01 10:24:50 goose: up to current file version: 317372026/10/01 10:24:50 OK 20260923120000_add_pushes.sql (15.89ms)17382026/10/01 10:24:50 goose: successfully migrated database to version: 2026092312000017392026/10/01 10:24:50 OK 1_commit_pending_closure.sql (1.04ms)17402026/10/01 10:24:50 OK 2_object_stats_trigger.sql (268.67µs)17412026/10/01 10:24:50 OK 3_commit_push.sql (195.79µs)17422026/10/01 10:24:50 goose: up to current file version: 317432026/10/01 10:24:50 OK 20241026095416_initial_model.sql (223.36ms)17442026/10/01 10:24:50 OK 20251210153512_drop_unused_gin_index.sql (7.58ms)17452026/10/01 10:24:50 OK 20251218171726_add_pins.sql (42.75ms)17462026/10/01 10:24:50 OK 20260628120000_add_object_size_and_stats.sql (18.65ms)17472026/10/01 10:24:50 INFO Aborted multipart uploads count=0 kept=017482026/10/01 10:24:50 WARN Force mode enabled - objects will be deleted immediately without grace period17492026/10/01 10:24:50 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=017502026/10/01 10:24:50 INFO Vacuumed table table=pending_closures17512026/10/01 10:24:50 INFO Vacuumed table table=pending_objects17522026/10/01 10:24:50 INFO Vacuumed table table=multipart_uploads17532026/10/01 10:24:50 INFO Vacuumed table table=closures17542026/10/01 10:24:50 INFO Vacuumed table table=objects1755--- PASS: TestGCMetrics (3.92s)1756=== CONT TestPinProtectsFromGC17572026/10/01 10:24:50 OK 20260905000000_add_claims.sql (76.31ms)17582026/10/01 10:24:50 OK 20260920000000_drop_claims.sql (78.57ms)1759=== NAME TestClientWithDependencies1760 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-41045-2866623493/TestClientWithDependencies379750268/001/store/9nnbsig2a93xpxixqdmpbf7ip03ni6yx-test-script17612026/10/01 10:24:50 OK 20260923120000_add_pushes.sql (26.19ms)17622026/10/01 10:24:50 goose: successfully migrated database to version: 2026092312000017632026/10/01 10:24:50 OK 1_commit_pending_closure.sql (1.79ms)17642026/10/01 10:24:50 OK 2_object_stats_trigger.sql (312.21µs)17652026/10/01 10:24:50 OK 3_commit_push.sql (237.08µs)17662026/10/01 10:24:50 goose: up to current file version: 31767 client_integration_test.go:615: Found 1 dependencies (including self)17682026/10/01 10:24:50 INFO Received push request method=POST path=/api/pushes17692026/10/01 10:24:50 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17702026/10/01 10:24:50 INFO Uploading 9nnbsig2a93xpxixqdmpbf7ip03ni6yx-test-script (136B)17712026/10/01 10:24:50 WARN Failed to register uploaded object key=9nnbsig2a93xpxixqdmpbf7ip03ni6yx.ls error="server returned 404: 404 page not found\n"17722026/10/01 10:24:50 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"17732026/10/01 10:24:50 WARN Failed to register uploaded object key=log/8p7q3x0219mn1scs25cxbjxvwswfp1sn-test-script.drv error="server returned 404: 404 page not found\n"17742026/10/01 10:24:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17752026/10/01 10:24:50 INFO Signed narinfos id=1 count=117762026/10/01 10:24:50 INFO Uploading 1 narinfos17772026/10/01 10:24:50 INFO Received complete push request method=POST path=/api/pushes/1/complete17782026/10/01 10:24:50 WARN Failed to register uploaded object key=9nnbsig2a93xpxixqdmpbf7ip03ni6yx.narinfo error="server returned 404: 404 page not found\n"17792026/10/01 10:24:50 INFO Upload complete. (233ms)1780 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-41045-2866623493/TestClientWithDependencies379750268/001/store) requires matching store prefix1781--- PASS: TestClientWithDependencies (5.37s)1782=== CONT TestClientSharedPathCommittedMidPush17832026-10-01 10:24:51.050 UTC [41924] ERROR: relation "goose_db_version" does not exist at character 3617842026-10-01 10:24:51.050 UTC [41924] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1785--- PASS: TestGCBugBareHashReferences (4.48s)1786=== CONT TestCacheConfigHandler1787=== RUN TestCacheConfigHandler/full_config,_no_issuer1788=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1789=== RUN TestCacheConfigHandler/no_cache_url_configured1790=== PAUSE TestCacheConfigHandler/no_cache_url_configured1791=== RUN TestCacheConfigHandler/no_signing_keys1792=== PAUSE TestCacheConfigHandler/no_signing_keys1793=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1794=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1795=== CONT TestClientMultipleUploads17962026/10/01 10:24:51 INFO lead: acquired remote=192.0.2.1:123417972026/10/01 10:24:51 INFO lead: released remote=192.0.2.1:12341798--- PASS: TestLeadEndsOnShutdown (4.14s)1799=== CONT TestClientIntegration18002026-10-01 10:24:51.204 UTC [41938] ERROR: relation "goose_db_version" does not exist at character 3618012026-10-01 10:24:51.204 UTC [41938] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18022026/10/01 10:24:51 OK 20241026095416_initial_model.sql (177.91ms)18032026/10/01 10:24:51 OK 20251210153512_drop_unused_gin_index.sql (6.43ms)18042026/10/01 10:24:51 OK 20251218171726_add_pins.sql (40.48ms)18052026/10/01 10:24:51 OK 20260628120000_add_object_size_and_stats.sql (29.57ms)18062026/10/01 10:24:51 OK 20260905000000_add_claims.sql (80.55ms)18072026/10/01 10:24:51 OK 20241026095416_initial_model.sql (229.39ms)18082026/10/01 10:24:51 OK 20251210153512_drop_unused_gin_index.sql (20.41ms)18092026/10/01 10:24:51 OK 20260920000000_drop_claims.sql (64.76ms)18102026/10/01 10:24:51 OK 20260923120000_add_pushes.sql (21.92ms)18112026/10/01 10:24:51 goose: successfully migrated database to version: 2026092312000018122026/10/01 10:24:51 OK 1_commit_pending_closure.sql (1.02ms)18132026/10/01 10:24:51 OK 2_object_stats_trigger.sql (248.96µs)18142026/10/01 10:24:51 OK 3_commit_push.sql (207.42µs)18152026/10/01 10:24:51 goose: up to current file version: 318162026/10/01 10:24:51 OK 20251218171726_add_pins.sql (40.98ms)18172026/10/01 10:24:51 OK 20260628120000_add_object_size_and_stats.sql (76.87ms)18182026/10/01 10:24:51 OK 20260905000000_add_claims.sql (94.07ms)18192026/10/01 10:24:51 OK 20260920000000_drop_claims.sql (69.3ms)18202026/10/01 10:24:51 OK 20260923120000_add_pushes.sql (20.43ms)18212026/10/01 10:24:51 goose: successfully migrated database to version: 2026092312000018222026/10/01 10:24:51 OK 1_commit_pending_closure.sql (1.13ms)18232026/10/01 10:24:51 OK 2_object_stats_trigger.sql (237.29µs)18242026/10/01 10:24:51 OK 3_commit_push.sql (194.58µs)18252026/10/01 10:24:51 goose: up to current file version: 318262026/10/01 10:24:51 INFO lead: acquired remote=192.0.2.1:123418272026/10/01 10:24:52 INFO lead: released remote=192.0.2.1:123418282026/10/01 10:24:52 INFO lead: acquired remote=192.0.2.1:123418292026/10/01 10:24:52 INFO lead: released remote=192.0.2.1:12341830--- PASS: TestLeadElectsOneAndHandsOver (4.03s)1831=== CONT TestClientErrorHandling1832=== RUN TestClientErrorHandling/InvalidStorePath1833=== PAUSE TestClientErrorHandling/InvalidStorePath1834=== RUN TestClientErrorHandling/InvalidAuthToken1835=== PAUSE TestClientErrorHandling/InvalidAuthToken1836=== RUN TestClientErrorHandling/ServerNotAvailable1837=== PAUSE TestClientErrorHandling/ServerNotAvailable1838=== CONT TestClientCADerivations18392026-10-01 10:24:52.150 UTC [41941] ERROR: relation "goose_db_version" does not exist at character 3618402026-10-01 10:24:52.150 UTC [41941] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18412026/10/01 10:24:52 OK 20241026095416_initial_model.sql (160.99ms)18422026/10/01 10:24:52 OK 20251210153512_drop_unused_gin_index.sql (9.13ms)18432026/10/01 10:24:52 OK 20251218171726_add_pins.sql (16.59ms)18442026/10/01 10:24:52 OK 20260628120000_add_object_size_and_stats.sql (29.44ms)18452026/10/01 10:24:52 OK 20260905000000_add_claims.sql (49.73ms)18462026/10/01 10:24:52 OK 20260920000000_drop_claims.sql (14.09ms)18472026-10-01 10:24:52.490 UTC [41947] ERROR: relation "goose_db_version" does not exist at character 3618482026-10-01 10:24:52.490 UTC [41947] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18492026/10/01 10:24:52 OK 20260923120000_add_pushes.sql (23.69ms)18502026/10/01 10:24:52 goose: successfully migrated database to version: 2026092312000018512026/10/01 10:24:52 OK 1_commit_pending_closure.sql (939.17µs)18522026/10/01 10:24:52 OK 2_object_stats_trigger.sql (241.42µs)18532026/10/01 10:24:52 OK 3_commit_push.sql (183.04µs)18542026/10/01 10:24:52 goose: up to current file version: 318552026/10/01 10:24:52 OK 20241026095416_initial_model.sql (173.21ms)18562026/10/01 10:24:52 OK 20251210153512_drop_unused_gin_index.sql (13.47ms)18572026/10/01 10:24:52 OK 20251218171726_add_pins.sql (19.07ms)18582026-10-01 10:24:52.795 UTC [41950] ERROR: relation "goose_db_version" does not exist at character 3618592026-10-01 10:24:52.795 UTC [41950] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18602026/10/01 10:24:52 OK 20260628120000_add_object_size_and_stats.sql (20.74ms)18612026/10/01 10:24:52 OK 20260905000000_add_claims.sql (29.37ms)18622026/10/01 10:24:52 OK 20260920000000_drop_claims.sql (5.91ms)18632026/10/01 10:24:52 OK 20260923120000_add_pushes.sql (8.89ms)18642026/10/01 10:24:52 goose: successfully migrated database to version: 2026092312000018652026/10/01 10:24:52 OK 1_commit_pending_closure.sql (959.04µs)18662026/10/01 10:24:52 OK 2_object_stats_trigger.sql (204.54µs)18672026/10/01 10:24:52 OK 3_commit_push.sql (171.17µs)18682026/10/01 10:24:52 goose: up to current file version: 318692026/10/01 10:24:53 OK 20241026095416_initial_model.sql (198.09ms)18702026/10/01 10:24:53 OK 20251210153512_drop_unused_gin_index.sql (6.91ms)18712026/10/01 10:24:53 OK 20251218171726_add_pins.sql (28.58ms)18722026/10/01 10:24:53 OK 20260628120000_add_object_size_and_stats.sql (33.06ms)18732026/10/01 10:24:53 OK 20260905000000_add_claims.sql (35ms)18742026-10-01 10:24:53.130 UTC [41958] ERROR: relation "goose_db_version" does not exist at character 3618752026-10-01 10:24:53.130 UTC [41958] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18762026/10/01 10:24:53 OK 20260920000000_drop_claims.sql (10.36ms)18772026/10/01 10:24:53 OK 20260923120000_add_pushes.sql (8.04ms)18782026/10/01 10:24:53 goose: successfully migrated database to version: 2026092312000018792026/10/01 10:24:53 OK 1_commit_pending_closure.sql (6.2ms)18802026/10/01 10:24:53 OK 2_object_stats_trigger.sql (505.83µs)18812026/10/01 10:24:53 OK 3_commit_push.sql (229.5µs)18822026/10/01 10:24:53 goose: up to current file version: 318832026-10-01 10:24:53.199 UTC [41961] ERROR: relation "goose_db_version" does not exist at character 3618842026-10-01 10:24:53.199 UTC [41961] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18852026-10-01 10:24:53.209 UTC [41962] ERROR: relation "goose_db_version" does not exist at character 3618862026-10-01 10:24:53.209 UTC [41962] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18872026/10/01 10:24:53 OK 20241026095416_initial_model.sql (106.06ms)18882026/10/01 10:24:53 OK 20251210153512_drop_unused_gin_index.sql (53.06ms)18892026/10/01 10:24:53 INFO Received uploads request method=POST path=/api/pending_closures1890--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (4.75s)1891=== CONT TestCacheStatsHandler18922026/10/01 10:24:53 OK 20251218171726_add_pins.sql (26.57ms)18932026/10/01 10:24:53 INFO Received uploads request method=POST path=/api/pending_closures18942026/10/01 10:24:53 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)18952026/10/01 10:24:53 INFO Uploading ibvjkwf6595jmbhg751dd182caj2fgzf-b (248B)18962026/10/01 10:24:53 INFO Uploading fzb89r8lwl03j942gbjznr93z8jw1rqs-shared-dep (136B)18972026/10/01 10:24:53 WARN Failed to register uploaded object key=r4dimld0ga6izj9qa39h3czbi8blrqys.ls error="server returned 404: 404 page not found\n"18982026/10/01 10:24:53 OK 20241026095416_initial_model.sql (138.66ms)18992026/10/01 10:24:53 WARN Failed to register uploaded object key=ibvjkwf6595jmbhg751dd182caj2fgzf.ls error="server returned 404: 404 page not found\n"19002026/10/01 10:24:53 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19012026/10/01 10:24:53 WARN Failed to register uploaded object key=nar/0n94c38rk8dfgzwjkrvgqincad1xixmw4z62l73p5b01vxya5jxj.nar.zst error="server returned 404: 404 page not found\n"19022026/10/01 10:24:53 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19032026/10/01 10:24:53 WARN Failed to register uploaded object key=fzb89r8lwl03j942gbjznr93z8jw1rqs.ls error="server returned 404: 404 page not found\n"19042026/10/01 10:24:53 INFO Signed narinfos id=1 count=219052026/10/01 10:24:53 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign19062026/10/01 10:24:53 INFO Signed narinfos id=2 count=219072026/10/01 10:24:53 INFO Uploading 4 narinfos19082026/10/01 10:24:53 OK 20251210153512_drop_unused_gin_index.sql (11.95ms)19092026/10/01 10:24:53 OK 20260628120000_add_object_size_and_stats.sql (44.39ms)19102026/10/01 10:24:53 WARN Failed to register uploaded object key=r4dimld0ga6izj9qa39h3czbi8blrqys.narinfo error="server returned 404: 404 page not found\n"19112026/10/01 10:24:53 WARN Failed to register uploaded object key=ibvjkwf6595jmbhg751dd182caj2fgzf.narinfo error="server returned 404: 404 page not found\n"19122026/10/01 10:24:53 WARN Failed to register uploaded object key=fzb89r8lwl03j942gbjznr93z8jw1rqs.narinfo error="server returned 404: 404 page not found\n"19132026/10/01 10:24:53 OK 20251218171726_add_pins.sql (19.49ms)19142026/10/01 10:24:53 OK 20241026095416_initial_model.sql (149.99ms)19152026/10/01 10:24:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19162026/10/01 10:24:53 WARN Failed to register uploaded object key=fzb89r8lwl03j942gbjznr93z8jw1rqs.narinfo error="server returned 404: 404 page not found\n"19172026/10/01 10:24:53 OK 20260905000000_add_claims.sql (39.09ms)19182026/10/01 10:24:53 OK 20251210153512_drop_unused_gin_index.sql (15.14ms)19192026/10/01 10:24:53 INFO Completed upload id=119202026/10/01 10:24:53 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete19212026/10/01 10:24:53 INFO Completed upload id=219222026/10/01 10:24:53 INFO Upload complete. (190ms)1923=== NAME TestClientFallsBackToClosures1924 client_pushes_test.go:112: Retrieved narinfo from S3:1925 StorePath: /nix/var/nix/builds/nix-41045-2866623493/TestClientFallsBackToClosures4044740779/001/store/fzb89r8lwl03j942gbjznr93z8jw1rqs-shared-dep1926 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1927 Compression: zstd1928 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821929 NarSize: 1361930 References: 1931 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1932 client_pushes_test.go:112: Retrieved narinfo from S3:1933 StorePath: /nix/var/nix/builds/nix-41045-2866623493/TestClientFallsBackToClosures4044740779/001/store/r4dimld0ga6izj9qa39h3czbi8blrqys-a1934 URL: nar/0n94c38rk8dfgzwjkrvgqincad1xixmw4z62l73p5b01vxya5jxj.nar.zst1935 Compression: zstd1936 NarHash: sha256:0n94c38rk8dfgzwjkrvgqincad1xixmw4z62l73p5b01vxya5jxj1937 NarSize: 2481938 References: /nix/var/nix/builds/nix-41045-2866623493/TestClientFallsBackToClosures4044740779/001/store/fzb89r8lwl03j942gbjznr93z8jw1rqs-shared-dep1939 CA: text:sha256:1ch0cmrnh21mbglxg5cm7dshbssf0disbf9923640baffd488psj1940 client_pushes_test.go:112: Retrieved narinfo from S3:1941 StorePath: /nix/var/nix/builds/nix-41045-2866623493/TestClientFallsBackToClosures4044740779/001/store/ibvjkwf6595jmbhg751dd182caj2fgzf-b1942 URL: nar/0n94c38rk8dfgzwjkrvgqincad1xixmw4z62l73p5b01vxya5jxj.nar.zst1943 Compression: zstd1944 NarHash: sha256:0n94c38rk8dfgzwjkrvgqincad1xixmw4z62l73p5b01vxya5jxj1945 NarSize: 2481946 References: /nix/var/nix/builds/nix-41045-2866623493/TestClientFallsBackToClosures4044740779/001/store/fzb89r8lwl03j942gbjznr93z8jw1rqs-shared-dep1947 CA: text:sha256:1ch0cmrnh21mbglxg5cm7dshbssf0disbf9923640baffd488psj19482026/10/01 10:24:53 OK 20260628120000_add_object_size_and_stats.sql (37.46ms)19492026/10/01 10:24:53 OK 20260920000000_drop_claims.sql (18.61ms)19502026/10/01 10:24:53 OK 20251218171726_add_pins.sql (19.49ms)19512026/10/01 10:24:53 OK 20260923120000_add_pushes.sql (2.2ms)19522026/10/01 10:24:53 goose: successfully migrated database to version: 2026092312000019532026/10/01 10:24:53 OK 1_commit_pending_closure.sql (986.04µs)19542026/10/01 10:24:53 OK 2_object_stats_trigger.sql (230.25µs)19552026/10/01 10:24:53 OK 3_commit_push.sql (152.04µs)19562026/10/01 10:24:53 goose: up to current file version: 31957--- PASS: TestClientFallsBackToClosures (4.09s)1958=== CONT TestPush_OverlappingRootsStoreOneRowPerKey19592026/10/01 10:24:53 OK 20260905000000_add_claims.sql (18.11ms)19602026/10/01 10:24:53 OK 20260628120000_add_object_size_and_stats.sql (37.66ms)19612026/10/01 10:24:53 OK 20260920000000_drop_claims.sql (36.51ms)19622026/10/01 10:24:53 OK 20260923120000_add_pushes.sql (12.98ms)19632026/10/01 10:24:53 goose: successfully migrated database to version: 2026092312000019642026/10/01 10:24:53 OK 1_commit_pending_closure.sql (1.02ms)19652026/10/01 10:24:53 OK 2_object_stats_trigger.sql (262.5µs)19662026/10/01 10:24:53 OK 3_commit_push.sql (572.08µs)19672026/10/01 10:24:53 goose: up to current file version: 319682026/10/01 10:24:53 OK 20260905000000_add_claims.sql (32.18ms)19692026/10/01 10:24:53 OK 20260920000000_drop_claims.sql (35.7ms)19702026/10/01 10:24:53 OK 20260923120000_add_pushes.sql (7.74ms)19712026/10/01 10:24:53 goose: successfully migrated database to version: 2026092312000019722026/10/01 10:24:53 OK 1_commit_pending_closure.sql (1.02ms)19732026/10/01 10:24:53 OK 2_object_stats_trigger.sql (276.46µs)19742026/10/01 10:24:53 OK 3_commit_push.sql (240.63µs)19752026/10/01 10:24:53 goose: up to current file version: 319762026/10/01 10:24:53 INFO Received push request method=POST path=/api/pushes19772026/10/01 10:24:53 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)19782026/10/01 10:24:53 INFO Uploading 0nvqkasa19ils92nln8q55j8vfdgvhc8-shared-dep (136B)19792026/10/01 10:24:53 INFO Uploading kd86slb7bvn2r58zjlnpws5x1y8znzk5-b (248B)19802026/10/01 10:24:53 WARN Failed to register uploaded object key=2zf8riqwffl9bl6g24q4rfqprwhljyfv.ls error="server returned 404: 404 page not found\n"19812026/10/01 10:24:53 WARN Failed to register uploaded object key=kd86slb7bvn2r58zjlnpws5x1y8znzk5.ls error="server returned 404: 404 page not found\n"19822026/10/01 10:24:53 WARN Failed to register uploaded object key=0nvqkasa19ils92nln8q55j8vfdgvhc8.ls error="server returned 404: 404 page not found\n"19832026/10/01 10:24:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19842026/10/01 10:24:53 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19852026/10/01 10:24:53 WARN Failed to register uploaded object key=nar/10f16f4cq1m0vrpdpf2lkp9yvkrhh3mv5sgj8ny16wdncs275q7x.nar.zst error="server returned 404: 404 page not found\n"19862026/10/01 10:24:53 INFO Signed narinfos id=1 count=319872026/10/01 10:24:53 INFO Uploading 3 narinfos19882026-10-01 10:24:53.655 UTC [41985] ERROR: relation "goose_db_version" does not exist at character 3619892026-10-01 10:24:53.655 UTC [41985] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19902026/10/01 10:24:53 WARN Failed to register uploaded object key=0nvqkasa19ils92nln8q55j8vfdgvhc8.narinfo error="server returned 404: 404 page not found\n"19912026/10/01 10:24:53 WARN Failed to register uploaded object key=2zf8riqwffl9bl6g24q4rfqprwhljyfv.narinfo error="server returned 404: 404 page not found\n"19922026/10/01 10:24:53 INFO Received complete push request method=POST path=/api/pushes/1/complete19932026/10/01 10:24:53 WARN Failed to register uploaded object key=kd86slb7bvn2r58zjlnpws5x1y8znzk5.narinfo error="server returned 404: 404 page not found\n"19942026/10/01 10:24:53 INFO Upload complete. (133ms)1995=== NAME TestClientPushesUseOnePush1996 client_pushes_test.go:97: Retrieved narinfo from S3:1997 StorePath: /nix/var/nix/builds/nix-41045-2866623493/TestClientPushesUseOnePush3464199161/001/store/0nvqkasa19ils92nln8q55j8vfdgvhc8-shared-dep1998 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1999 Compression: zstd2000 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822001 NarSize: 1362002 References: 2003 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2004 client_pushes_test.go:97: Retrieved narinfo from S3:2005 StorePath: /nix/var/nix/builds/nix-41045-2866623493/TestClientPushesUseOnePush3464199161/001/store/2zf8riqwffl9bl6g24q4rfqprwhljyfv-a2006 URL: nar/10f16f4cq1m0vrpdpf2lkp9yvkrhh3mv5sgj8ny16wdncs275q7x.nar.zst2007 Compression: zstd2008 NarHash: sha256:10f16f4cq1m0vrpdpf2lkp9yvkrhh3mv5sgj8ny16wdncs275q7x2009 NarSize: 2482010 References: /nix/var/nix/builds/nix-41045-2866623493/TestClientPushesUseOnePush3464199161/001/store/0nvqkasa19ils92nln8q55j8vfdgvhc8-shared-dep2011 CA: text:sha256:1ff4jiv9w2m7m818qgr5sx2pydy3yljc63wia3qyn7w1askf500y2012 client_pushes_test.go:97: Retrieved narinfo from S3:2013 StorePath: /nix/var/nix/builds/nix-41045-2866623493/TestClientPushesUseOnePush3464199161/001/store/kd86slb7bvn2r58zjlnpws5x1y8znzk5-b2014 URL: nar/10f16f4cq1m0vrpdpf2lkp9yvkrhh3mv5sgj8ny16wdncs275q7x.nar.zst2015 Compression: zstd2016 NarHash: sha256:10f16f4cq1m0vrpdpf2lkp9yvkrhh3mv5sgj8ny16wdncs275q7x2017 NarSize: 2482018 References: /nix/var/nix/builds/nix-41045-2866623493/TestClientPushesUseOnePush3464199161/001/store/0nvqkasa19ils92nln8q55j8vfdgvhc8-shared-dep2019 CA: text:sha256:1ff4jiv9w2m7m818qgr5sx2pydy3yljc63wia3qyn7w1askf500y2020=== NAME TestOrphanedObjectsGCStressTest2021 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2022=== NAME TestPinProtectsFromGC2023 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-41045-2866623493/TestPinProtectsFromGC1976783109/001/store/d0wiki2pflmpwkwipj9cvirbba6a0v9j-pinned-file.txt2024 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-41045-2866623493/TestPinProtectsFromGC1976783109/001/store/z4aqbgqffr16ff1g9fgvgykb91946s1q-unpinned-file.txt2025=== NAME TestOrphanedObjectsGCStressTest2026 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion2027--- PASS: TestClientPushesUseOnePush (3.70s)2028=== CONT TestRedundantMultipartUpload20292026/10/01 10:24:53 INFO Received push request method=POST path=/api/pushes20302026/10/01 10:24:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20312026/10/01 10:24:53 INFO Uploading d0wiki2pflmpwkwipj9cvirbba6a0v9j-pinned-file.txt (128B)20322026/10/01 10:24:53 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"20332026/10/01 10:24:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20342026/10/01 10:24:53 WARN Failed to register uploaded object key=d0wiki2pflmpwkwipj9cvirbba6a0v9j.ls error="server returned 404: 404 page not found\n"20352026/10/01 10:24:53 INFO Signed narinfos id=1 count=120362026/10/01 10:24:53 INFO Uploading 1 narinfos20372026/10/01 10:24:53 OK 20241026095416_initial_model.sql (199.47ms)20382026/10/01 10:24:53 OK 20251210153512_drop_unused_gin_index.sql (27.93ms)20392026/10/01 10:24:53 INFO Received complete push request method=POST path=/api/pushes/1/complete20402026/10/01 10:24:53 WARN Failed to register uploaded object key=d0wiki2pflmpwkwipj9cvirbba6a0v9j.narinfo error="server returned 404: 404 page not found\n"20412026/10/01 10:24:53 INFO Upload complete. (216ms)20422026/10/01 10:24:53 OK 20251218171726_add_pins.sql (58.38ms)20432026/10/01 10:24:54 OK 20260628120000_add_object_size_and_stats.sql (55.81ms)20442026/10/01 10:24:54 INFO Received push request method=POST path=/api/pushes20452026/10/01 10:24:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20462026/10/01 10:24:54 INFO Uploading z4aqbgqffr16ff1g9fgvgykb91946s1q-unpinned-file.txt (128B)20472026/10/01 10:24:54 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"20482026/10/01 10:24:54 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign20492026/10/01 10:24:54 INFO Signed narinfos id=2 count=120502026/10/01 10:24:54 INFO Uploading 1 narinfos20512026/10/01 10:24:54 WARN Failed to register uploaded object key=z4aqbgqffr16ff1g9fgvgykb91946s1q.ls error="server returned 404: 404 page not found\n"20522026/10/01 10:24:54 WARN Failed to register uploaded object key=z4aqbgqffr16ff1g9fgvgykb91946s1q.narinfo error="server returned 404: 404 page not found\n"20532026/10/01 10:24:54 INFO Received complete push request method=POST path=/api/pushes/2/complete20542026/10/01 10:24:54 OK 20260905000000_add_claims.sql (98.49ms)20552026/10/01 10:24:54 INFO Upload complete. (137ms)20562026/10/01 10:24:54 OK 20260920000000_drop_claims.sql (53.16ms)20572026/10/01 10:24:54 INFO Starting cleanup of old closures method=DELETE path=/api/closures20582026/10/01 10:24:54 INFO Garbage collection started20592026/10/01 10:24:54 INFO Aborted multipart uploads count=0 kept=020602026/10/01 10:24:54 WARN Force mode enabled - objects will be deleted immediately without grace period20612026/10/01 10:24:54 OK 20260923120000_add_pushes.sql (12.47ms)20622026/10/01 10:24:54 goose: successfully migrated database to version: 2026092312000020632026/10/01 10:24:54 OK 1_commit_pending_closure.sql (857.17µs)20642026/10/01 10:24:54 OK 2_object_stats_trigger.sql (232.58µs)20652026/10/01 10:24:54 OK 3_commit_push.sql (204.58µs)20662026/10/01 10:24:54 goose: up to current file version: 320672026/10/01 10:24:54 INFO Received push request method=POST path=/api/pushes20682026/10/01 10:24:54 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)20692026/10/01 10:24:54 INFO Uploading kniw6gx6kzvkp4x705wcjwnwxw5brvwn-shared-dep (136B)20702026/10/01 10:24:54 INFO Uploading qjxvs5ydqbfz9fdzby1qvivb9y7q43rb-top (256B)20712026/10/01 10:24:54 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=020722026/10/01 10:24:54 WARN Failed to register uploaded object key=qjxvs5ydqbfz9fdzby1qvivb9y7q43rb.ls error="server returned 404: 404 page not found\n"20732026/10/01 10:24:54 WARN Failed to register uploaded object key=nar/1vy5bfxl0hxmhlkhwql9hbbynab6dja3smbr8ngs0b0flzzi5iha.nar.zst error="server returned 404: 404 page not found\n"20742026/10/01 10:24:54 WARN Failed to register uploaded object key=kniw6gx6kzvkp4x705wcjwnwxw5brvwn.ls error="server returned 404: 404 page not found\n"20752026/10/01 10:24:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20762026/10/01 10:24:54 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"20772026/10/01 10:24:54 INFO Signed narinfos id=1 count=220782026/10/01 10:24:54 INFO Uploading 2 narinfos20792026/10/01 10:24:54 INFO Vacuumed table table=pending_closures20802026/10/01 10:24:54 INFO Received complete push request method=POST path=/api/pushes/1/complete20812026/10/01 10:24:54 WARN Failed to register uploaded object key=qjxvs5ydqbfz9fdzby1qvivb9y7q43rb.narinfo error="server returned 404: 404 page not found\n"20822026/10/01 10:24:54 WARN Failed to register uploaded object key=kniw6gx6kzvkp4x705wcjwnwxw5brvwn.narinfo error="server returned 404: 404 page not found\n"20832026/10/01 10:24:54 INFO Vacuumed table table=pending_objects20842026/10/01 10:24:54 INFO Vacuumed table table=multipart_uploads20852026/10/01 10:24:54 INFO Upload complete. (274ms)2086=== NAME TestClientSharedPathCommittedMidPush2087 client_integration_test.go:680: Retrieved narinfo from S3:2088 StorePath: /nix/var/nix/builds/nix-41045-2866623493/TestClientSharedPathCommittedMidPush827190839/001/store/kniw6gx6kzvkp4x705wcjwnwxw5brvwn-shared-dep2089 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2090 Compression: zstd2091 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822092 NarSize: 1362093 References: 2094 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2095=== NAME TestClientIntegration2096 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-41045-2866623493/TestClientIntegration646422827/002/store/9ckwfz26rix7bzv12x6xg887aigjkdwk-test-file.txt2097=== NAME TestClientSharedPathCommittedMidPush2098 client_integration_test.go:680: Retrieved narinfo from S3:2099 StorePath: /nix/var/nix/builds/nix-41045-2866623493/TestClientSharedPathCommittedMidPush827190839/001/store/qjxvs5ydqbfz9fdzby1qvivb9y7q43rb-top2100 URL: nar/1vy5bfxl0hxmhlkhwql9hbbynab6dja3smbr8ngs0b0flzzi5iha.nar.zst2101 Compression: zstd2102 NarHash: sha256:1vy5bfxl0hxmhlkhwql9hbbynab6dja3smbr8ngs0b0flzzi5iha2103 NarSize: 2562104 References: /nix/var/nix/builds/nix-41045-2866623493/TestClientSharedPathCommittedMidPush827190839/001/store/kniw6gx6kzvkp4x705wcjwnwxw5brvwn-shared-dep2105 CA: text:sha256:0adj5la8ziaxrlg0zaw96zzmc6vzxscikxhsykcf581fx3ypp5b021062026/10/01 10:24:54 INFO Vacuumed table table=closures21072026/10/01 10:24:54 INFO Vacuumed table table=objects2108--- PASS: TestClientSharedPathCommittedMidPush (3.53s)2109=== CONT TestPush_SignsNarinfosOfItsPendingObjects21102026/10/01 10:24:54 INFO Received push request method=POST path=/api/pushes21112026/10/01 10:24:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21122026/10/01 10:24:54 INFO Uploading 9ckwfz26rix7bzv12x6xg887aigjkdwk-test-file.txt (152B)21132026/10/01 10:24:54 WARN Failed to register uploaded object key=9ckwfz26rix7bzv12x6xg887aigjkdwk.ls error="server returned 404: 404 page not found\n"21142026/10/01 10:24:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign21152026/10/01 10:24:54 INFO Signed narinfos id=1 count=121162026/10/01 10:24:54 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"21172026/10/01 10:24:54 INFO Uploading 1 narinfos21182026/10/01 10:24:54 INFO Received complete push request method=POST path=/api/pushes/1/complete21192026/10/01 10:24:54 WARN Failed to register uploaded object key=9ckwfz26rix7bzv12x6xg887aigjkdwk.narinfo error="server returned 404: 404 page not found\n"21202026/10/01 10:24:54 INFO Upload complete. (242ms)21212026/10/01 10:24:54 INFO All 1 paths already cached2122=== NAME TestClientIntegration2123 client_integration_test.go:312: Retrieved narinfo from S3:2124 StorePath: /nix/var/nix/builds/nix-41045-2866623493/TestClientIntegration646422827/002/store/9ckwfz26rix7bzv12x6xg887aigjkdwk-test-file.txt2125 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2126 Compression: zstd2127 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12128 NarSize: 1522129 References: 2130 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12131 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2132 client_integration_test.go:313: Decompressed .ls content (64 bytes):2133 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2134 client_integration_test.go:316: Testing garbage collection...2135=== NAME TestClientMultipleUploads2136 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-41045-2866623493/TestClientMultipleUploads1541875314/001/store/7jp23zsdms9cm4f0f6k01xq94jrxkax0-test-file-0.txt21372026/10/01 10:24:54 INFO Starting cleanup of old closures method=DELETE path=/api/closures21382026/10/01 10:24:54 INFO Garbage collection started21392026/10/01 10:24:54 INFO Aborted multipart uploads count=0 kept=021402026/10/01 10:24:54 WARN Force mode enabled - objects will be deleted immediately without grace period21412026/10/01 10:24:54 INFO Aborted multipart uploads count=1 kept=021422026/10/01 10:24:54 INFO Received cleanup request method=DELETE path=/api/pending_closures21432026/10/01 10:24:54 INFO Aborted multipart uploads count=1 kept=02144--- PASS: TestPendingCleanupUsesOneCutoff (9.86s)2145=== CONT TestPush_RejectsBadRequests21462026/10/01 10:24:54 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=02147=== NAME TestClientMultipleUploads2148 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-41045-2866623493/TestClientMultipleUploads1541875314/001/store/yf0bafaqf1wdj3b61l0zm55i5b4iixhw-test-file-1.txt21492026/10/01 10:24:54 INFO Vacuumed table table=pending_closures21502026/10/01 10:24:54 INFO Vacuumed table table=pending_objects21512026/10/01 10:24:54 INFO Vacuumed table table=multipart_uploads21522026/10/01 10:24:54 INFO Vacuumed table table=closures21532026/10/01 10:24:55 INFO Vacuumed table table=objects2154 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-41045-2866623493/TestClientMultipleUploads1541875314/001/store/1gnq9vg5pvjy1rl96jjisa0ajlw1kx0d-test-file-2.txt2155{"timestamp":"2026-10-01T10:24:55.102768Z","level":"ERROR","message":"Scanner cycle completed without a durable data usage snapshot","event":"scanner_persist_state","component":"scanner","subsystem":"runtime","cycle":4,"outcome":"NoUpdate","state":"usage_not_durable","target":"rustfs::scanner","filename":"crates/scanner/src/scanner.rs","line_number":2350,"threadName":"rustfs-worker","threadId":"ThreadId(8)"}21562026/10/01 10:24:55 INFO Received push request method=POST path=/api/pushes21572026-10-01 10:24:55.115 UTC [42064] ERROR: relation "goose_db_version" does not exist at character 3621582026-10-01 10:24:55.115 UTC [42064] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21592026/10/01 10:24:55 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)21602026/10/01 10:24:55 INFO Uploading yf0bafaqf1wdj3b61l0zm55i5b4iixhw-test-file-1.txt (160B)21612026/10/01 10:24:55 INFO Uploading 1gnq9vg5pvjy1rl96jjisa0ajlw1kx0d-test-file-2.txt (160B)21622026/10/01 10:24:55 INFO Uploading 7jp23zsdms9cm4f0f6k01xq94jrxkax0-test-file-0.txt (160B)21632026/10/01 10:24:55 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"21642026/10/01 10:24:55 WARN Failed to register uploaded object key=7jp23zsdms9cm4f0f6k01xq94jrxkax0.ls error="server returned 404: 404 page not found\n"21652026/10/01 10:24:55 WARN Failed to register uploaded object key=1gnq9vg5pvjy1rl96jjisa0ajlw1kx0d.ls error="server returned 404: 404 page not found\n"21662026/10/01 10:24:55 WARN Failed to register uploaded object key=yf0bafaqf1wdj3b61l0zm55i5b4iixhw.ls error="server returned 404: 404 page not found\n"21672026/10/01 10:24:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign21682026/10/01 10:24:55 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"21692026/10/01 10:24:55 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"21702026/10/01 10:24:55 INFO Signed narinfos id=1 count=321712026/10/01 10:24:55 INFO Uploading 3 narinfos21722026/10/01 10:24:55 WARN Failed to register uploaded object key=7jp23zsdms9cm4f0f6k01xq94jrxkax0.narinfo error="server returned 404: 404 page not found\n"21732026/10/01 10:24:55 WARN Failed to register uploaded object key=yf0bafaqf1wdj3b61l0zm55i5b4iixhw.narinfo error="server returned 404: 404 page not found\n"21742026/10/01 10:24:55 INFO Received complete push request method=POST path=/api/pushes/1/complete21752026/10/01 10:24:55 WARN Failed to register uploaded object key=1gnq9vg5pvjy1rl96jjisa0ajlw1kx0d.narinfo error="server returned 404: 404 page not found\n"21762026/10/01 10:24:55 INFO Upload complete. (251ms)2177 client_integration_test.go:369: Uploaded 3 paths in 293.398916ms2178=== NAME TestClientCADerivations2179 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-41045-2866623493/TestClientCADerivations897048569/001/store/6czmd4k7bcxvwhi2mv74mfim8nxw34wz-ca-test21802026/10/01 10:24:55 OK 20241026095416_initial_model.sql (200.9ms)21812026/10/01 10:24:55 OK 20251210153512_drop_unused_gin_index.sql (15.5ms)2182--- PASS: TestClientMultipleUploads (4.33s)2183=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit2184=== NAME TestClientCADerivations2185 client_ca_test.go:139: Found 1 dependencies (including self)21862026/10/01 10:24:55 OK 20251218171726_add_pins.sql (29.49ms)21872026-10-01 10:24:55.407 UTC [42069] ERROR: relation "goose_db_version" does not exist at character 3621882026-10-01 10:24:55.407 UTC [42069] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21892026/10/01 10:24:55 OK 20260628120000_add_object_size_and_stats.sql (53.37ms)21902026/10/01 10:24:55 OK 20260905000000_add_claims.sql (29.45ms)21912026/10/01 10:24:55 OK 20260920000000_drop_claims.sql (13.14ms)21922026/10/01 10:24:55 OK 20260923120000_add_pushes.sql (13.97ms)21932026/10/01 10:24:55 goose: successfully migrated database to version: 2026092312000021942026/10/01 10:24:55 OK 1_commit_pending_closure.sql (3.34ms)21952026/10/01 10:24:55 OK 2_object_stats_trigger.sql (693.29µs)21962026/10/01 10:24:55 OK 3_commit_push.sql (528.92µs)21972026/10/01 10:24:55 goose: up to current file version: 321982026/10/01 10:24:55 INFO Received push request method=POST path=/api/pushes21992026/10/01 10:24:55 OK 20241026095416_initial_model.sql (70.05ms)22002026/10/01 10:24:55 OK 20251210153512_drop_unused_gin_index.sql (15.76ms)22012026/10/01 10:24:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)22022026/10/01 10:24:55 INFO Uploading 6czmd4k7bcxvwhi2mv74mfim8nxw34wz-ca-test (144B)22032026/10/01 10:24:55 OK 20251218171726_add_pins.sql (27.34ms)22042026/10/01 10:24:55 WARN Failed to register uploaded object key=6czmd4k7bcxvwhi2mv74mfim8nxw34wz.ls error="server returned 404: 404 page not found\n"22052026/10/01 10:24:55 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"22062026/10/01 10:24:55 WARN Failed to register uploaded object key=log/pjf95y9m90ii3x0j2p6kak9q963j3816-ca-test.drv error="server returned 404: 404 page not found\n"22072026/10/01 10:24:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign22082026/10/01 10:24:55 OK 20260628120000_add_object_size_and_stats.sql (28.87ms)22092026/10/01 10:24:55 INFO Signed narinfos id=1 count=122102026/10/01 10:24:55 INFO Uploading 1 narinfos22112026/10/01 10:24:55 INFO Received complete push request method=POST path=/api/pushes/1/complete22122026/10/01 10:24:55 WARN Failed to register uploaded object key=6czmd4k7bcxvwhi2mv74mfim8nxw34wz.narinfo error="server returned 404: 404 page not found\n"22132026/10/01 10:24:55 INFO Upload complete. (252ms)2214 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-41045-2866623493/TestClientCADerivations897048569/001/store/6czmd4k7bcxvwhi2mv74mfim8nxw34wz-ca-test2215 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2216 Compression: zstd2217 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2218 NarSize: 1442219 References: 2220 Deriver: /nix/var/nix/builds/nix-41045-2866623493/TestClientCADerivations897048569/001/store/pjf95y9m90ii3x0j2p6kak9q963j3816-ca-test.drv2221 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2222 client_ca_test.go:185: Checking for realisation files in S3...2223 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2224 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache22252026/10/01 10:24:55 OK 20260905000000_add_claims.sql (98.15ms)22262026/10/01 10:24:55 OK 20260920000000_drop_claims.sql (51.83ms)22272026/10/01 10:24:55 OK 20260923120000_add_pushes.sql (33.36ms)22282026/10/01 10:24:55 goose: successfully migrated database to version: 2026092312000022292026/10/01 10:24:55 OK 1_commit_pending_closure.sql (1.19ms)22302026/10/01 10:24:55 OK 2_object_stats_trigger.sql (240.25µs)22312026/10/01 10:24:55 OK 3_commit_push.sql (206.04µs)22322026/10/01 10:24:55 goose: up to current file version: 32233 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket57?endpoint=http://localhost:61295®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-41045-2866623493/TestClientCADerivations897048569/001/store'2234 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12235--- PASS: TestCacheStatsHandler (2.58s)2236=== CONT TestPush_CompleteCommitsEveryRoot2237--- PASS: TestClientCADerivations (3.84s)2238=== CONT TestService_AuthMiddleware_OIDC22392026/10/01 10:24:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61706/oidc22402026/10/01 10:24:56 INFO Received push request method=POST path=/api/pushes22412026/10/01 10:24:56 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=022422026/10/01 10:24:56 INFO Received create pin request method=POST path=/api/pins/myapp22432026/10/01 10:24:56 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-41045-2866623493/TestPinProtectsFromGC1976783109/001/store/d0wiki2pflmpwkwipj9cvirbba6a0v9j-pinned-file.txt narinfo_key=d0wiki2pflmpwkwipj9cvirbba6a0v9j.narinfo22442026/10/01 10:24:56 INFO Starting cleanup of old closures method=DELETE path=/api/closures22452026/10/01 10:24:56 INFO Garbage collection started22462026/10/01 10:24:56 INFO Aborted multipart uploads count=0 kept=022472026/10/01 10:24:56 WARN Force mode enabled - objects will be deleted immediately without grace period22482026/10/01 10:24:56 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=022492026/10/01 10:24:56 INFO Vacuumed table table=pending_closures22502026/10/01 10:24:56 INFO Vacuumed table table=pending_objects22512026/10/01 10:24:56 INFO Vacuumed table table=multipart_uploads22522026/10/01 10:24:56 INFO Vacuumed table table=closures22532026/10/01 10:24:56 INFO Vacuumed table table=objects2254--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (2.86s)2255=== CONT TestService_ReadScope_PublicByDefault22562026-10-01 10:24:56.512 UTC [42085] ERROR: relation "goose_db_version" does not exist at character 3622572026-10-01 10:24:56.512 UTC [42085] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22582026/10/01 10:24:56 OK 20241026095416_initial_model.sql (125.25ms)22592026/10/01 10:24:56 OK 20251210153512_drop_unused_gin_index.sql (16.01ms)22602026/10/01 10:24:56 OK 20251218171726_add_pins.sql (23.19ms)22612026-10-01 10:24:56.744 UTC [42096] ERROR: relation "goose_db_version" does not exist at character 3622622026-10-01 10:24:56.744 UTC [42096] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22632026/10/01 10:24:56 OK 20260628120000_add_object_size_and_stats.sql (79.82ms)22642026/10/01 10:24:56 OK 20260905000000_add_claims.sql (12.23ms)22652026/10/01 10:24:56 OK 20260920000000_drop_claims.sql (5.28ms)22662026/10/01 10:24:56 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02267=== NAME TestClientIntegration2268 client_integration_test.go:323: Objects in database after GC:2269 client_integration_test.go:323: Successfully deleted all objects with GC --force22702026/10/01 10:24:56 OK 20260923120000_add_pushes.sql (21.5ms)22712026/10/01 10:24:56 goose: successfully migrated database to version: 2026092312000022722026/10/01 10:24:56 OK 1_commit_pending_closure.sql (2.22ms)22732026/10/01 10:24:56 OK 2_object_stats_trigger.sql (359.83µs)22742026/10/01 10:24:56 OK 3_commit_push.sql (312.17µs)22752026/10/01 10:24:56 goose: up to current file version: 32276--- PASS: TestClientIntegration (5.86s)2277=== CONT TestService_RequireScope_OIDC22782026-10-01 10:24:56.974 UTC [42097] ERROR: relation "goose_db_version" does not exist at character 3622792026-10-01 10:24:56.974 UTC [42097] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22802026/10/01 10:24:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61716/oidc22812026/10/01 10:24:57 OK 20241026095416_initial_model.sql (237.13ms)22822026/10/01 10:24:57 OK 20251210153512_drop_unused_gin_index.sql (27.66ms)22832026/10/01 10:24:57 OK 20251218171726_add_pins.sql (43.99ms)22842026/10/01 10:24:57 OK 20260628120000_add_object_size_and_stats.sql (60.08ms)22852026/10/01 10:24:57 INFO Received uploads request method=POST path=/api/pending_closures22862026/10/01 10:24:57 OK 20260905000000_add_claims.sql (156.06ms)22872026/10/01 10:24:57 INFO Received uploads request method=POST path=/api/pending_closures22882026/10/01 10:24:57 OK 20260920000000_drop_claims.sql (79.96ms)22892026/10/01 10:24:57 OK 20260923120000_add_pushes.sql (45.28ms)22902026/10/01 10:24:57 goose: successfully migrated database to version: 2026092312000022912026/10/01 10:24:57 OK 1_commit_pending_closure.sql (2.25ms)22922026/10/01 10:24:57 OK 2_object_stats_trigger.sql (370.04µs)22932026/10/01 10:24:57 OK 3_commit_push.sql (292.38µs)22942026/10/01 10:24:57 goose: up to current file version: 322952026/10/01 10:24:57 OK 20241026095416_initial_model.sql (368.18ms)22962026/10/01 10:24:57 OK 20251210153512_drop_unused_gin_index.sql (7.52ms)22972026/10/01 10:24:57 OK 20251218171726_add_pins.sql (69.29ms)22982026/10/01 10:24:57 OK 20260628120000_add_object_size_and_stats.sql (64.74ms)22992026/10/01 10:24:57 OK 20260905000000_add_claims.sql (153.77ms)23002026/10/01 10:24:57 OK 20260920000000_drop_claims.sql (92.51ms)23012026/10/01 10:24:57 OK 20260923120000_add_pushes.sql (29.53ms)23022026/10/01 10:24:57 goose: successfully migrated database to version: 2026092312000023032026/10/01 10:24:57 OK 1_commit_pending_closure.sql (1.55ms)23042026/10/01 10:24:57 OK 2_object_stats_trigger.sql (301.5µs)23052026/10/01 10:24:57 OK 3_commit_push.sql (238.58µs)23062026/10/01 10:24:57 goose: up to current file version: 323072026/10/01 10:24:57 INFO Received push request method=POST path=/api/pushes23082026/10/01 10:24:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign23092026/10/01 10:24:58 INFO Signed narinfos id=1 count=12310--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (3.53s)2311=== CONT TestService_verifyS3Integrity2312=== NAME TestPinProtectsFromGC2313 client_integration_test.go:840: Pin successfully protected closure from garbage collection2314--- PASS: TestPinProtectsFromGC (8.00s)2315=== CONT TestReadRedirectKeepsNarinfoProxied2316=== NAME TestOrphanedObjectsGCStressTest2317 orphaned_objects_gc_test.go:509: Stress test completed successfully:2318 orphaned_objects_gc_test.go:510: - Active objects preserved: 202319 orphaned_objects_gc_test.go:511: - Objects deleted: 2102320 orphaned_objects_gc_test.go:512: - Total GC'd: 2102321--- PASS: TestOrphanedObjectsGCStressTest (14.22s)2322=== CONT TestReadRedirectUsesPublicS3URL2323=== RUN TestPush_RejectsBadRequests/no_roots2324=== PAUSE TestPush_RejectsBadRequests/no_roots2325=== RUN TestPush_RejectsBadRequests/no_objects2326=== PAUSE TestPush_RejectsBadRequests/no_objects2327=== RUN TestPush_RejectsBadRequests/bad_root2328=== PAUSE TestPush_RejectsBadRequests/bad_root2329=== RUN TestPush_RejectsBadRequests/root_not_in_objects2330=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects2331=== CONT TestReadProxyRangeRequest23322026-10-01 10:24:59.085 UTC [42130] ERROR: relation "goose_db_version" does not exist at character 3623332026-10-01 10:24:59.085 UTC [42130] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23342026-10-01 10:24:59.604 UTC [42138] ERROR: relation "goose_db_version" does not exist at character 3623352026-10-01 10:24:59.604 UTC [42138] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23362026/10/01 10:24:59 OK 20241026095416_initial_model.sql (310.77ms)23372026/10/01 10:24:59 OK 20251210153512_drop_unused_gin_index.sql (11.08ms)23382026-10-01 10:24:59.625 UTC [42137] ERROR: relation "goose_db_version" does not exist at character 3623392026-10-01 10:24:59.625 UTC [42137] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23402026/10/01 10:24:59 OK 20251218171726_add_pins.sql (37.26ms)23412026/10/01 10:24:59 OK 20260628120000_add_object_size_and_stats.sql (52.61ms)23422026/10/01 10:24:59 OK 20260905000000_add_claims.sql (119.86ms)23432026/10/01 10:24:59 OK 20260920000000_drop_claims.sql (80.16ms)23442026/10/01 10:24:59 OK 20260923120000_add_pushes.sql (23.13ms)23452026/10/01 10:24:59 goose: successfully migrated database to version: 2026092312000023462026-10-01 10:24:59.945 UTC [42142] ERROR: relation "goose_db_version" does not exist at character 3623472026-10-01 10:24:59.945 UTC [42142] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23482026/10/01 10:24:59 OK 1_commit_pending_closure.sql (8.65ms)23492026/10/01 10:24:59 OK 2_object_stats_trigger.sql (525.5µs)23502026/10/01 10:24:59 OK 3_commit_push.sql (406.17µs)23512026/10/01 10:24:59 goose: up to current file version: 323522026/10/01 10:24:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23532026/10/01 10:24:59 OK 20241026095416_initial_model.sql (278.38ms)23542026/10/01 10:25:00 OK 20251210153512_drop_unused_gin_index.sql (42.9ms)23552026/10/01 10:25:00 OK 20241026095416_initial_model.sql (341.62ms)23562026/10/01 10:25:00 OK 20251210153512_drop_unused_gin_index.sql (26.23ms)23572026/10/01 10:25:00 OK 20251218171726_add_pins.sql (46.28ms)23582026/10/01 10:25:00 OK 20251218171726_add_pins.sql (29.38ms)23592026/10/01 10:25:00 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZGZiNWUwNjEtNmQ4OC00MmZlLTk2OTUtNGRkYzUxNTRhNDhmLjA4YTkxZjA0LWM3YTMtNDE2YS1iYmEzLTc0YjVhN2Y3MzYyMngxNzkwODUwMjk3MzM1MjQ0MDAw parts=1223602026/10/01 10:25:00 INFO Received uploads request method=POST path=/api/pending_closures23612026/10/01 10:25:00 OK 20260628120000_add_object_size_and_stats.sql (88.48ms)23622026/10/01 10:25:00 OK 20260628120000_add_object_size_and_stats.sql (98.46ms)23632026/10/01 10:25:00 INFO Received uploads request method=POST path=/api/pending_closures23642026/10/01 10:25:00 OK 20260905000000_add_claims.sql (194.89ms)23652026/10/01 10:25:00 OK 20260905000000_add_claims.sql (201.84ms)23662026/10/01 10:25:00 OK 20260920000000_drop_claims.sql (103.9ms)23672026/10/01 10:25:00 OK 20260920000000_drop_claims.sql (110.91ms)23682026/10/01 10:25:00 OK 20260923120000_add_pushes.sql (56.17ms)23692026/10/01 10:25:00 goose: successfully migrated database to version: 2026092312000023702026/10/01 10:25:00 INFO Received push request method=POST path=/api/pushes23712026/10/01 10:25:00 OK 20260923120000_add_pushes.sql (62.66ms)23722026/10/01 10:25:00 goose: successfully migrated database to version: 2026092312000023732026/10/01 10:25:00 OK 1_commit_pending_closure.sql (9.29ms)23742026/10/01 10:25:00 OK 2_object_stats_trigger.sql (1.18ms)23752026/10/01 10:25:00 OK 3_commit_push.sql (3.31ms)23762026/10/01 10:25:00 goose: up to current file version: 323772026/10/01 10:25:00 OK 1_commit_pending_closure.sql (7.64ms)23782026/10/01 10:25:00 OK 2_object_stats_trigger.sql (5.05ms)23792026/10/01 10:25:00 OK 3_commit_push.sql (1.19ms)23802026/10/01 10:25:00 goose: up to current file version: 323812026/10/01 10:25:00 OK 20241026095416_initial_model.sql (512.47ms)23822026/10/01 10:25:00 OK 20251210153512_drop_unused_gin_index.sql (27.58ms)23832026/10/01 10:25:00 OK 20251218171726_add_pins.sql (87.22ms)23842026/10/01 10:25:00 INFO Received complete push request method=POST path=/api/pushes/1/complete23852026/10/01 10:25:00 OK 20260628120000_add_object_size_and_stats.sql (56.32ms)23862026/10/01 10:25:00 INFO Received push request method=POST path=/api/pushes23872026/10/01 10:25:00 INFO Aborted multipart uploads count=0 kept=023882026/10/01 10:25:00 WARN Force mode enabled - objects will be deleted immediately without grace period23892026/10/01 10:25:00 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=2 objects-failed-to-delete=023902026/10/01 10:25:00 OK 20260905000000_add_claims.sql (156.48ms)23912026/10/01 10:25:00 INFO Vacuumed table table=pending_closures23922026/10/01 10:25:01 INFO Vacuumed table table=pending_objects23932026/10/01 10:25:01 OK 20260920000000_drop_claims.sql (145.94ms)23942026/10/01 10:25:01 OK 20260923120000_add_pushes.sql (31.11ms)23952026/10/01 10:25:01 goose: successfully migrated database to version: 2026092312000023962026/10/01 10:25:01 INFO Vacuumed table table=multipart_uploads23972026/10/01 10:25:01 OK 1_commit_pending_closure.sql (6.49ms)23982026/10/01 10:25:01 OK 2_object_stats_trigger.sql (1.14ms)23992026/10/01 10:25:01 OK 3_commit_push.sql (656.83µs)24002026/10/01 10:25:01 goose: up to current file version: 324012026/10/01 10:25:01 INFO Vacuumed table table=closures24022026/10/01 10:25:01 INFO Received push request method=POST path=/api/pushes24032026/10/01 10:25:01 INFO Vacuumed table table=objects24042026/10/01 10:25:01 INFO Received complete push request method=POST path=/api/pushes/2/complete2405--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (5.81s)2406=== CONT TestService_createPendingClosureHandler24072026/10/01 10:25:01 INFO Received complete push request method=POST path=/api/pushes/1/complete2408--- PASS: TestPush_CompleteCommitsEveryRoot (5.59s)2409=== CONT TestService_AuthMiddleware_MTLSBoundSubjects2410=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2411=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2412=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2413=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2414=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2415=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2416=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2417=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2418=== CONT TestService_ReadAuthMiddleware24192026-10-01 10:25:01.964 UTC [42161] ERROR: relation "goose_db_version" does not exist at character 3624202026-10-01 10:25:01.964 UTC [42161] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2421--- PASS: TestService_ReadScope_PublicByDefault (5.79s)2422=== CONT TestService_AuthMiddleware_MTLSProxyHeader24232026/10/01 10:25:02 OK 20241026095416_initial_model.sql (279.27ms)24242026/10/01 10:25:02 OK 20251210153512_drop_unused_gin_index.sql (26.36ms)24252026/10/01 10:25:02 OK 20251218171726_add_pins.sql (50.75ms)24262026/10/01 10:25:02 OK 20260628120000_add_object_size_and_stats.sql (73.98ms)24272026-10-01 10:25:02.556 UTC [42166] ERROR: relation "goose_db_version" does not exist at character 3624282026-10-01 10:25:02.556 UTC [42166] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24292026/10/01 10:25:02 OK 20260905000000_add_claims.sql (51.49ms)24302026/10/01 10:25:02 OK 20260920000000_drop_claims.sql (77.11ms)24312026-10-01 10:25:02.648 UTC [42170] ERROR: relation "goose_db_version" does not exist at character 3624322026-10-01 10:25:02.648 UTC [42170] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24332026-10-01 10:25:02.648 UTC [42168] ERROR: relation "goose_db_version" does not exist at character 3624342026-10-01 10:25:02.648 UTC [42168] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24352026/10/01 10:25:02 OK 20260923120000_add_pushes.sql (7.9ms)24362026/10/01 10:25:02 goose: successfully migrated database to version: 2026092312000024372026/10/01 10:25:02 OK 1_commit_pending_closure.sql (2.13ms)24382026/10/01 10:25:02 OK 2_object_stats_trigger.sql (555.71µs)24392026/10/01 10:25:02 OK 3_commit_push.sql (2.32ms)24402026/10/01 10:25:02 goose: up to current file version: 324412026-10-01 10:25:02.928 UTC [42171] ERROR: relation "goose_db_version" does not exist at character 3624422026-10-01 10:25:02.928 UTC [42171] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24432026/10/01 10:25:02 OK 20241026095416_initial_model.sql (303.92ms)24442026/10/01 10:25:02 OK 20251210153512_drop_unused_gin_index.sql (30.2ms)24452026/10/01 10:25:02 OK 20251218171726_add_pins.sql (11.52ms)24462026/10/01 10:25:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete24472026/10/01 10:25:03 OK 20241026095416_initial_model.sql (266.98ms)24482026/10/01 10:25:03 OK 20260628120000_add_object_size_and_stats.sql (90.73ms)24492026/10/01 10:25:03 OK 20251210153512_drop_unused_gin_index.sql (62.18ms)24502026/10/01 10:25:03 OK 20241026095416_initial_model.sql (342.31ms)24512026/10/01 10:25:03 OK 20251210153512_drop_unused_gin_index.sql (18.69ms)24522026/10/01 10:25:03 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZGZiNWUwNjEtNmQ4OC00MmZlLTk2OTUtNGRkYzUxNTRhNDhmLmMxNGNmYTY2LTZhNDYtNDIyZC04Y2ZmLTZjNzFiMTZjOTJjN3gxNzkwODUwMzAwMTk2NTkzMDAw error="Get \"http://127.0.0.1:1/bucket60/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"24532026/10/01 10:25:03 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZGZiNWUwNjEtNmQ4OC00MmZlLTk2OTUtNGRkYzUxNTRhNDhmLjI2OGU5NzA0LTZkZjMtNDhmZC1iNjFjLWM1MTU4YTcyZGI1ZngxNzkwODUwMzAwMTIwNjg4MDAw parts=1224542026/10/01 10:25:03 INFO Received cleanup request method=DELETE path=/api/pending_closures24552026/10/01 10:25:03 INFO Aborted multipart uploads count=1 kept=024562026/10/01 10:25:03 OK 20251218171726_add_pins.sql (59.65ms)2457=== RUN TestService_RequireScope_OIDC/builder_may_write2458=== PAUSE TestService_RequireScope_OIDC/builder_may_write2459=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2460=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2461=== RUN TestService_RequireScope_OIDC/ops_may_admin2462=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2463=== RUN TestService_RequireScope_OIDC/ops_may_not_write2464=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2465=== RUN TestService_RequireScope_OIDC/reader_may_not_write2466=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2467=== RUN TestService_RequireScope_OIDC/static_token_may_admin2468=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2469=== RUN TestService_RequireScope_OIDC/static_token_may_write2470=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2471=== RUN TestService_RequireScope_OIDC/reader_may_read2472=== PAUSE TestService_RequireScope_OIDC/reader_may_read2473=== RUN TestService_RequireScope_OIDC/writer_implies_read2474=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2475=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2476=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2477=== CONT TestMetricsInventory2478--- PASS: TestRedundantMultipartUpload (9.43s)2479=== CONT TestServerTLSConfig2480=== RUN TestServerTLSConfig/no_client_CA2481=== PAUSE TestServerTLSConfig/no_client_CA2482=== RUN TestServerTLSConfig/missing_CA_file2483=== PAUSE TestServerTLSConfig/missing_CA_file2484=== RUN TestServerTLSConfig/not_a_PEM_file2485=== PAUSE TestServerTLSConfig/not_a_PEM_file2486=== CONT TestService_NativeMTLS24872026/10/01 10:25:03 OK 20260905000000_add_claims.sql (136.57ms)24882026/10/01 10:25:03 OK 20251218171726_add_pins.sql (88.74ms)24892026/10/01 10:25:03 OK 20260628120000_add_object_size_and_stats.sql (95.32ms)24902026/10/01 10:25:03 OK 20260628120000_add_object_size_and_stats.sql (91.36ms)24912026/10/01 10:25:03 OK 20260920000000_drop_claims.sql (98.27ms)24922026/10/01 10:25:03 OK 20260923120000_add_pushes.sql (55.45ms)24932026/10/01 10:25:03 goose: successfully migrated database to version: 2026092312000024942026/10/01 10:25:03 OK 1_commit_pending_closure.sql (2.83ms)24952026/10/01 10:25:03 OK 2_object_stats_trigger.sql (658.29µs)24962026/10/01 10:25:03 OK 3_commit_push.sql (413.63µs)24972026/10/01 10:25:03 goose: up to current file version: 324982026/10/01 10:25:03 OK 20260905000000_add_claims.sql (156.36ms)24992026/10/01 10:25:03 OK 20241026095416_initial_model.sql (455.92ms)25002026/10/01 10:25:03 OK 20260905000000_add_claims.sql (160.18ms)25012026/10/01 10:25:03 OK 20260920000000_drop_claims.sql (99.84ms)25022026/10/01 10:25:03 OK 20251210153512_drop_unused_gin_index.sql (48.25ms)25032026/10/01 10:25:03 OK 20260923120000_add_pushes.sql (50.89ms)25042026/10/01 10:25:03 goose: successfully migrated database to version: 2026092312000025052026/10/01 10:25:03 OK 1_commit_pending_closure.sql (4.44ms)25062026/10/01 10:25:03 OK 2_object_stats_trigger.sql (815.96µs)25072026/10/01 10:25:03 OK 3_commit_push.sql (442.42µs)25082026/10/01 10:25:03 goose: up to current file version: 325092026/10/01 10:25:03 OK 20260920000000_drop_claims.sql (124.87ms)25102026/10/01 10:25:03 OK 20251218171726_add_pins.sql (80.69ms)25112026/10/01 10:25:03 OK 20260923120000_add_pushes.sql (42.36ms)25122026/10/01 10:25:03 goose: successfully migrated database to version: 2026092312000025132026/10/01 10:25:03 OK 1_commit_pending_closure.sql (5.56ms)25142026/10/01 10:25:03 OK 2_object_stats_trigger.sql (918.58µs)25152026/10/01 10:25:03 OK 3_commit_push.sql (552.92µs)25162026/10/01 10:25:03 goose: up to current file version: 325172026/10/01 10:25:03 OK 20260628120000_add_object_size_and_stats.sql (91.88ms)25182026/10/01 10:25:03 INFO Received uploads request method=POST path=/api/pending_closures25192026/10/01 10:25:04 OK 20260905000000_add_claims.sql (317.12ms)25202026/10/01 10:25:04 OK 20260920000000_drop_claims.sql (133.32ms)25212026/10/01 10:25:04 OK 20260923120000_add_pushes.sql (36.69ms)25222026/10/01 10:25:04 goose: successfully migrated database to version: 2026092312000025232026/10/01 10:25:04 OK 1_commit_pending_closure.sql (2.1ms)25242026/10/01 10:25:04 OK 2_object_stats_trigger.sql (445.25µs)25252026/10/01 10:25:04 OK 3_commit_push.sql (323.33µs)25262026/10/01 10:25:04 goose: up to current file version: 32527--- PASS: TestReadProxyRangeRequest (6.13s)2528=== CONT TestCreatePendingClosureRejectsOversizedNAR25292026/10/01 10:25:04 INFO Received uploads request method=POST path=/api/pending_closures2530--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)2531=== CONT TestNARDeduplicationMetadataUploadBug2532--- PASS: TestReadRedirectKeepsNarinfoProxied (6.77s)2533=== CONT TestCacheConfigHandlerMaxNarSize2534--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)2535=== CONT TestReadProxyDisabled2536--- PASS: TestReadRedirectUsesPublicS3URL (7.46s)2537=== CONT TestReadRedirectNar25382026/10/01 10:25:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete25392026-10-01 10:25:06.992 UTC [42194] ERROR: relation "goose_db_version" does not exist at character 3625402026-10-01 10:25:06.992 UTC [42194] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25412026/10/01 10:25:07 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZGZiNWUwNjEtNmQ4OC00MmZlLTk2OTUtNGRkYzUxNTRhNDhmLmNjNmM5NTY5LTNlMDAtNGFlMC1iYTIwLWJmNGJlZDYzZjdhOXgxNzkwODUwMzA0MDIyNjIxMDAw parts=1025422026/10/01 10:25:07 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete25432026-10-01 10:25:07.154 UTC [42196] ERROR: relation "goose_db_version" does not exist at character 3625442026-10-01 10:25:07.154 UTC [42196] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25452026/10/01 10:25:07 INFO Completed upload id=125462026/10/01 10:25:07 INFO Received uploads request method=POST path=/api/pending_closures25472026/10/01 10:25:07 INFO Received uploads request method=POST path=/api/pending_closures25482026/10/01 10:25:07 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo25492026/10/01 10:25:07 WARN Found objects in DB but missing from S3, will re-upload count=12550--- PASS: TestService_verifyS3Integrity (9.06s)2551=== CONT TestReadProxyRootRedirectsToIndexHTML25522026-10-01 10:25:07.228 UTC [42195] ERROR: relation "goose_db_version" does not exist at character 3625532026-10-01 10:25:07.228 UTC [42195] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25542026-10-01 10:25:07.287 UTC [42199] ERROR: relation "goose_db_version" does not exist at character 3625552026-10-01 10:25:07.287 UTC [42199] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25562026/10/01 10:25:07 OK 20241026095416_initial_model.sql (333.9ms)25572026/10/01 10:25:07 OK 20251210153512_drop_unused_gin_index.sql (25.22ms)25582026/10/01 10:25:07 OK 20241026095416_initial_model.sql (315.44ms)25592026/10/01 10:25:07 OK 20251210153512_drop_unused_gin_index.sql (29.22ms)25602026/10/01 10:25:07 OK 20251218171726_add_pins.sql (67.14ms)25612026/10/01 10:25:07 OK 20251218171726_add_pins.sql (53.89ms)25622026/10/01 10:25:07 OK 20260628120000_add_object_size_and_stats.sql (49.42ms)25632026/10/01 10:25:07 OK 20241026095416_initial_model.sql (352.08ms)25642026/10/01 10:25:07 OK 20260628120000_add_object_size_and_stats.sql (37.26ms)25652026/10/01 10:25:07 OK 20241026095416_initial_model.sql (288.66ms)25662026/10/01 10:25:07 OK 20251210153512_drop_unused_gin_index.sql (7.57ms)25672026/10/01 10:25:07 OK 20251210153512_drop_unused_gin_index.sql (13.38ms)25682026/10/01 10:25:07 OK 20260905000000_add_claims.sql (61.92ms)25692026/10/01 10:25:07 OK 20251218171726_add_pins.sql (44.53ms)25702026/10/01 10:25:07 OK 20251218171726_add_pins.sql (52.98ms)25712026/10/01 10:25:07 OK 20260920000000_drop_claims.sql (42.32ms)25722026/10/01 10:25:07 OK 20260905000000_add_claims.sql (69.87ms)25732026/10/01 10:25:07 OK 20260923120000_add_pushes.sql (31.58ms)25742026/10/01 10:25:07 goose: successfully migrated database to version: 2026092312000025752026/10/01 10:25:07 OK 20260628120000_add_object_size_and_stats.sql (42.05ms)25762026/10/01 10:25:07 OK 20260628120000_add_object_size_and_stats.sql (42.84ms)25772026/10/01 10:25:07 OK 1_commit_pending_closure.sql (3.25ms)25782026/10/01 10:25:07 OK 2_object_stats_trigger.sql (599µs)25792026/10/01 10:25:07 OK 3_commit_push.sql (375.88µs)25802026/10/01 10:25:07 goose: up to current file version: 325812026/10/01 10:25:07 OK 20260920000000_drop_claims.sql (77.22ms)25822026/10/01 10:25:07 OK 20260923120000_add_pushes.sql (45.5ms)25832026/10/01 10:25:07 goose: successfully migrated database to version: 2026092312000025842026/10/01 10:25:07 OK 1_commit_pending_closure.sql (3.29ms)25852026/10/01 10:25:07 OK 2_object_stats_trigger.sql (675.33µs)25862026/10/01 10:25:07 OK 3_commit_push.sql (403.88µs)25872026/10/01 10:25:07 goose: up to current file version: 325882026/10/01 10:25:07 OK 20260905000000_add_claims.sql (161.31ms)25892026/10/01 10:25:07 OK 20260905000000_add_claims.sql (169.58ms)25902026/10/01 10:25:08 OK 20260920000000_drop_claims.sql (63.7ms)25912026/10/01 10:25:08 OK 20260920000000_drop_claims.sql (72.49ms)25922026/10/01 10:25:08 OK 20260923120000_add_pushes.sql (25.94ms)25932026/10/01 10:25:08 goose: successfully migrated database to version: 2026092312000025942026/10/01 10:25:08 OK 1_commit_pending_closure.sql (2.6ms)25952026/10/01 10:25:08 OK 2_object_stats_trigger.sql (586.58µs)25962026/10/01 10:25:08 OK 3_commit_push.sql (477µs)25972026/10/01 10:25:08 goose: up to current file version: 325982026/10/01 10:25:08 OK 20260923120000_add_pushes.sql (34.57ms)25992026/10/01 10:25:08 goose: successfully migrated database to version: 2026092312000026002026/10/01 10:25:08 OK 1_commit_pending_closure.sql (2.18ms)26012026/10/01 10:25:08 OK 2_object_stats_trigger.sql (487.08µs)26022026/10/01 10:25:08 OK 3_commit_push.sql (424.67µs)26032026/10/01 10:25:08 goose: up to current file version: 32604{"timestamp":"2026-10-01T10:25:08.057072Z","level":"ERROR","message":"Scanner cycle completed without a durable data usage snapshot","event":"scanner_persist_state","component":"scanner","subsystem":"runtime","cycle":4,"outcome":"NoUpdate","state":"usage_not_durable","target":"rustfs::scanner","filename":"crates/scanner/src/scanner.rs","line_number":2350,"threadName":"rustfs-worker","threadId":"ThreadId(8)"}26052026/10/01 10:25:08 INFO Received uploads request method=POST path=/api/pending_closures26062026/10/01 10:25:08 INFO Received uploads request method=POST path=/api/pending_closures26072026/10/01 10:25:08 INFO Received uploads request method=POST path=/api/pending_closures26082026-10-01 10:25:08.180 UTC [42211] ERROR: relation "goose_db_version" does not exist at character 3626092026-10-01 10:25:08.180 UTC [42211] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26102026-10-01 10:25:08.589 UTC [42212] ERROR: relation "goose_db_version" does not exist at character 3626112026-10-01 10:25:08.589 UTC [42212] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2612--- PASS: TestService_ReadAuthMiddleware (7.06s)2613=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info26142026/10/01 10:25:08 INFO Received uploads request method=POST path=/2615=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key26162026/10/01 10:25:08 INFO Received complete multipart upload request method=POST path=/2617=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal26182026/10/01 10:25:08 INFO Received uploads request method=POST path=/2619=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key26202026/10/01 10:25:08 INFO Received request for more parts method=POST path=/2621--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2622 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2623 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2624 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2625 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2626=== CONT TestPendingClosureWriteTimeout/empty2627=== CONT TestProxyWriteTimeout/narinfo2628=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline26292026/10/01 10:25:08 OK 20241026095416_initial_model.sql (421.65ms)26302026/10/01 10:25:08 OK 20251210153512_drop_unused_gin_index.sql (37.91ms)26312026/10/01 10:25:08 OK 20251218171726_add_pins.sql (75.45ms)26322026/10/01 10:25:08 OK 20260628120000_add_object_size_and_stats.sql (64.29ms)26332026/10/01 10:25:09 OK 20241026095416_initial_model.sql (374.85ms)26342026/10/01 10:25:09 OK 20260905000000_add_claims.sql (124.73ms)26352026/10/01 10:25:09 OK 20251210153512_drop_unused_gin_index.sql (10.31ms)26362026/10/01 10:25:09 OK 20251218171726_add_pins.sql (47.32ms)26372026/10/01 10:25:09 OK 20260920000000_drop_claims.sql (72.96ms)26382026/10/01 10:25:09 OK 20260923120000_add_pushes.sql (28.09ms)26392026/10/01 10:25:09 goose: successfully migrated database to version: 2026092312000026402026/10/01 10:25:09 OK 1_commit_pending_closure.sql (2.09ms)26412026/10/01 10:25:09 OK 2_object_stats_trigger.sql (475µs)26422026/10/01 10:25:09 OK 3_commit_push.sql (427.29µs)26432026/10/01 10:25:09 goose: up to current file version: 326442026/10/01 10:25:09 OK 20260628120000_add_object_size_and_stats.sql (74.76ms)26452026/10/01 10:25:09 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"26462026/10/01 10:25:09 WARN mTLS auth: bound subjects configured but subject DN unavailable26472026/10/01 10:25:09 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2648--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (7.71s)2649=== CONT TestPendingClosureWriteTimeout/670k_objects2650=== CONT TestPendingClosureWriteTimeout/400_objects2651=== CONT TestProxyWriteTimeout/unknown_size2652=== CONT TestProxyWriteTimeout/10_GiB_nar2653=== CONT TestProxyWriteTimeout/1_GiB_nar2654--- PASS: TestProxyWriteTimeout (0.00s)2655 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2656 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2657 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2658 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2659=== CONT TestIsValidUploadKey/narinfo2660=== CONT TestIsValidUploadKey/realisation_plus_in_output2661=== CONT TestIsValidUploadKey/unknown_type2662=== CONT TestIsValidUploadKey/empty_key2663=== CONT TestIsValidUploadKey/absolute2664=== CONT TestIsValidUploadKey/traversal_nar2665=== CONT TestIsValidUploadKey/traversal2666=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2667=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2668=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2669=== CONT TestIsValidUploadKey/index.html2670=== CONT TestIsValidUploadKey/nix-cache-info2671=== CONT TestIsValidUploadKey/build_log_home-manager_file2672=== CONT TestIsValidUploadKey/realisation2673=== CONT TestIsValidUploadKey/build_log_equals2674=== CONT TestIsValidUploadKey/build_log_question_mark2675=== CONT TestIsValidUploadKey/build_log_plus_in_name2676=== CONT TestIsValidUploadKey/nar_plain2677=== CONT TestIsValidUploadKey/build_log2678=== CONT TestIsValidUploadKey/listing2679=== CONT TestIsValidUploadKey/nar_xz2680=== CONT TestIsValidUploadKey/nar_zst2681--- PASS: TestIsValidUploadKey (0.03s)2682 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2683 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2684 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2685 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2686 --- PASS: TestIsValidUploadKey/absolute (0.00s)2687 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2688 --- PASS: TestIsValidUploadKey/traversal (0.00s)2689 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2690 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2691 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2692 --- PASS: TestIsValidUploadKey/index.html (0.00s)2693 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2694 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2695 --- PASS: TestIsValidUploadKey/realisation (0.00s)2696 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2697 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2698 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2699 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2700 --- PASS: TestIsValidUploadKey/build_log (0.00s)2701 --- PASS: TestIsValidUploadKey/listing (0.00s)2702 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2703 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2704=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure27052026/10/01 10:25:09 INFO Received uploads request method=POST path=/27062026/10/01 10:25:09 OK 20260905000000_add_claims.sql (132.45ms)27072026/10/01 10:25:09 OK 20260920000000_drop_claims.sql (54.24ms)27082026/10/01 10:25:09 OK 20260923120000_add_pushes.sql (25ms)27092026/10/01 10:25:09 goose: successfully migrated database to version: 2026092312000027102026/10/01 10:25:09 OK 1_commit_pending_closure.sql (1.06ms)27112026/10/01 10:25:09 OK 2_object_stats_trigger.sql (227.71µs)27122026/10/01 10:25:09 OK 3_commit_push.sql (182.83µs)27132026/10/01 10:25:09 goose: up to current file version: 32714=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts27152026/10/01 10:25:09 INFO Received request for more parts method=POST path=/2716=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart27172026/10/01 10:25:09 INFO Received complete multipart upload request method=POST path=/2718--- PASS: TestUploadHandlersRejectOversizedBody (0.05s)2719 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.29s)2720 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)2721 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)2722=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows2723--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (7.58s)2724=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check27252026-10-01 10:25:09.828 UTC [42231] ERROR: relation "goose_db_version" does not exist at character 3627262026-10-01 10:25:09.828 UTC [42231] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC27272026-10-01 10:25:09.963 UTC [42236] ERROR: relation "goose_db_version" does not exist at character 3627282026-10-01 10:25:09.963 UTC [42236] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2729--- PASS: TestMetricsInventory (7.03s)2730=== CONT TestIsValidCachePath/narinfo2731=== CONT TestIsValidCachePath/short_hash2732=== CONT TestIsValidCachePath/wrong_extension2733=== CONT TestIsValidCachePath/leading_slash2734=== CONT TestIsValidCachePath/empty2735=== CONT TestIsValidCachePath/random_path2736=== CONT TestIsValidCachePath/invalid_char_u2737=== CONT TestIsValidCachePath/invalid_char_e2738=== CONT TestIsValidCachePath/traversal_in_middle2739=== CONT TestIsValidCachePath/traversal_parent2740=== CONT TestIsValidCachePath/index.html2741=== CONT TestIsValidCachePath/nix-cache-info2742=== CONT TestIsValidCachePath/realisation2743=== CONT TestIsValidCachePath/log2744=== CONT TestIsValidCachePath/ls2745=== CONT TestIsValidCachePath/nar_uncompressed2746=== CONT TestIsValidCachePath/nar_bz22747=== CONT TestIsValidCachePath/nar_xz2748=== CONT TestIsValidCachePath/nar_zst2749=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2750--- PASS: TestIsValidCachePath (0.00s)2751 --- PASS: TestIsValidCachePath/narinfo (0.00s)2752 --- PASS: TestIsValidCachePath/short_hash (0.00s)2753 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2754 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2755 --- PASS: TestIsValidCachePath/empty (0.00s)2756 --- PASS: TestIsValidCachePath/random_path (0.00s)2757 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2758 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2759 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2760 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2761 --- PASS: TestIsValidCachePath/index.html (0.00s)2762 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2763 --- PASS: TestIsValidCachePath/realisation (0.00s)2764 --- PASS: TestIsValidCachePath/log (0.00s)2765 --- PASS: TestIsValidCachePath/ls (0.00s)2766 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2767 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2768 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2769 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2770 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2771=== CONT TestParseSingleRange/none2772=== CONT TestParseSingleRange/open-ended2773=== CONT TestParseSingleRange/start_far_past_EOF2774=== CONT TestParseSingleRange/start_past_EOF2775=== CONT TestParseSingleRange/single_byte2776=== CONT TestParseSingleRange/suffix_exceeds_size2777=== CONT TestParseSingleRange/suffix2778=== CONT TestParseSingleRange/end_clamped_to_size2779=== CONT TestParseSingleRange/multi-range_ignored2780=== CONT TestParseSingleRange/malformed_no_dash2781=== CONT TestParseSingleRange/closed2782=== CONT TestParseSingleRange/unknown_unit2783=== CONT TestParseSingleRange/malformed_end_before_start2784=== CONT TestParseSingleRange/malformed_both_empty2785--- PASS: TestParseSingleRange (0.00s)2786 --- PASS: TestParseSingleRange/none (0.00s)2787 --- PASS: TestParseSingleRange/open-ended (0.00s)2788 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2789 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2790 --- PASS: TestParseSingleRange/single_byte (0.00s)2791 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2792 --- PASS: TestParseSingleRange/suffix (0.00s)2793 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2794 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2795 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2796 --- PASS: TestParseSingleRange/closed (0.00s)2797 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2798 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2799 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2800=== CONT TestResolveDBConnectionString/flag_wins2801=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2802=== CONT TestResolveDBConnectionString/nothing_configured2803=== CONT TestResolveDBConnectionString/missing_file_is_an_error2804=== CONT TestResolveDBConnectionString/file_when_flag_empty2805=== CONT TestCacheConfigHandler/full_config,_no_issuer2806=== CONT TestCacheConfigHandler/no_signing_keys2807=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2808=== CONT TestCacheConfigHandler/no_cache_url_configured2809--- PASS: TestCacheConfigHandler (0.00s)2810 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2811 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2812 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2813 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2814=== CONT TestClientErrorHandling/InvalidStorePath2815--- PASS: TestResolveDBConnectionString (0.03s)2816 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2817 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2818 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2819 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2820 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)28212026/10/01 10:25:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete28222026/10/01 10:25:10 OK 20241026095416_initial_model.sql (388.08ms)28232026-10-01 10:25:10.372 UTC [42242] ERROR: relation "goose_db_version" does not exist at character 3628242026-10-01 10:25:10.372 UTC [42242] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC28252026/10/01 10:25:10 OK 20251210153512_drop_unused_gin_index.sql (17.2ms)28262026/10/01 10:25:10 OK 20241026095416_initial_model.sql (345.13ms)28272026/10/01 10:25:10 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZGZiNWUwNjEtNmQ4OC00MmZlLTk2OTUtNGRkYzUxNTRhNDhmLjc4MmFhNGNjLTU4NDMtNGMxMi1hM2E5LWE5MjBlNDNkMGRiMXgxNzkwODUwMzA4MjI4NDAxMDAw parts=1028282026/10/01 10:25:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete28292026/10/01 10:25:10 INFO Completed upload id=128302026/10/01 10:25:10 OK 20251210153512_drop_unused_gin_index.sql (25.75ms)28312026/10/01 10:25:10 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000028322026/10/01 10:25:10 INFO Received uploads request method=POST path=/api/pending_closures28332026/10/01 10:25:10 INFO Starting cleanup of old closures method=DELETE path=/api/closures28342026/10/01 10:25:10 INFO Aborted multipart uploads count=0 kept=028352026/10/01 10:25:10 OK 20251218171726_add_pins.sql (69.67ms)28362026/10/01 10:25:10 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=028372026/10/01 10:25:10 OK 20251218171726_add_pins.sql (71.9ms)28382026/10/01 10:25:10 INFO Vacuumed table table=pending_closures28392026/10/01 10:25:10 OK 20260628120000_add_object_size_and_stats.sql (81.9ms)28402026/10/01 10:25:10 WARN mTLS auth: subject not in bound subjects subject="CN=reader"28412026/10/01 10:25:10 WARN mTLS auth: subject not in bound subjects subject="CN=reader"2842--- PASS: TestService_NativeMTLS (7.38s)2843=== CONT TestClientErrorHandling/ServerNotAvailable28442026/10/01 10:25:10 INFO Vacuumed table table=pending_objects28452026/10/01 10:25:10 OK 20260628120000_add_object_size_and_stats.sql (64.39ms)28462026/10/01 10:25:10 OK 20260905000000_add_claims.sql (62.28ms)28472026/10/01 10:25:10 INFO Vacuumed table table=multipart_uploads28482026/10/01 10:25:10 OK 20260920000000_drop_claims.sql (44.89ms)28492026/10/01 10:25:10 OK 20260905000000_add_claims.sql (86.03ms)28502026/10/01 10:25:10 OK 20260923120000_add_pushes.sql (4.54ms)28512026/10/01 10:25:10 goose: successfully migrated database to version: 2026092312000028522026/10/01 10:25:10 OK 1_commit_pending_closure.sql (1.32ms)28532026/10/01 10:25:10 OK 2_object_stats_trigger.sql (243.17µs)28542026/10/01 10:25:10 OK 3_commit_push.sql (206.42µs)28552026/10/01 10:25:10 goose: up to current file version: 328562026/10/01 10:25:10 INFO Vacuumed table table=closures28572026/10/01 10:25:10 INFO Vacuumed table table=objects28582026/10/01 10:25:10 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000002859--- PASS: TestService_createPendingClosureHandler (9.53s)2860=== CONT TestClientErrorHandling/InvalidAuthToken28612026/10/01 10:25:10 OK 20260920000000_drop_claims.sql (119.21ms)28622026/10/01 10:25:10 OK 20260923120000_add_pushes.sql (30.92ms)28632026/10/01 10:25:10 goose: successfully migrated database to version: 2026092312000028642026/10/01 10:25:10 OK 1_commit_pending_closure.sql (1.38ms)28652026/10/01 10:25:10 OK 2_object_stats_trigger.sql (319.75µs)28662026/10/01 10:25:10 OK 3_commit_push.sql (279.71µs)28672026/10/01 10:25:10 goose: up to current file version: 328682026/10/01 10:25:10 OK 20241026095416_initial_model.sql (325.86ms)28692026/10/01 10:25:10 OK 20251210153512_drop_unused_gin_index.sql (8.98ms)28702026/10/01 10:25:10 OK 20251218171726_add_pins.sql (73.87ms)28712026/10/01 10:25:10 OK 20260628120000_add_object_size_and_stats.sql (84.37ms)28722026/10/01 10:25:11 OK 20260905000000_add_claims.sql (59.4ms)28732026/10/01 10:25:11 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present28742026/10/01 10:25:11 OK 20260920000000_drop_claims.sql (81.51ms)28752026/10/01 10:25:11 OK 20260923120000_add_pushes.sql (26.51ms)28762026/10/01 10:25:11 goose: successfully migrated database to version: 2026092312000028772026/10/01 10:25:11 OK 1_commit_pending_closure.sql (1.39ms)28782026/10/01 10:25:11 OK 2_object_stats_trigger.sql (328.83µs)28792026/10/01 10:25:11 OK 3_commit_push.sql (244.79µs)28802026/10/01 10:25:11 goose: up to current file version: 328812026/10/01 10:25:11 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=182.050882ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present28822026/10/01 10:25:11 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=437.946354ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present28832026-10-01 10:25:11.481 UTC [42257] ERROR: relation "goose_db_version" does not exist at character 3628842026-10-01 10:25:11.481 UTC [42257] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2885--- PASS: TestReadProxyDisabled (6.27s)2886=== CONT TestPush_RejectsBadRequests/no_roots28872026/10/01 10:25:11 INFO Received push request method=POST path=/api/pushes2888=== CONT TestPush_RejectsBadRequests/bad_root28892026/10/01 10:25:11 INFO Received push request method=POST path=/api/pushes2890=== CONT TestPush_RejectsBadRequests/root_not_in_objects28912026/10/01 10:25:11 INFO Received push request method=POST path=/api/pushes2892=== CONT TestPush_RejectsBadRequests/no_objects28932026/10/01 10:25:11 INFO Received push request method=POST path=/api/pushes2894=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2895--- PASS: TestPush_RejectsBadRequests (3.62s)2896 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2897 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2898 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2899 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2900=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected29012026/10/01 10:25:11 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]2902=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2903=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected29042026/10/01 10:25:11 WARN Authentication failed token_preview=eyJhbGciOi...RVzhws5DxA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2905=== CONT TestService_RequireScope_OIDC/builder_may_write2906=== CONT TestService_RequireScope_OIDC/static_token_may_admin2907=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2908=== CONT TestService_RequireScope_OIDC/writer_implies_read2909=== CONT TestService_RequireScope_OIDC/reader_may_read2910=== CONT TestService_RequireScope_OIDC/static_token_may_write2911=== CONT TestService_RequireScope_OIDC/ops_may_not_write2912=== CONT TestService_RequireScope_OIDC/reader_may_not_write2913=== CONT TestService_RequireScope_OIDC/ops_may_admin2914=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2915=== CONT TestServerTLSConfig/no_client_CA2916=== CONT TestServerTLSConfig/not_a_PEM_file2917--- PASS: TestService_AuthMiddleware_OIDC (5.69s)2918 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2919 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2920 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2921 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2922--- PASS: TestService_RequireScope_OIDC (6.22s)2923 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2924 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2925 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2926 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2927 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2928 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2929 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2930 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2931 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2932 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2933=== CONT TestServerTLSConfig/missing_CA_file2934--- PASS: TestServerTLSConfig (0.00s)2935 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2936 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.04s)2937 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2938=== NAME TestNARDeduplicationMetadataUploadBug2939 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-41045-2866623493/TestNARDeduplicationMetadataUploadBug2305194298/001/store/i2jyzm2x639h6zpjyz1gl6r59jamfry7-file1.txt29402026/10/01 10:25:11 INFO Received push request method=POST path=/api/pushes29412026/10/01 10:25:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)29422026/10/01 10:25:11 INFO Uploading i2jyzm2x639h6zpjyz1gl6r59jamfry7-file1.txt (160B)29432026/10/01 10:25:11 WARN Failed to register uploaded object key=i2jyzm2x639h6zpjyz1gl6r59jamfry7.ls error="server returned 404: 404 page not found\n"29442026/10/01 10:25:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign29452026/10/01 10:25:11 INFO Signed narinfos id=1 count=129462026/10/01 10:25:11 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"29472026/10/01 10:25:11 INFO Uploading 1 narinfos29482026/10/01 10:25:11 OK 20241026095416_initial_model.sql (195.51ms)29492026/10/01 10:25:11 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=809.331742ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present29502026/10/01 10:25:11 OK 20251210153512_drop_unused_gin_index.sql (14.29ms)29512026/10/01 10:25:11 INFO Received complete push request method=POST path=/api/pushes/1/complete29522026/10/01 10:25:11 WARN Failed to register uploaded object key=i2jyzm2x639h6zpjyz1gl6r59jamfry7.narinfo error="server returned 404: 404 page not found\n"29532026/10/01 10:25:11 INFO Upload complete. (202ms)29542026/10/01 10:25:11 OK 20251218171726_add_pins.sql (56.38ms)2955 metadata_upload_test.go:54: Retrieved narinfo from S3:2956 StorePath: /nix/var/nix/builds/nix-41045-2866623493/TestNARDeduplicationMetadataUploadBug2305194298/001/store/i2jyzm2x639h6zpjyz1gl6r59jamfry7-file1.txt2957 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2958 Compression: zstd2959 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2960 NarSize: 1602961 References: 2962 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2963 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2964 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2965 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}2966--- PASS: TestReadRedirectNar (5.95s)29672026/10/01 10:25:11 OK 20260628120000_add_object_size_and_stats.sql (32.76ms)2968=== NAME TestNARDeduplicationMetadataUploadBug2969 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-41045-2866623493/TestNARDeduplicationMetadataUploadBug2305194298/001/store/x8vpdqbidzwn75rb2ykpml2l41dr5awa-file2.txt29702026/10/01 10:25:12 OK 20260905000000_add_claims.sql (125.35ms)29712026/10/01 10:25:12 OK 20260920000000_drop_claims.sql (46.16ms)29722026/10/01 10:25:12 OK 20260923120000_add_pushes.sql (17.46ms)29732026/10/01 10:25:12 goose: successfully migrated database to version: 2026092312000029742026/10/01 10:25:12 OK 1_commit_pending_closure.sql (950µs)29752026/10/01 10:25:12 OK 2_object_stats_trigger.sql (538.17µs)29762026/10/01 10:25:12 OK 3_commit_push.sql (174.17µs)29772026/10/01 10:25:12 goose: up to current file version: 329782026/10/01 10:25:12 INFO Received push request method=POST path=/api/pushes29792026/10/01 10:25:12 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)29802026/10/01 10:25:12 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign29812026/10/01 10:25:12 INFO Signed narinfos id=2 count=129822026/10/01 10:25:12 INFO Uploading 1 narinfos29832026/10/01 10:25:12 WARN Failed to register uploaded object key=x8vpdqbidzwn75rb2ykpml2l41dr5awa.ls error="server returned 404: 404 page not found\n"29842026/10/01 10:25:12 INFO Received complete push request method=POST path=/api/pushes/2/complete29852026/10/01 10:25:12 WARN Failed to register uploaded object key=x8vpdqbidzwn75rb2ykpml2l41dr5awa.narinfo error="server returned 404: 404 page not found\n"29862026/10/01 10:25:12 INFO Upload complete. (141ms)2987 metadata_upload_test.go:76: Retrieved narinfo from S3:2988 StorePath: /nix/var/nix/builds/nix-41045-2866623493/TestNARDeduplicationMetadataUploadBug2305194298/001/store/x8vpdqbidzwn75rb2ykpml2l41dr5awa-file2.txt2989 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2990 Compression: zstd2991 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2992 NarSize: 1602993 References: 2994 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2995 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2996 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2997 {"version":1,"root":{"type":"regular","size":44}}2998--- PASS: TestNARDeduplicationMetadataUploadBug (7.78s)2999--- PASS: TestReadProxyRootRedirectsToIndexHTML (5.41s)30002026/10/01 10:25:12 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.68953705s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present30012026-10-01 10:25:12.771 UTC [42276] ERROR: relation "goose_db_version" does not exist at character 3630022026-10-01 10:25:12.771 UTC [42276] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC30032026/10/01 10:25:13 OK 20241026095416_initial_model.sql (285.75ms)30042026/10/01 10:25:13 OK 20251210153512_drop_unused_gin_index.sql (16.3ms)30052026/10/01 10:25:13 OK 20251218171726_add_pins.sql (71.26ms)30062026/10/01 10:25:13 OK 20260628120000_add_object_size_and_stats.sql (61.77ms)30072026/10/01 10:25:13 OK 20260905000000_add_claims.sql (86.94ms)30082026/10/01 10:25:13 OK 20260920000000_drop_claims.sql (60.85ms)30092026/10/01 10:25:13 OK 20260923120000_add_pushes.sql (10.71ms)30102026/10/01 10:25:13 goose: successfully migrated database to version: 2026092312000030112026/10/01 10:25:13 OK 1_commit_pending_closure.sql (923.75µs)30122026/10/01 10:25:13 OK 2_object_stats_trigger.sql (252.25µs)30132026/10/01 10:25:13 OK 3_commit_push.sql (199.08µs)30142026/10/01 10:25:13 goose: up to current file version: 330152026-10-01 10:25:13.486 UTC [42281] ERROR: relation "goose_db_version" does not exist at character 3630162026-10-01 10:25:13.486 UTC [42281] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC30172026-10-01 10:25:13.511 UTC [42282] ERROR: relation "goose_db_version" does not exist at character 3630182026-10-01 10:25:13.511 UTC [42282] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC30192026-10-01 10:25:13.865 UTC [42296] ERROR: relation "goose_db_version" does not exist at character 3630202026-10-01 10:25:13.865 UTC [42296] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC30212026/10/01 10:25:13 INFO Received uploads request method=POST path=/api/pending_closures30222026/10/01 10:25:13 OK 20241026095416_initial_model.sql (291.68ms)30232026/10/01 10:25:13 OK 20241026095416_initial_model.sql (308.39ms)30242026/10/01 10:25:13 OK 20251210153512_drop_unused_gin_index.sql (13.7ms)30252026/10/01 10:25:13 OK 20251210153512_drop_unused_gin_index.sql (13.82ms)30262026/10/01 10:25:13 OK 20251218171726_add_pins.sql (38.98ms)30272026/10/01 10:25:13 OK 20251218171726_add_pins.sql (53.21ms)30282026-10-01 10:25:13.973 UTC [42310] ERROR: relation "goose_db_version" does not exist at character 3630292026-10-01 10:25:13.973 UTC [42310] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC30302026/10/01 10:25:13 OK 20260628120000_add_object_size_and_stats.sql (34.9ms)30312026/10/01 10:25:14 OK 20260628120000_add_object_size_and_stats.sql (44.84ms)30322026/10/01 10:25:14 OK 20260905000000_add_claims.sql (58.89ms)30332026/10/01 10:25:14 OK 20260905000000_add_claims.sql (37.69ms)30342026/10/01 10:25:14 OK 20260920000000_drop_claims.sql (34.33ms)30352026/10/01 10:25:14 OK 20260920000000_drop_claims.sql (37.54ms)30362026/10/01 10:25:14 OK 20260923120000_add_pushes.sql (24.26ms)30372026/10/01 10:25:14 goose: successfully migrated database to version: 2026092312000030382026/10/01 10:25:14 OK 20260923120000_add_pushes.sql (24.58ms)30392026/10/01 10:25:14 goose: successfully migrated database to version: 2026092312000030402026/10/01 10:25:14 OK 1_commit_pending_closure.sql (1.11ms)30412026/10/01 10:25:14 OK 2_object_stats_trigger.sql (374.17µs)30422026/10/01 10:25:14 OK 1_commit_pending_closure.sql (1.53ms)30432026/10/01 10:25:14 OK 3_commit_push.sql (286.83µs)30442026/10/01 10:25:14 goose: up to current file version: 330452026/10/01 10:25:14 OK 2_object_stats_trigger.sql (302.42µs)30462026/10/01 10:25:14 OK 3_commit_push.sql (214.75µs)30472026/10/01 10:25:14 goose: up to current file version: 330482026/10/01 10:25:14 OK 20241026095416_initial_model.sql (164.69ms)30492026/10/01 10:25:14 OK 20251210153512_drop_unused_gin_index.sql (19.51ms)30502026/10/01 10:25:14 OK 20251218171726_add_pins.sql (53.81ms)30512026/10/01 10:25:14 OK 20260628120000_add_object_size_and_stats.sql (38.33ms)30522026/10/01 10:25:14 OK 20241026095416_initial_model.sql (273.43ms)30532026/10/01 10:25:14 OK 20251210153512_drop_unused_gin_index.sql (12.68ms)30542026/10/01 10:25:14 OK 20260905000000_add_claims.sql (113.74ms)30552026/10/01 10:25:14 OK 20251218171726_add_pins.sql (48ms)30562026/10/01 10:25:14 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30572026/10/01 10:25:14 OK 20260920000000_drop_claims.sql (95.08ms)30582026/10/01 10:25:14 OK 20260628120000_add_object_size_and_stats.sql (55ms)30592026/10/01 10:25:14 OK 20260923120000_add_pushes.sql (16.62ms)30602026/10/01 10:25:14 goose: successfully migrated database to version: 2026092312000030612026/10/01 10:25:14 OK 1_commit_pending_closure.sql (982.08µs)30622026/10/01 10:25:14 OK 2_object_stats_trigger.sql (228.92µs)30632026/10/01 10:25:14 OK 3_commit_push.sql (188.33µs)30642026/10/01 10:25:14 goose: up to current file version: 330652026/10/01 10:25:14 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=197.727414ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30662026/10/01 10:25:14 OK 20260905000000_add_claims.sql (119.31ms)30672026/10/01 10:25:14 INFO Received uploads request method=POST path=/api/pending_closures30682026/10/01 10:25:14 INFO Aborted multipart uploads count=0 kept=030692026/10/01 10:25:14 WARN Force mode enabled - objects will be deleted immediately without grace period30702026/10/01 10:25:14 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=030712026/10/01 10:25:14 INFO Vacuumed table table=pending_closures30722026/10/01 10:25:14 OK 20260920000000_drop_claims.sql (103.48ms)30732026/10/01 10:25:14 INFO Vacuumed table table=pending_objects30742026/10/01 10:25:14 INFO Vacuumed table table=multipart_uploads30752026/10/01 10:25:14 INFO Vacuumed table table=closures30762026/10/01 10:25:14 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=377.276201ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30772026/10/01 10:25:14 OK 20260923120000_add_pushes.sql (28.33ms)30782026/10/01 10:25:14 goose: successfully migrated database to version: 2026092312000030792026/10/01 10:25:14 OK 1_commit_pending_closure.sql (1.3ms)30802026/10/01 10:25:14 OK 2_object_stats_trigger.sql (292.33µs)30812026/10/01 10:25:14 OK 3_commit_push.sql (236.5µs)30822026/10/01 10:25:14 goose: up to current file version: 330832026/10/01 10:25:14 INFO Vacuumed table table=objects3084--- PASS: TestPendingClosureWriteTimeout (0.00s)3085 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)3086 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)3087 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)3088 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (6.02s)30892026/10/01 10:25:14 INFO Received uploads request method=POST path=/api/pending_closures30902026/10/01 10:25:14 INFO Aborted multipart uploads count=0 kept=030912026/10/01 10:25:14 WARN Force mode enabled - objects will be deleted immediately without grace period30922026/10/01 10:25:15 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=1 objects-deleted-after-grace-period=1 objects-failed-to-delete=030932026/10/01 10:25:15 INFO Vacuumed table table=pending_closures30942026/10/01 10:25:15 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=768.942516ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30952026/10/01 10:25:15 INFO Vacuumed table table=pending_objects30962026/10/01 10:25:15 INFO Vacuumed table table=multipart_uploads30972026/10/01 10:25:15 INFO Vacuumed table table=closures30982026/10/01 10:25:15 INFO Vacuumed table table=objects3099--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)3100 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (5.09s)3101 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (5.73s)31022026/10/01 10:25:15 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.707654553s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config31032026/10/01 10:25:16 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"31042026/10/01 10:25:16 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"31052026/10/01 10:25:17 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"31062026/10/01 10:25:17 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config31072026/10/01 10:25:17 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=181.825295ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config31082026/10/01 10:25:17 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=383.037146ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config31092026/10/01 10:25:18 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=729.989918ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config31102026/10/01 10:25:18 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.489768159s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config3111{"timestamp":"2026-10-01T10:25:19.973724Z","level":"ERROR","message":"Scanner cycle completed without a durable data usage snapshot","event":"scanner_persist_state","component":"scanner","subsystem":"runtime","cycle":4,"outcome":"NoUpdate","state":"usage_not_durable","target":"rustfs::scanner","filename":"crates/scanner/src/scanner.rs","line_number":2350,"threadName":"rustfs-worker","threadId":"ThreadId(3)"}31122026/10/01 10:25:20 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures31132026/10/01 10:25:20 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=213.562458ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures31142026/10/01 10:25:20 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=362.381344ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures31152026/10/01 10:25:21 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=804.730927ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures31162026/10/01 10:25:21 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.732616677s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures3117--- PASS: TestClientErrorHandling (0.00s)3118 --- PASS: TestClientErrorHandling/InvalidStorePath (5.26s)3119 --- PASS: TestClientErrorHandling/InvalidAuthToken (5.43s)3120 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.15s)3121PASS3122{"timestamp":"2026-10-01T10:25:23.698216Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:61821","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(6)"}31232026-10-01 10:25:23.984 UTC [41262] LOG: received smart shutdown request31242026-10-01 10:25:23.984 UTC [41262] LOG: background worker "logical replication launcher" (PID 41272) exited with exit code 131252026-10-01 10:25:23.990 UTC [41267] LOG: shutting down31262026-10-01 10:25:23.990 UTC [41267] LOG: checkpoint starting: shutdown immediate31272026-10-01 10:25:25.266 UTC [41267] LOG: checkpoint complete: wrote 12810 buffers (78.2%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 25 recycled; write=0.734 s, sync=0.501 s, total=1.277 s; sync files=28983, longest=0.001 s, average=0.001 s; distance=407873 kB, estimate=407873 kB; lsn=0/1A5DD6F8, redo lsn=0/1A5DD6F831282026-10-01 10:25:25.272 UTC [41262] LOG: database system is shut down3129Running OIDC tests...3130=== RUN TestAudienceForIssuer3131=== PAUSE TestAudienceForIssuer3132=== RUN TestGlobMatch3133=== PAUSE TestGlobMatch3134=== RUN TestValidateToken_ValidToken3135=== PAUSE TestValidateToken_ValidToken3136=== RUN TestValidateToken_WrongAudience3137=== PAUSE TestValidateToken_WrongAudience3138=== RUN TestValidateToken_Expired3139=== PAUSE TestValidateToken_Expired3140=== RUN TestValidateToken_BoundClaimsMismatch3141=== PAUSE TestValidateToken_BoundClaimsMismatch3142=== RUN TestValidateToken_BoundSubjectMismatch3143=== PAUSE TestValidateToken_BoundSubjectMismatch3144=== RUN TestValidateToken_MultipleProviders3145=== PAUSE TestValidateToken_MultipleProviders3146=== RUN TestValidateToken_NoMatchingProvider3147=== PAUSE TestValidateToken_NoMatchingProvider3148=== RUN TestValidateToken_KubernetesServiceAccount3149=== PAUSE TestValidateToken_KubernetesServiceAccount3150=== RUN TestNewValidator_KubernetesRequiresCA3151=== PAUSE TestNewValidator_KubernetesRequiresCA3152=== RUN TestValidateToken_KubernetesIssuerFromOwnToken3153=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken3154=== RUN TestPins_ReservedForMatchingRule3155=== PAUSE TestPins_ReservedForMatchingRule3156=== RUN TestPins_TopLevelShorthand3157=== PAUSE TestPins_TopLevelShorthand3158=== RUN TestPins_ConfigValidation3159=== PAUSE TestPins_ConfigValidation3160=== RUN TestScopes_LegacyProviderDefaultsToWrite3161=== PAUSE TestScopes_LegacyProviderDefaultsToWrite3162=== RUN TestScopes_Rules3163=== PAUSE TestScopes_Rules3164=== RUN TestScopes_ConfigValidation3165=== PAUSE TestScopes_ConfigValidation3166=== CONT TestAudienceForIssuer3167--- PASS: TestAudienceForIssuer (0.00s)3168=== CONT TestScopes_ConfigValidation3169=== CONT TestValidateToken_KubernetesServiceAccount3170=== CONT TestValidateToken_BoundClaimsMismatch3171=== CONT TestValidateToken_WrongAudience3172=== CONT TestValidateToken_MultipleProviders3173=== CONT TestValidateToken_NoMatchingProvider3174=== CONT TestPins_TopLevelShorthand3175=== CONT TestValidateToken_ValidToken3176=== CONT TestValidateToken_KubernetesIssuerFromOwnToken3177=== CONT TestPins_ReservedForMatchingRule3178--- PASS: TestScopes_ConfigValidation (0.00s)3179=== CONT TestGlobMatch3180=== RUN TestGlobMatch/foo_foo3181=== PAUSE TestGlobMatch/foo_foo3182=== RUN TestGlobMatch/foo_bar3183=== PAUSE TestGlobMatch/foo_bar3184=== RUN TestGlobMatch/*_3185=== PAUSE TestGlobMatch/*_3186=== RUN TestGlobMatch/*_anything3187=== PAUSE TestGlobMatch/*_anything3188=== RUN TestGlobMatch/foo*_foo3189=== PAUSE TestGlobMatch/foo*_foo3190=== RUN TestGlobMatch/foo*_foobar3191=== PAUSE TestGlobMatch/foo*_foobar3192=== RUN TestGlobMatch/foo*_bar3193=== PAUSE TestGlobMatch/foo*_bar3194=== RUN TestGlobMatch/*bar_bar3195=== PAUSE TestGlobMatch/*bar_bar3196=== RUN TestGlobMatch/*bar_foobar3197=== PAUSE TestGlobMatch/*bar_foobar3198=== RUN TestGlobMatch/*bar_foo3199=== PAUSE TestGlobMatch/*bar_foo3200=== RUN TestGlobMatch/foo*bar_foobar3201=== PAUSE TestGlobMatch/foo*bar_foobar3202=== RUN TestGlobMatch/foo*bar_foo123bar3203=== PAUSE TestGlobMatch/foo*bar_foo123bar3204=== RUN TestGlobMatch/foo*bar_foobarbaz3205=== PAUSE TestGlobMatch/foo*bar_foobarbaz3206=== RUN TestGlobMatch/*/*_foo/bar3207=== PAUSE TestGlobMatch/*/*_foo/bar3208=== RUN TestGlobMatch/*/*_foo3209=== PAUSE TestGlobMatch/*/*_foo3210=== RUN TestGlobMatch/refs/heads/*_refs/heads/main3211=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main3212=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.03213=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.03214=== RUN TestGlobMatch/refs/*/main_refs/heads/main3215=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main3216=== RUN TestGlobMatch/fo?_foo3217=== PAUSE TestGlobMatch/fo?_foo3218=== RUN TestGlobMatch/fo?_fo3219=== PAUSE TestGlobMatch/fo?_fo3220=== RUN TestGlobMatch/fo?_fooo3221=== PAUSE TestGlobMatch/fo?_fooo3222=== RUN TestGlobMatch/?oo_foo3223=== PAUSE TestGlobMatch/?oo_foo3224=== RUN TestGlobMatch/?oo_boo3225=== PAUSE TestGlobMatch/?oo_boo3226=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3227=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3228=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3229=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3230=== CONT TestGlobMatch/foo_foo3231=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3232=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3233=== CONT TestGlobMatch/?oo_boo3234=== CONT TestGlobMatch/?oo_foo3235=== CONT TestGlobMatch/fo?_fooo3236=== CONT TestGlobMatch/fo?_fo3237=== CONT TestGlobMatch/fo?_foo3238=== CONT TestGlobMatch/refs/*/main_refs/heads/main3239=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.03240=== CONT TestGlobMatch/refs/heads/*_refs/heads/main3241=== CONT TestGlobMatch/*/*_foo3242=== CONT TestGlobMatch/*/*_foo/bar3243=== CONT TestGlobMatch/foo*bar_foobarbaz3244=== CONT TestGlobMatch/foo*bar_foo123bar3245=== CONT TestGlobMatch/foo*bar_foobar3246=== CONT TestGlobMatch/*bar_foo3247=== CONT TestGlobMatch/*bar_foobar3248=== CONT TestGlobMatch/*bar_bar3249=== CONT TestGlobMatch/foo*_bar3250=== CONT TestGlobMatch/foo*_foobar3251=== CONT TestGlobMatch/foo*_foo3252=== CONT TestGlobMatch/*_anything3253=== CONT TestGlobMatch/*_3254=== CONT TestGlobMatch/foo_bar3255--- PASS: TestGlobMatch (0.00s)3256 --- PASS: TestGlobMatch/foo_foo (0.00s)3257 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)3258 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)3259 --- PASS: TestGlobMatch/?oo_boo (0.00s)3260 --- PASS: TestGlobMatch/?oo_foo (0.00s)3261 --- PASS: TestGlobMatch/fo?_fooo (0.00s)3262 --- PASS: TestGlobMatch/fo?_fo (0.00s)3263 --- PASS: TestGlobMatch/fo?_foo (0.00s)3264 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)3265 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)3266 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)3267 --- PASS: TestGlobMatch/*/*_foo (0.00s)3268 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)3269 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)3270 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)3271 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)3272 --- PASS: TestGlobMatch/*bar_foo (0.00s)3273 --- PASS: TestGlobMatch/*bar_foobar (0.00s)3274 --- PASS: TestGlobMatch/*bar_bar (0.00s)3275 --- PASS: TestGlobMatch/foo*_bar (0.00s)3276 --- PASS: TestGlobMatch/foo*_foobar (0.00s)3277 --- PASS: TestGlobMatch/foo*_foo (0.00s)3278 --- PASS: TestGlobMatch/*_anything (0.00s)3279 --- PASS: TestGlobMatch/*_ (0.00s)3280 --- PASS: TestGlobMatch/foo_bar (0.00s)3281=== CONT TestValidateToken_BoundSubjectMismatch32822026/10/01 10:25:26 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12332832026/10/01 10:25:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62088/oidc3284--- PASS: TestPins_ReservedForMatchingRule (0.04s)3285=== CONT TestNewValidator_KubernetesRequiresCA3286--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.05s)3287=== CONT TestValidateToken_Expired32882026/10/01 10:25:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62090/oidc3289--- PASS: TestValidateToken_BoundSubjectMismatch (0.07s)3290=== CONT TestScopes_Rules32912026/10/01 10:25:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62093/oidc32922026/10/01 10:25:26 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:62097/oidc32932026/10/01 10:25:26 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:62085/oidc3294--- PASS: TestValidateToken_WrongAudience (0.10s)3295=== CONT TestScopes_LegacyProviderDefaultsToWrite3296--- PASS: TestValidateToken_MultipleProviders (0.10s)3297=== CONT TestPins_ConfigValidation32982026/10/01 10:25:26 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:621003299--- PASS: TestPins_ConfigValidation (0.00s)33002026/10/01 10:25:26 http: TLS handshake error from 127.0.0.1:62095: remote error: tls: bad certificate3301--- PASS: TestNewValidator_KubernetesRequiresCA (0.06s)3302--- PASS: TestValidateToken_KubernetesServiceAccount (0.11s)33032026/10/01 10:25:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62102/oidc3304--- PASS: TestValidateToken_Expired (0.07s)33052026/10/01 10:25:26 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:62092/oidc3306--- PASS: TestValidateToken_NoMatchingProvider (0.16s)33072026/10/01 10:25:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62107/oidc33082026/10/01 10:25:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62108/oidc3309--- PASS: TestValidateToken_BoundClaimsMismatch (0.18s)3310--- PASS: TestPins_TopLevelShorthand (0.18s)33112026/10/01 10:25:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62111/oidc3312--- PASS: TestValidateToken_ValidToken (0.19s)33132026/10/01 10:25:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62113/oidc3314--- PASS: TestScopes_Rules (0.12s)33152026/10/01 10:25:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62115/oidc3316--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.11s)3317PASS3318Running hook tests...3319=== RUN TestSendPathsEmpty3320=== PAUSE TestSendPathsEmpty3321=== RUN TestQueueEnqueueAndFetch3322=== PAUSE TestQueueEnqueueAndFetch3323=== RUN TestQueueDeduplication3324=== PAUSE TestQueueDeduplication3325=== RUN TestQueueRemove3326=== PAUSE TestQueueRemove3327=== RUN TestQueueFetchBatchLimit3328=== PAUSE TestQueueFetchBatchLimit3329=== RUN TestQueueRetryMovesToBack3330=== PAUSE TestQueueRetryMovesToBack3331=== RUN TestQueueFetchRemoveLifecycle3332=== PAUSE TestQueueFetchRemoveLifecycle3333=== RUN TestQueueConcurrentWriters3334=== PAUSE TestQueueConcurrentWriters3335=== RUN TestQueueRemoveLargeClosure3336=== PAUSE TestQueueRemoveLargeClosure3337=== RUN TestServerClientIntegration3338=== PAUSE TestServerClientIntegration3339=== RUN TestServerQueueError3340=== PAUSE TestServerQueueError3341=== RUN TestGetListenerSocketActivation3342 server_test.go:210: === RUN TestGetListenerSocketActivation3343 --- PASS: TestGetListenerSocketActivation (0.00s)3344 PASS3345 3346--- PASS: TestGetListenerSocketActivation (0.01s)3347=== RUN TestDrainIsolatesPoisonPath3348=== PAUSE TestDrainIsolatesPoisonPath3349=== RUN TestRunNotBlockedByPoisonHead3350=== PAUSE TestRunNotBlockedByPoisonHead3351=== RUN TestDrainGivesUpWhenServerDown3352=== PAUSE TestDrainGivesUpWhenServerDown3353=== RUN TestFailedPathPrunedByLaterClosure3354=== PAUSE TestFailedPathPrunedByLaterClosure3355=== RUN TestWorkerUploadsAndRemoves3356=== PAUSE TestWorkerUploadsAndRemoves3357=== RUN TestWorkerSkipsGCdPaths3358=== PAUSE TestWorkerSkipsGCdPaths3359=== RUN TestWorkerPrunesClosureDeps3360=== PAUSE TestWorkerPrunesClosureDeps3361=== RUN TestDrainTimeout3362=== PAUSE TestDrainTimeout3363=== CONT TestSendPathsEmpty3364=== CONT TestServerQueueError3365=== CONT TestQueueRemove3366=== CONT TestQueueFetchBatchLimit3367=== CONT TestQueueDeduplication3368=== CONT TestQueueFetchRemoveLifecycle3369=== CONT TestQueueRetryMovesToBack3370=== CONT TestWorkerUploadsAndRemoves3371--- PASS: TestSendPathsEmpty (0.00s)3372=== CONT TestServerClientIntegration3373=== CONT TestQueueRemoveLargeClosure3374=== CONT TestQueueConcurrentWriters33752026/10/01 10:25:27 ERROR Failed to queue paths error="permission denied" count=13376--- PASS: TestServerQueueError (0.00s)3377=== CONT TestQueueEnqueueAndFetch3378--- PASS: TestServerClientIntegration (0.00s)3379=== CONT TestWorkerPrunesClosureDeps3380--- PASS: TestQueueFetchBatchLimit (0.01s)3381=== CONT TestDrainTimeout3382--- PASS: TestQueueRemove (0.01s)3383=== CONT TestRunNotBlockedByPoisonHead33842026/10/01 10:25:27 INFO Upload queue status pending=23385--- PASS: TestQueueEnqueueAndFetch (0.01s)3386=== CONT TestFailedPathPrunedByLaterClosure33872026/10/01 10:25:27 INFO Upload queue status pending=233882026/10/01 10:25:27 INFO Uploading batch count=133892026/10/01 10:25:27 INFO Uploading batch count=23390--- PASS: TestQueueRetryMovesToBack (0.01s)3391=== CONT TestDrainGivesUpWhenServerDown3392--- PASS: TestQueueDeduplication (0.01s)3393=== CONT TestWorkerSkipsGCdPaths3394--- PASS: TestQueueFetchRemoveLifecycle (0.01s)3395=== CONT TestDrainIsolatesPoisonPath33962026/10/01 10:25:27 INFO Uploading batch count=233972026/10/01 10:25:27 INFO Upload queue status pending=233982026/10/01 10:25:27 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-41045-2866623493/TestWorkerSkipsGCdPaths2672854476/002/nonexistent33992026/10/01 10:25:27 INFO Uploading batch count=134002026/10/01 10:25:27 INFO Upload queue status pending=334012026/10/01 10:25:27 INFO Uploading batch count=134022026/10/01 10:25:27 ERROR Upload failed error="upload failed" count=134032026/10/01 10:25:27 INFO Uploading batch count=134042026/10/01 10:25:27 ERROR Upload failed error="upload failed" count=134052026/10/01 10:25:27 INFO Uploading batch count=234062026/10/01 10:25:27 ERROR Upload failed error="upload failed" count=234072026/10/01 10:25:27 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-41045-2866623493/TestDrainGivesUpWhenServerDown2810244662/002/a34082026/10/01 10:25:27 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-41045-2866623493/TestDrainGivesUpWhenServerDown2810244662/002/b34092026/10/01 10:25:27 INFO Uploading batch count=134102026/10/01 10:25:27 INFO Uploading batch count=134112026/10/01 10:25:27 INFO Uploading batch count=434122026/10/01 10:25:27 ERROR Upload failed error="upload failed" count=434132026/10/01 10:25:27 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-41045-2866623493/TestDrainIsolatesPoisonPath791643247/002/bbb34142026/10/01 10:25:27 INFO Uploading batch count=134152026/10/01 10:25:27 ERROR Upload failed error="upload failed" count=134162026/10/01 10:25:27 INFO Uploading batch count=234172026/10/01 10:25:27 ERROR Upload failed error="upload failed" count=234182026/10/01 10:25:27 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-41045-2866623493/TestDrainGivesUpWhenServerDown2810244662/002/c34192026/10/01 10:25:27 INFO Uploading batch count=134202026/10/01 10:25:27 ERROR Upload failed error="upload failed" count=13421--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)34222026/10/01 10:25:27 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-41045-2866623493/TestDrainGivesUpWhenServerDown2810244662/002/d34232026/10/01 10:25:27 INFO Uploading batch count=134242026/10/01 10:25:27 ERROR Upload failed error="upload failed" count=134252026/10/01 10:25:27 ERROR Drain finished with paths left in queue remaining=134262026/10/01 10:25:27 INFO Uploading batch count=234272026/10/01 10:25:27 ERROR Upload failed error="upload failed" count=234282026/10/01 10:25:27 ERROR Upload failed, will retry later error="upload--- PASS: TestDrainIsolatesPoisonPath (0.01s)3429 failed" path=/nix/var/nix/builds/nix-41045-2866623493/TestDrainGivesUpWhenServerDown2810244662/002/e34302026/10/01 10:25:27 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-41045-2866623493/TestDrainGivesUpWhenServerDown2810244662/002/f34312026/10/01 10:25:27 ERROR Drain finished with paths left in queue remaining=103432--- PASS: TestDrainGivesUpWhenServerDown (0.02s)3433--- PASS: TestWorkerPrunesClosureDeps (0.03s)3434--- PASS: TestWorkerUploadsAndRemoves (0.03s)3435--- PASS: TestWorkerSkipsGCdPaths (0.03s)3436--- PASS: TestQueueRemoveLargeClosure (0.07s)3437--- PASS: TestQueueConcurrentWriters (0.08s)34382026/10/01 10:25:27 ERROR Upload failed error="context deadline exceeded" count=234392026/10/01 10:25:27 ERROR Drain finished with paths left in queue remaining=43440--- PASS: TestDrainTimeout (0.21s)34412026/10/01 10:25:28 INFO Uploading batch count=134422026/10/01 10:25:28 INFO Uploading batch count=134432026/10/01 10:25:28 INFO Uploading batch count=134442026/10/01 10:25:28 ERROR Upload failed error="upload failed" count=134452026/10/01 10:25:28 INFO Uploading batch count=134462026/10/01 10:25:28 ERROR Upload failed error="upload failed" count=134472026/10/01 10:25:28 INFO Uploading batch count=134482026/10/01 10:25:28 ERROR Upload failed error="upload failed" count=134492026/10/01 10:25:28 INFO Uploading batch count=134502026/10/01 10:25:28 ERROR Upload failed error="upload failed" count=134512026/10/01 10:25:28 ERROR Drain finished with paths left in queue remaining=13452--- PASS: TestRunNotBlockedByPoisonHead (1.02s)3453PASS