niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #274
· 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 TestDoServerRequestAttachesToken95=== CONT TestShellSplit96=== CONT TestSetClientTLSErrors97=== CONT TestStreamPushRequestLine98--- PASS: TestShellSplit (0.00s)99=== CONT TestStreamPushGivesUpOnDeadServer100=== CONT TestStreamPushIsolatesFailures101=== CONT TestStreamPushBatchesUnderLoad102=== CONT TestStreamPushReportsEveryPath1032026/09/28 03:27:22 ERROR Upload failed error="bad path" count=3104=== CONT TestShellSplitErrors105--- PASS: TestShellSplitErrors (0.00s)106=== CONT TestClientSignaturesByStorePath107=== CONT TestSetClientTLS108--- PASS: TestClientSignaturesByStorePath (0.00s)109=== CONT TestStreamPushReportsSignatures1102026/09/28 03:27:22 ERROR Upload failed error="connection refused" count=20111=== CONT TestSetClientTLSDoesNotMutateDefaultTransport1122026/09/28 03:27:22 ERROR Server seems unavailable, giving up on batch untried=17113--- PASS: TestStreamPushIsolatesFailures (0.00s)114=== CONT TestScriptTokenCachesUntilRefresh115--- PASS: TestStreamPushReportsEveryPath (0.00s)116=== CONT TestScriptTokenEmptyCommand117--- PASS: TestScriptTokenEmptyCommand (0.00s)118=== CONT TestScriptTokenScriptFails1192026/09/28 03:27:22 ERROR Upload failed error=boom count=1120--- PASS: TestStreamPushReportsSignatures (0.00s)121=== CONT TestScriptTokenBadJSON1222026/09/28 03:27:22 ERROR Upload failed error=boom count=1123--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)124=== CONT TestScriptTokenEmptyToken125=== RUN TestSetClientTLSErrors/missing_cert_file126=== PAUSE TestSetClientTLSErrors/missing_cert_file127=== RUN TestSetClientTLSErrors/missing_key_file128=== PAUSE TestSetClientTLSErrors/missing_key_file129=== RUN TestSetClientTLSErrors/missing_ca_file130=== PAUSE TestSetClientTLSErrors/missing_ca_file131=== RUN TestSetClientTLSErrors/invalid_ca_file132=== PAUSE TestSetClientTLSErrors/invalid_ca_file133=== CONT TestEncodeNixBase32WithRealHash134--- PASS: TestEncodeNixBase32WithRealHash (0.00s)135=== CONT TestDoWithRetry_BodyReplayedViaGetBody136--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)137=== CONT TestResolveStorePath138--- PASS: TestDoServerRequestAttachesToken (0.01s)139=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess140--- PASS: TestScriptTokenScriptFails (0.01s)141=== CONT TestRateLimiterFeedback1422026/09/28 03:27:22 WARN Rate limiter enabled after throttle name=server-test rate=5143=== RUN TestRateLimiterFeedback/429_enables_limiter144=== PAUSE TestRateLimiterFeedback/429_enables_limiter145=== RUN TestRateLimiterFeedback/503_enables_limiter146=== PAUSE TestRateLimiterFeedback/503_enables_limiter147=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter148=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter149=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter150=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter151=== CONT TestPathInfoCACompatibility152=== RUN TestPathInfoCACompatibility/null_ca_field153=== PAUSE TestPathInfoCACompatibility/null_ca_field154=== RUN TestPathInfoCACompatibility/old_string_format_-_text155=== RUN TestSetClientTLS/rejects_connection_without_client_cert156=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert157=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA158=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA159=== RUN TestSetClientTLS/preserves_debug_logging_transport160=== PAUSE TestSetClientTLS/preserves_debug_logging_transport161=== CONT TestParsePathInfoJSONMultiplePaths162=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths163=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths164=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths165=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths166=== CONT TestParsePathInfoJSON167=== RUN TestParsePathInfoJSON/Nix_format168=== PAUSE TestParsePathInfoJSON/Nix_format169=== RUN TestParsePathInfoJSON/Lix_format170=== PAUSE TestParsePathInfoJSON/Lix_format171=== RUN TestParsePathInfoJSON/empty_input172=== PAUSE TestParsePathInfoJSON/empty_input173=== RUN TestParsePathInfoJSON/whitespace_only174=== PAUSE TestParsePathInfoJSON/whitespace_only175=== RUN TestParsePathInfoJSON/invalid_JSON176=== PAUSE TestParsePathInfoJSON/invalid_JSON177--- PASS: TestResolveStorePath (0.00s)178=== CONT TestPathInfoHashCompatibility179=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)180=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)181=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon182=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon183=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI184=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI185=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512186=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512187=== CONT TestGetStorePathHash188=== RUN TestGetStorePathHash/valid_store_path189=== PAUSE TestGetStorePathHash/valid_store_path190=== RUN TestGetStorePathHash/basename_without_hyphen_should_error191=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error192=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error193=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error194=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error195=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error196=== CONT TestConvertHashToNix32197=== RUN TestConvertHashToNix32/SRI_format_to_Nix32198=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32199=== RUN TestConvertHashToNix32/already_Nix32_format200=== PAUSE TestConvertHashToNix32/already_Nix32_format201=== RUN TestConvertHashToNix32/invalid_format202=== PAUSE TestConvertHashToNix32/invalid_format203=== CONT TestUploadMultipart_SupersededByPeer204=== RUN TestUploadMultipart_SupersededByPeer/exists205=== PAUSE TestUploadMultipart_SupersededByPeer/exists206=== RUN TestUploadMultipart_SupersededByPeer/missing207=== PAUSE TestUploadMultipart_SupersededByPeer/missing208=== CONT TestEncodeNixBase32209=== RUN TestEncodeNixBase32/test_string_hash210=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text211=== PAUSE TestEncodeNixBase32/test_string_hash212=== CONT TestDumpPathWriterError213=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive214=== RUN TestEncodeNixBase32/empty_input215=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive2162026/09/28 03:27:22 WARN Rate limiter enabled after throttle name=server-test rate=5217=== RUN TestPathInfoCACompatibility/new_structured_format_-_text218=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text219=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method2202026/09/28 03:27:22 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:63469221=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method222=== PAUSE TestEncodeNixBase32/empty_input223=== CONT TestDumpPathSingleFile224=== CONT TestDumpPathMatchesNix2252026/09/28 03:27:22 WARN Rate limiter backed off name=server-test rate=52262026/09/28 03:27:22 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:63469227--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)228=== CONT TestFileTokenMissing229--- PASS: TestFileTokenMissing (0.00s)230=== CONT TestScriptTokenNoExpiryRerunsEveryCall231--- PASS: TestScriptTokenBadJSON (0.01s)232=== CONT TestFileTokenEmpty233--- PASS: TestScriptTokenEmptyToken (0.01s)234=== CONT TestFileTokenReadsAndCaches235--- PASS: TestFileTokenEmpty (0.00s)236=== CONT TestFilterOversizedClosures237--- PASS: TestFileTokenReadsAndCaches (0.00s)238=== CONT TestPartSizeForNAR239=== RUN TestPartSizeForNAR/zero_stays_at_minimum240=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum241=== RUN TestPartSizeForNAR/small_stays_at_minimum242=== PAUSE TestPartSizeForNAR/small_stays_at_minimum243=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum244=== RUN TestFilterOversizedClosures/no_limit_keeps_everything245=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum246=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts247=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts248=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything249=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped250=== RUN TestPartSizeForNAR/1_TiB251=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped252=== RUN TestFilterOversizedClosures/all_closures_skipped253=== PAUSE TestFilterOversizedClosures/all_closures_skipped254=== PAUSE TestPartSizeForNAR/1_TiB255=== CONT TestUploadMultipart_PartsInParallel256=== RUN TestPartSizeForNAR/5_TiB_S3_max_object257=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object258=== RUN TestPartSizeForNAR/capped_at_5_GiB259=== PAUSE TestPartSizeForNAR/capped_at_5_GiB260=== CONT TestCaseHackSuffix261--- PASS: TestStreamPushRequestLine (0.02s)262=== CONT TestStaticToken263--- PASS: TestStaticToken (0.00s)264=== CONT TestRegisterUploadedObjectReusesConnections265--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)266=== CONT TestSetClientTLSErrors/missing_cert_file267=== CONT TestSetClientTLSErrors/missing_ca_file268=== CONT TestSetClientTLSErrors/invalid_ca_file269=== CONT TestSetClientTLSErrors/missing_key_file270=== CONT TestRateLimiterFeedback/429_enables_limiter271--- PASS: TestSetClientTLSErrors (0.00s)272 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)273 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)274 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)275 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)2762026/09/28 03:27:22 WARN Rate limiter enabled after throttle name=server-test rate=52772026/09/28 03:27:22 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:635442782026/09/28 03:27:22 WARN Rate limiter backed off name=server-test rate=5279=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter280=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter281=== CONT TestRateLimiterFeedback/503_enables_limiter2822026/09/28 03:27:22 WARN Rate limiter enabled after throttle name=server-test rate=52832026/09/28 03:27:22 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:635502842026/09/28 03:27:22 WARN Rate limiter backed off name=server-test rate=5285--- PASS: TestRateLimiterFeedback (0.00s)286 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)287 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)288 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)289 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)290=== CONT TestSetClientTLS/rejects_connection_without_client_cert291--- PASS: TestDumpPathWriterError (0.04s)292=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths293=== CONT TestSetClientTLS/preserves_debug_logging_transport294=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA295--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)296=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths297--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)298 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)299 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)300=== CONT TestParsePathInfoJSON/Nix_format301=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)302=== CONT TestGetStorePathHash/valid_store_path303=== CONT TestParsePathInfoJSON/invalid_JSON304=== CONT TestParsePathInfoJSON/whitespace_only305=== CONT TestParsePathInfoJSON/empty_input306=== CONT TestParsePathInfoJSON/Lix_format307--- PASS: TestParsePathInfoJSON (0.00s)308 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)309 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)310 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)311 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)312 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)313=== CONT TestConvertHashToNix32/SRI_format_to_Nix32314=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512315=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI316=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon317--- PASS: TestPathInfoHashCompatibility (0.00s)318 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)319 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)320 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)321 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)322=== CONT TestUploadMultipart_SupersededByPeer/exists323--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)324=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error325=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error326=== CONT TestGetStorePathHash/basename_without_hyphen_should_error327--- PASS: TestGetStorePathHash (0.00s)328 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)329 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)330 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)331 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)332=== CONT TestConvertHashToNix32/invalid_format333=== CONT TestConvertHashToNix32/already_Nix32_format334--- PASS: TestConvertHashToNix32 (0.00s)335 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)336 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)337 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)338=== CONT TestUploadMultipart_SupersededByPeer/missing339=== CONT TestPathInfoCACompatibility/new_structured_format_-_text340--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)341 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)342 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)343=== CONT TestPathInfoCACompatibility/null_ca_field344=== CONT TestEncodeNixBase32/test_string_hash345=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive346=== CONT TestPathInfoCACompatibility/old_string_format_-_text347=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method348=== CONT TestEncodeNixBase32/empty_input349--- PASS: TestEncodeNixBase32 (0.00s)350 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)351 --- PASS: TestEncodeNixBase32/empty_input (0.00s)352=== CONT TestFilterOversizedClosures/no_limit_keeps_everything353=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3542026/09/28 03:27:22 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=2000355=== CONT TestPartSizeForNAR/zero_stays_at_minimum356=== CONT TestPartSizeForNAR/1_TiB357=== CONT TestPartSizeForNAR/capped_at_5_GiB358=== CONT TestPartSizeForNAR/5_TiB_S3_max_object359--- PASS: TestPathInfoCACompatibility (0.00s)360 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)361 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)362 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)363 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)364 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)365=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum366=== CONT TestFilterOversizedClosures/all_closures_skipped367=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts368=== CONT TestPartSizeForNAR/small_stays_at_minimum369--- PASS: TestPartSizeForNAR (0.00s)370 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)371 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)372 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)373 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)374 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)375 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)376 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)3772026/09/28 03:27:22 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=50378--- PASS: TestFilterOversizedClosures (0.00s)379 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)380 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)381 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)3822026/09/28 03:27:22 http: TLS handshake error from 127.0.0.1:63552: remote error: tls: bad certificate383--- PASS: TestSetClientTLS (0.01s)384 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)385 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)386 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)387--- PASS: TestDumpPathSingleFile (0.05s)388--- PASS: TestCaseHackSuffix (0.05s)389--- PASS: TestDumpPathMatchesNix (0.07s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestUploadMultipart_PartsInParallel (0.61s)392--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)393PASS394Running server tests...395The files belonging to this database system will be owned by user "_nixbld1".396This user must also own the server process.397398The database cluster will be initialized with locale "C".399The default database encoding has accordingly been set to "SQL_ASCII".400The default text search configuration will be set to "english".401402Data page checksums are enabled.403404creating directory /nix/var/nix/builds/nix-34546-2893374115/postgres256274091/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-34546-2893374115/postgres256274091/data -l logfile start4214222026-09-28 03:27:25.994 UTC [34758] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4232026-09-28 03:27:25.994 UTC [34758] LOG: listening on Unix socket "/nix/var/nix/builds/nix-34546-2893374115/postgres256274091/.s.PGSQL.5432"4242026-09-28 03:27:25.996 UTC [34765] LOG: database system was shut down at 2026-09-28 03:27:25 UTC4252026-09-28 03:27:25.997 UTC [34758] LOG: database system is ready to accept connections426/nix/var/nix/builds/nix-34546-2893374115/postgres256274091:5432 - accepting connections427{"timestamp":"2026-09-28T03:27:28.052987Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"4d63d950-3626-46dd-950d-f2bbb9d6612f","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":2,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":463,"threadName":"rustfs-worker","threadId":"ThreadId(3)"}428=== RUN TestService_AuthMiddleware429=== PAUSE TestService_AuthMiddleware430=== RUN TestService_AuthMiddleware_MTLSProxyHeader431=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader432=== RUN TestService_AuthMiddleware_MTLSBoundSubjects433=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects434=== RUN TestService_ReadAuthMiddleware435=== PAUSE TestService_ReadAuthMiddleware436=== RUN TestService_AuthMiddleware_OIDC437=== PAUSE TestService_AuthMiddleware_OIDC438=== RUN TestService_RequireScope_OIDC439=== PAUSE TestService_RequireScope_OIDC440=== RUN TestService_ReadScope_PublicByDefault441=== PAUSE TestService_ReadScope_PublicByDefault442=== RUN TestCacheConfigHandler443=== PAUSE TestCacheConfigHandler444=== RUN TestCacheStatsHandler445=== PAUSE TestCacheStatsHandler446=== RUN TestClientCADerivations447=== PAUSE TestClientCADerivations448=== RUN TestClientErrorHandling449=== PAUSE TestClientErrorHandling450=== RUN TestClientIntegration451=== PAUSE TestClientIntegration452=== RUN TestClientMultipleUploads453=== PAUSE TestClientMultipleUploads454=== RUN TestClientWithDependencies455=== PAUSE TestClientWithDependencies456=== RUN TestClientSharedPathCommittedMidPush457=== PAUSE TestClientSharedPathCommittedMidPush458=== RUN TestPinProtectsFromGC459=== PAUSE TestPinProtectsFromGC460=== RUN TestClientPushesUseOnePush461=== PAUSE TestClientPushesUseOnePush462=== RUN TestClientFallsBackToClosures463=== PAUSE TestClientFallsBackToClosures464=== RUN TestResolveDBConnectionString465=== PAUSE TestResolveDBConnectionString466=== RUN TestLeadElectsOneAndHandsOver467=== PAUSE TestLeadElectsOneAndHandsOver468=== RUN TestLeadIncumbentWinsAfterRestart4692026-09-28 03:27:28.476 UTC [34794] ERROR: relation "goose_db_version" does not exist at character 364702026-09-28 03:27:28.476 UTC [34794] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4712026/09/28 03:27:28 OK 20241026095416_initial_model.sql (3.84ms)4722026/09/28 03:27:28 OK 20251210153512_drop_unused_gin_index.sql (497.88µs)4732026/09/28 03:27:28 OK 20251218171726_add_pins.sql (843µs)4742026/09/28 03:27:28 OK 20260628120000_add_object_size_and_stats.sql (842.21µs)4752026/09/28 03:27:28 OK 20260905000000_add_claims.sql (936.79µs)4762026/09/28 03:27:28 OK 20260920000000_drop_claims.sql (591.79µs)4772026/09/28 03:27:28 OK 20260923120000_add_pushes.sql (477.08µs)4782026/09/28 03:27:28 goose: successfully migrated database to version: 202609231200004792026/09/28 03:27:28 OK 1_commit_pending_closure.sql (926.71µs)4802026/09/28 03:27:28 OK 2_object_stats_trigger.sql (216.92µs)4812026/09/28 03:27:28 OK 3_commit_push.sql (216.04µs)4822026/09/28 03:27:28 goose: up to current file version: 34832026/09/28 03:27:28 INFO lead: acquired remote=192.0.2.1:12344842026/09/28 03:27:29 INFO lead: released remote=192.0.2.1:12344852026/09/28 03:27:29 INFO lead: acquired remote=192.0.2.1:12344862026/09/28 03:27:29 INFO lead: released remote=192.0.2.1:1234487--- PASS: TestLeadIncumbentWinsAfterRestart (1.04s)488=== RUN TestLeadEndsOnShutdown489=== PAUSE TestLeadEndsOnShutdown490=== RUN TestGCAdvisoryLockBlocksConcurrentRun4912026-09-28 03:27:29.253 UTC [34820] ERROR: relation "goose_db_version" does not exist at character 364922026-09-28 03:27:29.253 UTC [34820] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4932026/09/28 03:27:29 OK 20241026095416_initial_model.sql (3.45ms)4942026/09/28 03:27:29 OK 20251210153512_drop_unused_gin_index.sql (501.75µs)4952026/09/28 03:27:29 OK 20251218171726_add_pins.sql (897.08µs)4962026/09/28 03:27:29 OK 20260628120000_add_object_size_and_stats.sql (873.63µs)4972026/09/28 03:27:29 OK 20260905000000_add_claims.sql (970.38µs)4982026/09/28 03:27:29 OK 20260920000000_drop_claims.sql (570.75µs)4992026/09/28 03:27:29 OK 20260923120000_add_pushes.sql (400.42µs)5002026/09/28 03:27:29 goose: successfully migrated database to version: 202609231200005012026/09/28 03:27:29 OK 1_commit_pending_closure.sql (796.54µs)5022026/09/28 03:27:29 OK 2_object_stats_trigger.sql (192.67µs)5032026/09/28 03:27:29 OK 3_commit_push.sql (175.25µs)5042026/09/28 03:27:29 goose: up to current file version: 3505--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.13s)506=== RUN TestGCBugBareHashReferences507=== PAUSE TestGCBugBareHashReferences508=== RUN TestGCMetrics509=== PAUSE TestGCMetrics510=== RUN TestGCTaskStore_StartNew511=== PAUSE TestGCTaskStore_StartNew512=== RUN TestGCTaskStore_DeduplicateSameParams513=== PAUSE TestGCTaskStore_DeduplicateSameParams514=== RUN TestGCTaskStore_ConflictDifferentParams515=== PAUSE TestGCTaskStore_ConflictDifferentParams516=== RUN TestGCTaskStore_GetEmpty517=== PAUSE TestGCTaskStore_GetEmpty518=== RUN TestGCTaskStore_GetReturnsLatest519=== PAUSE TestGCTaskStore_GetReturnsLatest520=== RUN TestGCTaskStore_CompletedAllowsNewTask521=== PAUSE TestGCTaskStore_CompletedAllowsNewTask522=== RUN TestGCTaskStore_PhaseUpdates523=== PAUSE TestGCTaskStore_PhaseUpdates524=== RUN TestGCTaskStore_Fail525=== PAUSE TestGCTaskStore_Fail526=== RUN TestGracefulShutdownDrainsInflight527=== PAUSE TestGracefulShutdownDrainsInflight528=== RUN TestService_healthCheckHandler529=== PAUSE TestService_healthCheckHandler530=== RUN TestService_readinessHandler531=== PAUSE TestService_readinessHandler532=== RUN TestGenerateLandingPage533=== PAUSE TestGenerateLandingPage534=== RUN TestCacheConfigHandlerMaxNarSize535=== PAUSE TestCacheConfigHandlerMaxNarSize536=== RUN TestCreatePendingClosureRejectsOversizedNAR537=== PAUSE TestCreatePendingClosureRejectsOversizedNAR538=== RUN TestNARDeduplicationMetadataUploadBug539=== PAUSE TestNARDeduplicationMetadataUploadBug540=== RUN TestMetricsInventory541=== PAUSE TestMetricsInventory542=== RUN TestService_NativeMTLS543=== PAUSE TestService_NativeMTLS544=== RUN TestServerTLSConfig545=== PAUSE TestServerTLSConfig546=== RUN TestMultipartCleanup547=== PAUSE TestMultipartCleanup548=== RUN TestObjectStatsTrigger549=== PAUSE TestObjectStatsTrigger550=== RUN TestOrphanedObjectsGC551=== PAUSE TestOrphanedObjectsGC552=== RUN TestOrphanedObjectsGCStressTest553=== PAUSE TestOrphanedObjectsGCStressTest554=== RUN TestResurrectedObjectNotDeleted555=== PAUSE TestResurrectedObjectNotDeleted556=== RUN TestCreatePin_ReservedPins557=== PAUSE TestCreatePin_ReservedPins558=== RUN TestParseSingleRange559=== PAUSE TestParseSingleRange560=== RUN TestProxyHeadersOnlyTrustedOnSocket561=== PAUSE TestProxyHeadersOnlyTrustedOnSocket562=== RUN TestIsValidCachePath563=== PAUSE TestIsValidCachePath564=== RUN TestReadProxyNarinfo565=== PAUSE TestReadProxyNarinfo566=== RUN TestReadProxyNarinfoAlreadyDecompressed567=== PAUSE TestReadProxyNarinfoAlreadyDecompressed568=== RUN TestReadProxyNarStreaming569=== PAUSE TestReadProxyNarStreaming570=== RUN TestReadProxy404571=== PAUSE TestReadProxy404572=== RUN TestReadProxyInvalidPath573=== PAUSE TestReadProxyInvalidPath574=== RUN TestReadProxyHead575=== PAUSE TestReadProxyHead576=== RUN TestReadProxyConditionalGet577=== PAUSE TestReadProxyConditionalGet578=== RUN TestReadProxyRootRedirectsToIndexHTML579=== PAUSE TestReadProxyRootRedirectsToIndexHTML580=== RUN TestReadProxyDisabled581=== PAUSE TestReadProxyDisabled582=== RUN TestReadRedirectNar583=== PAUSE TestReadRedirectNar584=== RUN TestReadRedirectKeepsNarinfoProxied585=== PAUSE TestReadRedirectKeepsNarinfoProxied586=== RUN TestReadProxyRangeRequest587=== PAUSE TestReadProxyRangeRequest588=== RUN TestReadRedirectUsesPublicS3URL589=== PAUSE TestReadRedirectUsesPublicS3URL590=== RUN TestPush_OverlappingRootsStoreOneRowPerKey591=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey592=== RUN TestPush_CompleteCommitsEveryRoot593=== PAUSE TestPush_CompleteCommitsEveryRoot594=== RUN TestPush_CommitFailsWhenSkippedKeyWasCollected595=== PAUSE TestPush_CommitFailsWhenSkippedKeyWasCollected596=== RUN TestPush_RejectsBadRequests597=== PAUSE TestPush_RejectsBadRequests598=== RUN TestPush_SignsNarinfosOfItsPendingObjects599=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects600=== RUN TestRedundantMultipartUpload601=== PAUSE TestRedundantMultipartUpload602=== RUN TestCompleteMultipartUpload_ErrorButObjectExists603=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists604=== RUN TestCompletedNarNotReofferedAcrossClosures605=== PAUSE TestCompletedNarNotReofferedAcrossClosures606=== RUN TestPresignedUploadRegisteredBeforeCommit607=== PAUSE TestPresignedUploadRegisteredBeforeCommit608=== RUN TestService_Rustfstest609=== PAUSE TestService_Rustfstest610=== RUN TestParseSize611=== PAUSE TestParseSize612=== RUN TestSkippedUploadsHandler613=== PAUSE TestSkippedUploadsHandler614=== RUN TestSystemdListenerNotActivated615--- PASS: TestSystemdListenerNotActivated (0.00s)616=== RUN TestWatchdogBeatsWhenHealthy617--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)618=== RUN TestWatchdogSkipsWhenUnhealthy6192026/09/28 03:27:29 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6202026/09/28 03:27:29 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6212026/09/28 03:27:29 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6222026/09/28 03:27:29 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6232026/09/28 03:27:29 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6242026/09/28 03:27:29 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6252026/09/28 03:27:29 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6262026/09/28 03:27:29 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6272026/09/28 03:27:29 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"628--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)629=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle630=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle631=== RUN TestProxyWriteTimeout632=== PAUSE TestProxyWriteTimeout633=== RUN TestIsValidUploadKey634=== PAUSE TestIsValidUploadKey635=== RUN TestUploadHandlersRejectInvalidKeys636=== PAUSE TestUploadHandlersRejectInvalidKeys637=== RUN TestUploadHandlersRejectOversizedBody638=== PAUSE TestUploadHandlersRejectOversizedBody639=== RUN TestService_cleanupPendingClosuresHandler640=== PAUSE TestService_cleanupPendingClosuresHandler641=== RUN TestService_createPendingClosureHandler642=== PAUSE TestService_createPendingClosureHandler643=== RUN TestService_verifyS3Integrity644=== PAUSE TestService_verifyS3Integrity645=== RUN TestCompleteMultipartUnregistered646=== PAUSE TestCompleteMultipartUnregistered647=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT648=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT649=== CONT TestCompleteMultipartUpload_ErrorButObjectExists650=== CONT TestService_AuthMiddleware651=== CONT TestCacheConfigHandlerMaxNarSize652=== CONT TestResolveDBConnectionString653=== CONT TestGCTaskStore_GetReturnsLatest654--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)655=== CONT TestGenerateLandingPage656=== CONT TestReadProxyNarStreaming657=== CONT TestObjectStatsTrigger658=== CONT TestClientFallsBackToClosures659=== CONT TestMultipartCleanup660=== CONT TestClientPushesUseOnePush661--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)662=== CONT TestOrphanedObjectsGC663=== RUN TestResolveDBConnectionString/flag_wins664=== PAUSE TestResolveDBConnectionString/flag_wins665=== RUN TestResolveDBConnectionString/file_when_flag_empty666=== PAUSE TestResolveDBConnectionString/file_when_flag_empty667=== RUN TestResolveDBConnectionString/missing_file_is_an_error668=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error669=== RUN TestResolveDBConnectionString/PGHOST_allows_empty670=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty671=== RUN TestResolveDBConnectionString/nothing_configured672=== PAUSE TestResolveDBConnectionString/nothing_configured673=== CONT TestPinProtectsFromGC674--- PASS: TestGenerateLandingPage (0.01s)675=== CONT TestClientSharedPathCommittedMidPush6762026-09-28 03:27:29.882 UTC [34850] ERROR: relation "goose_db_version" does not exist at character 366772026-09-28 03:27:29.882 UTC [34850] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6782026-09-28 03:27:29.883 UTC [34849] ERROR: relation "goose_db_version" does not exist at character 366792026-09-28 03:27:29.883 UTC [34849] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6802026-09-28 03:27:29.884 UTC [34851] ERROR: relation "goose_db_version" does not exist at character 366812026-09-28 03:27:29.884 UTC [34851] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6822026-09-28 03:27:29.884 UTC [34853] ERROR: relation "goose_db_version" does not exist at character 366832026-09-28 03:27:29.884 UTC [34853] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6842026-09-28 03:27:29.884 UTC [34852] ERROR: relation "goose_db_version" does not exist at character 366852026-09-28 03:27:29.884 UTC [34852] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6862026-09-28 03:27:29.884 UTC [34854] ERROR: relation "goose_db_version" does not exist at character 366872026-09-28 03:27:29.884 UTC [34854] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6882026-09-28 03:27:29.886 UTC [34856] ERROR: relation "goose_db_version" does not exist at character 366892026-09-28 03:27:29.886 UTC [34856] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6902026-09-28 03:27:29.887 UTC [34857] ERROR: relation "goose_db_version" does not exist at character 366912026-09-28 03:27:29.887 UTC [34857] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6922026-09-28 03:27:29.887 UTC [34858] ERROR: relation "goose_db_version" does not exist at character 366932026-09-28 03:27:29.887 UTC [34858] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6942026-09-28 03:27:29.888 UTC [34855] ERROR: relation "goose_db_version" does not exist at character 366952026-09-28 03:27:29.888 UTC [34855] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6962026/09/28 03:27:29 OK 20241026095416_initial_model.sql (8ms)6972026/09/28 03:27:29 OK 20241026095416_initial_model.sql (7.29ms)6982026/09/28 03:27:29 OK 20241026095416_initial_model.sql (7.52ms)6992026/09/28 03:27:29 OK 20241026095416_initial_model.sql (8.01ms)7002026/09/28 03:27:29 OK 20251210153512_drop_unused_gin_index.sql (984.63µs)7012026/09/28 03:27:29 OK 20251210153512_drop_unused_gin_index.sql (762µs)7022026/09/28 03:27:29 OK 20251210153512_drop_unused_gin_index.sql (1.07ms)7032026/09/28 03:27:29 OK 20241026095416_initial_model.sql (7.29ms)7042026/09/28 03:27:29 OK 20251210153512_drop_unused_gin_index.sql (997µs)7052026/09/28 03:27:29 OK 20241026095416_initial_model.sql (8.67ms)7062026/09/28 03:27:29 OK 20241026095416_initial_model.sql (8.27ms)7072026/09/28 03:27:29 OK 20251210153512_drop_unused_gin_index.sql (1.16ms)7082026/09/28 03:27:29 OK 20251210153512_drop_unused_gin_index.sql (1.02ms)7092026/09/28 03:27:29 OK 20251218171726_add_pins.sql (1.94ms)7102026/09/28 03:27:29 OK 20251218171726_add_pins.sql (1.95ms)7112026/09/28 03:27:29 OK 20241026095416_initial_model.sql (9.11ms)7122026/09/28 03:27:29 OK 20251210153512_drop_unused_gin_index.sql (1.04ms)7132026/09/28 03:27:29 OK 20251218171726_add_pins.sql (2.5ms)7142026/09/28 03:27:29 OK 20251218171726_add_pins.sql (2.19ms)7152026/09/28 03:27:29 OK 20251210153512_drop_unused_gin_index.sql (826.38µs)7162026/09/28 03:27:29 OK 20251218171726_add_pins.sql (1.68ms)7172026/09/28 03:27:29 OK 20260628120000_add_object_size_and_stats.sql (2.01ms)7182026/09/28 03:27:29 OK 20241026095416_initial_model.sql (9.41ms)7192026/09/28 03:27:29 OK 20251218171726_add_pins.sql (2.54ms)7202026/09/28 03:27:29 OK 20251218171726_add_pins.sql (1.84ms)7212026/09/28 03:27:29 OK 20260628120000_add_object_size_and_stats.sql (1.57ms)7222026/09/28 03:27:29 OK 20260628120000_add_object_size_and_stats.sql (1.66ms)7232026/09/28 03:27:29 OK 20260628120000_add_object_size_and_stats.sql (1.55ms)7242026/09/28 03:27:29 OK 20251218171726_add_pins.sql (1.94ms)7252026/09/28 03:27:29 OK 20260628120000_add_object_size_and_stats.sql (2.83ms)7262026/09/28 03:27:29 OK 20251210153512_drop_unused_gin_index.sql (965.38µs)7272026/09/28 03:27:29 OK 20241026095416_initial_model.sql (8.16ms)7282026/09/28 03:27:29 OK 20260905000000_add_claims.sql (2.04ms)7292026/09/28 03:27:29 OK 20251210153512_drop_unused_gin_index.sql (899.17µs)7302026/09/28 03:27:29 OK 20260628120000_add_object_size_and_stats.sql (2.29ms)7312026/09/28 03:27:29 OK 20260628120000_add_object_size_and_stats.sql (1.81ms)7322026/09/28 03:27:29 OK 20251218171726_add_pins.sql (1.73ms)7332026/09/28 03:27:29 OK 20260905000000_add_claims.sql (1.91ms)7342026/09/28 03:27:29 OK 20260628120000_add_object_size_and_stats.sql (2.67ms)7352026/09/28 03:27:29 OK 20260905000000_add_claims.sql (2.68ms)7362026/09/28 03:27:29 OK 20260905000000_add_claims.sql (2.71ms)7372026/09/28 03:27:29 OK 20260920000000_drop_claims.sql (1.22ms)7382026/09/28 03:27:29 OK 20260905000000_add_claims.sql (2.22ms)7392026/09/28 03:27:29 OK 20260920000000_drop_claims.sql (1.1ms)7402026/09/28 03:27:29 OK 20260920000000_drop_claims.sql (1.12ms)7412026/09/28 03:27:29 OK 20260628120000_add_object_size_and_stats.sql (1.38ms)7422026/09/28 03:27:29 OK 20251218171726_add_pins.sql (2.21ms)7432026/09/28 03:27:29 OK 20260920000000_drop_claims.sql (1.65ms)7442026/09/28 03:27:29 OK 20260923120000_add_pushes.sql (1.49ms)7452026/09/28 03:27:29 goose: successfully migrated database to version: 202609231200007462026/09/28 03:27:29 OK 20260905000000_add_claims.sql (2.19ms)7472026/09/28 03:27:29 OK 20260920000000_drop_claims.sql (1.45ms)7482026/09/28 03:27:29 OK 20260923120000_add_pushes.sql (778.67µs)7492026/09/28 03:27:29 goose: successfully migrated database to version: 202609231200007502026/09/28 03:27:29 OK 20260905000000_add_claims.sql (2.18ms)7512026/09/28 03:27:29 OK 20260905000000_add_claims.sql (2.31ms)7522026/09/28 03:27:29 OK 20260923120000_add_pushes.sql (1.16ms)7532026/09/28 03:27:29 goose: successfully migrated database to version: 202609231200007542026/09/28 03:27:29 OK 20260923120000_add_pushes.sql (805.79µs)7552026/09/28 03:27:29 goose: successfully migrated database to version: 202609231200007562026/09/28 03:27:29 OK 20260923120000_add_pushes.sql (997µs)7572026/09/28 03:27:29 goose: successfully migrated database to version: 202609231200007582026/09/28 03:27:29 OK 20260628120000_add_object_size_and_stats.sql (1.45ms)7592026/09/28 03:27:29 OK 1_commit_pending_closure.sql (1.43ms)7602026/09/28 03:27:29 OK 20260920000000_drop_claims.sql (969.5µs)7612026/09/28 03:27:29 OK 20260920000000_drop_claims.sql (1.28ms)7622026/09/28 03:27:29 OK 20260920000000_drop_claims.sql (1.8ms)7632026/09/28 03:27:29 OK 20260905000000_add_claims.sql (2.04ms)7642026/09/28 03:27:29 OK 2_object_stats_trigger.sql (433.08µs)7652026/09/28 03:27:29 OK 1_commit_pending_closure.sql (1.39ms)7662026/09/28 03:27:29 OK 1_commit_pending_closure.sql (1.86ms)7672026/09/28 03:27:29 OK 1_commit_pending_closure.sql (1.36ms)7682026/09/28 03:27:29 OK 20260923120000_add_pushes.sql (642.29µs)7692026/09/28 03:27:29 goose: successfully migrated database to version: 202609231200007702026/09/28 03:27:29 OK 20260923120000_add_pushes.sql (629.29µs)7712026/09/28 03:27:29 OK 3_commit_push.sql (376.08µs)7722026/09/28 03:27:29 goose: up to current file version: 37732026/09/28 03:27:29 goose: successfully migrated database to version: 202609231200007742026/09/28 03:27:29 OK 1_commit_pending_closure.sql (1.51ms)7752026/09/28 03:27:29 OK 20260923120000_add_pushes.sql (721.5µs)7762026/09/28 03:27:29 goose: successfully migrated database to version: 202609231200007772026/09/28 03:27:29 OK 2_object_stats_trigger.sql (413.42µs)7782026/09/28 03:27:29 OK 2_object_stats_trigger.sql (527.58µs)7792026/09/28 03:27:29 OK 2_object_stats_trigger.sql (520.58µs)7802026/09/28 03:27:29 OK 2_object_stats_trigger.sql (347µs)7812026/09/28 03:27:29 OK 20260920000000_drop_claims.sql (1.04ms)7822026/09/28 03:27:29 OK 20260905000000_add_claims.sql (1.59ms)7832026/09/28 03:27:29 OK 3_commit_push.sql (409.79µs)7842026/09/28 03:27:29 goose: up to current file version: 37852026/09/28 03:27:29 OK 3_commit_push.sql (388.38µs)7862026/09/28 03:27:29 OK 3_commit_push.sql (300.25µs)7872026/09/28 03:27:29 goose: up to current file version: 37882026/09/28 03:27:29 goose: up to current file version: 37892026/09/28 03:27:29 OK 3_commit_push.sql (469.83µs)7902026/09/28 03:27:29 goose: up to current file version: 37912026/09/28 03:27:29 OK 1_commit_pending_closure.sql (936.42µs)7922026/09/28 03:27:29 OK 20260923120000_add_pushes.sql (552.96µs)7932026/09/28 03:27:29 goose: successfully migrated database to version: 202609231200007942026/09/28 03:27:29 OK 1_commit_pending_closure.sql (1.17ms)7952026/09/28 03:27:29 OK 1_commit_pending_closure.sql (1.14ms)7962026/09/28 03:27:29 OK 20260920000000_drop_claims.sql (828.88µs)7972026/09/28 03:27:29 OK 2_object_stats_trigger.sql (464.17µs)7982026/09/28 03:27:29 OK 2_object_stats_trigger.sql (397.46µs)7992026/09/28 03:27:29 OK 2_object_stats_trigger.sql (220.83µs)8002026/09/28 03:27:29 OK 3_commit_push.sql (299.88µs)8012026/09/28 03:27:29 goose: up to current file version: 38022026/09/28 03:27:29 OK 3_commit_push.sql (326.25µs)8032026/09/28 03:27:29 goose: up to current file version: 38042026/09/28 03:27:29 OK 1_commit_pending_closure.sql (738.83µs)8052026/09/28 03:27:29 OK 3_commit_push.sql (314.04µs)8062026/09/28 03:27:29 goose: up to current file version: 38072026/09/28 03:27:29 OK 20260923120000_add_pushes.sql (496.54µs)8082026/09/28 03:27:29 goose: successfully migrated database to version: 202609231200008092026/09/28 03:27:29 OK 2_object_stats_trigger.sql (168.83µs)8102026/09/28 03:27:29 OK 3_commit_push.sql (185.25µs)8112026/09/28 03:27:29 goose: up to current file version: 38122026/09/28 03:27:29 OK 1_commit_pending_closure.sql (645.46µs)8132026/09/28 03:27:29 OK 2_object_stats_trigger.sql (196.33µs)8142026/09/28 03:27:29 OK 3_commit_push.sql (183.5µs)8152026/09/28 03:27:29 goose: up to current file version: 3816--- PASS: TestReadProxyNarStreaming (0.43s)817=== CONT TestClientWithDependencies8182026/09/28 03:27:30 INFO Received push request method=POST path=/api/pushes8192026/09/28 03:27:30 INFO Received push request method=POST path=/api/pushes8202026/09/28 03:27:30 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)8212026/09/28 03:27:30 INFO Uploading mllg23b8bhby1aij2rzaiccwmr66ffx0-shared-dep (136B)8222026/09/28 03:27:30 INFO Uploading 45hgkj9nz9g1f10inl2nlq0drs28f620-a (248B)8232026/09/28 03:27:30 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)8242026/09/28 03:27:30 INFO Uploading qwigf7l3bbz08flc9v1szbjgf2fczci2-shared-dep (136B)8252026/09/28 03:27:30 INFO Uploading 8w8v37h6n01lz2gbf2d3dqpn2dsmgp2g-top (256B)8262026/09/28 03:27:30 WARN Failed to register uploaded object key=45hgkj9nz9g1f10inl2nlq0drs28f620.ls error="server returned 404: 404 page not found\n"8272026/09/28 03:27:30 WARN Failed to register uploaded object key=8w8v37h6n01lz2gbf2d3dqpn2dsmgp2g.ls error="server returned 404: 404 page not found\n"8282026/09/28 03:27:30 WARN Failed to register uploaded object key=nar/17lgia3gn2jawivsd0ai54qv0g0s866gjw9m14ma814kjbf1sk64.nar.zst error="server returned 404: 404 page not found\n"8292026/09/28 03:27:30 WARN Failed to register uploaded object key=grv73h0qbm5m4lm1vh7j82p22i0lbijn.ls error="server returned 404: 404 page not found\n"8302026/09/28 03:27:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8312026/09/28 03:27:30 WARN Failed to register uploaded object key=mllg23b8bhby1aij2rzaiccwmr66ffx0.ls error="server returned 404: 404 page not found\n"8322026/09/28 03:27:30 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"8332026/09/28 03:27:30 WARN Failed to register uploaded object key=qwigf7l3bbz08flc9v1szbjgf2fczci2.ls error="server returned 404: 404 page not found\n"8342026/09/28 03:27:30 WARN Failed to register uploaded object key=nar/01gslyk435i3q2zj5iij5kly7d3qm0bk940n8pix3c5w5p24jlih.nar.zst error="server returned 404: 404 page not found\n"8352026/09/28 03:27:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8362026/09/28 03:27:30 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"8372026/09/28 03:27:30 INFO Signed narinfos id=1 count=38382026/09/28 03:27:30 INFO Signed narinfos id=1 count=28392026/09/28 03:27:30 INFO Uploading 3 narinfos8402026/09/28 03:27:30 INFO Uploading 2 narinfos8412026/09/28 03:27:30 INFO Received complete push request method=POST path=/api/pushes/1/complete8422026/09/28 03:27:30 WARN Failed to register uploaded object key=8w8v37h6n01lz2gbf2d3dqpn2dsmgp2g.narinfo error="server returned 404: 404 page not found\n"8432026/09/28 03:27:30 WARN Failed to register uploaded object key=45hgkj9nz9g1f10inl2nlq0drs28f620.narinfo error="server returned 404: 404 page not found\n"8442026/09/28 03:27:30 INFO Received complete push request method=POST path=/api/pushes/1/complete8452026/09/28 03:27:30 WARN Failed to register uploaded object key=grv73h0qbm5m4lm1vh7j82p22i0lbijn.narinfo error="server returned 404: 404 page not found\n"8462026/09/28 03:27:30 WARN Failed to register uploaded object key=mllg23b8bhby1aij2rzaiccwmr66ffx0.narinfo error="server returned 404: 404 page not found\n"8472026/09/28 03:27:30 WARN Failed to register uploaded object key=qwigf7l3bbz08flc9v1szbjgf2fczci2.narinfo error="server returned 404: 404 page not found\n"8482026/09/28 03:27:30 INFO Upload complete. (100ms)8492026/09/28 03:27:30 INFO Upload complete. (142ms)850=== NAME TestClientSharedPathCommittedMidPush851 client_integration_test.go:680: Retrieved narinfo from S3:852 StorePath: /nix/var/nix/builds/nix-34546-2893374115/TestClientSharedPathCommittedMidPush3105117049/001/store/qwigf7l3bbz08flc9v1szbjgf2fczci2-shared-dep853 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst854 Compression: zstd855 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82856 NarSize: 136857 References: 858 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n859=== NAME TestClientPushesUseOnePush860 client_pushes_test.go:97: Retrieved narinfo from S3:861 StorePath: /nix/var/nix/builds/nix-34546-2893374115/TestClientPushesUseOnePush3842612398/001/store/mllg23b8bhby1aij2rzaiccwmr66ffx0-shared-dep862 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst863 Compression: zstd864 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82865 NarSize: 136866 References: 867 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n868=== NAME TestClientSharedPathCommittedMidPush869 client_integration_test.go:680: Retrieved narinfo from S3:870 StorePath: /nix/var/nix/builds/nix-34546-2893374115/TestClientSharedPathCommittedMidPush3105117049/001/store/8w8v37h6n01lz2gbf2d3dqpn2dsmgp2g-top871 URL: nar/01gslyk435i3q2zj5iij5kly7d3qm0bk940n8pix3c5w5p24jlih.nar.zst872 Compression: zstd873 NarHash: sha256:01gslyk435i3q2zj5iij5kly7d3qm0bk940n8pix3c5w5p24jlih874 NarSize: 256875 References: /nix/var/nix/builds/nix-34546-2893374115/TestClientSharedPathCommittedMidPush3105117049/001/store/qwigf7l3bbz08flc9v1szbjgf2fczci2-shared-dep876 CA: text:sha256:118a7xqkg5ikk0yifg881i2nsprzml7lfn9cw063hh45dny2w5h2877=== NAME TestClientPushesUseOnePush878 client_pushes_test.go:97: Retrieved narinfo from S3:879 StorePath: /nix/var/nix/builds/nix-34546-2893374115/TestClientPushesUseOnePush3842612398/001/store/45hgkj9nz9g1f10inl2nlq0drs28f620-a880 URL: nar/17lgia3gn2jawivsd0ai54qv0g0s866gjw9m14ma814kjbf1sk64.nar.zst881 Compression: zstd882 NarHash: sha256:17lgia3gn2jawivsd0ai54qv0g0s866gjw9m14ma814kjbf1sk64883 NarSize: 248884 References: /nix/var/nix/builds/nix-34546-2893374115/TestClientPushesUseOnePush3842612398/001/store/mllg23b8bhby1aij2rzaiccwmr66ffx0-shared-dep885 CA: text:sha256:1jxqq5rkl4k8q799390iiwrmwbsh838srnb1wsnbsrbi896gd2mx886 client_pushes_test.go:97: Retrieved narinfo from S3:887 StorePath: /nix/var/nix/builds/nix-34546-2893374115/TestClientPushesUseOnePush3842612398/001/store/grv73h0qbm5m4lm1vh7j82p22i0lbijn-b888 URL: nar/17lgia3gn2jawivsd0ai54qv0g0s866gjw9m14ma814kjbf1sk64.nar.zst889 Compression: zstd890 NarHash: sha256:17lgia3gn2jawivsd0ai54qv0g0s866gjw9m14ma814kjbf1sk64891 NarSize: 248892 References: /nix/var/nix/builds/nix-34546-2893374115/TestClientPushesUseOnePush3842612398/001/store/mllg23b8bhby1aij2rzaiccwmr66ffx0-shared-dep893 CA: text:sha256:1jxqq5rkl4k8q799390iiwrmwbsh838srnb1wsnbsrbi896gd2mx894--- PASS: TestClientSharedPathCommittedMidPush (1.07s)895=== CONT TestClientMultipleUploads896--- PASS: TestClientPushesUseOnePush (1.08s)897=== CONT TestClientIntegration8982026/09/28 03:27:30 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"899--- PASS: TestService_AuthMiddleware (1.10s)900=== CONT TestClientErrorHandling901=== RUN TestClientErrorHandling/InvalidStorePath902=== PAUSE TestClientErrorHandling/InvalidStorePath903=== RUN TestClientErrorHandling/InvalidAuthToken904=== PAUSE TestClientErrorHandling/InvalidAuthToken905=== RUN TestClientErrorHandling/ServerNotAvailable906=== PAUSE TestClientErrorHandling/ServerNotAvailable907=== CONT TestClientCADerivations908=== NAME TestPinProtectsFromGC909 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-34546-2893374115/TestPinProtectsFromGC3933243981/001/store/fv4n2ybwhcfqirh9yh2y7kvfhi69wynl-pinned-file.txt910 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-34546-2893374115/TestPinProtectsFromGC3933243981/001/store/lamwa1f1hxizv58p2770c5x4fw4jb3gw-unpinned-file.txt9112026-09-28 03:27:30.724 UTC [34907] ERROR: relation "goose_db_version" does not exist at character 369122026-09-28 03:27:30.724 UTC [34907] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9132026/09/28 03:27:30 INFO Received push request method=POST path=/api/pushes9142026/09/28 03:27:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9152026/09/28 03:27:30 INFO Uploading fv4n2ybwhcfqirh9yh2y7kvfhi69wynl-pinned-file.txt (128B)9162026/09/28 03:27:30 OK 20241026095416_initial_model.sql (36.9ms)9172026/09/28 03:27:30 OK 20251210153512_drop_unused_gin_index.sql (6.43ms)9182026/09/28 03:27:30 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"9192026/09/28 03:27:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9202026/09/28 03:27:30 WARN Failed to register uploaded object key=fv4n2ybwhcfqirh9yh2y7kvfhi69wynl.ls error="server returned 404: 404 page not found\n"9212026/09/28 03:27:30 INFO Signed narinfos id=1 count=19222026/09/28 03:27:30 INFO Uploading 1 narinfos9232026/09/28 03:27:30 INFO Received complete push request method=POST path=/api/pushes/1/complete9242026/09/28 03:27:30 WARN Failed to register uploaded object key=fv4n2ybwhcfqirh9yh2y7kvfhi69wynl.narinfo error="server returned 404: 404 page not found\n"9252026/09/28 03:27:30 OK 20251218171726_add_pins.sql (13.51ms)9262026/09/28 03:27:30 INFO Upload complete. (85ms)9272026/09/28 03:27:30 OK 20260628120000_add_object_size_and_stats.sql (18.64ms)9282026/09/28 03:27:30 OK 20260905000000_add_claims.sql (33.18ms)9292026/09/28 03:27:30 OK 20260920000000_drop_claims.sql (6.37ms)9302026/09/28 03:27:30 OK 20260923120000_add_pushes.sql (15.75ms)9312026/09/28 03:27:30 goose: successfully migrated database to version: 202609231200009322026/09/28 03:27:30 OK 1_commit_pending_closure.sql (806µs)9332026/09/28 03:27:30 OK 2_object_stats_trigger.sql (236.79µs)9342026/09/28 03:27:30 OK 3_commit_push.sql (199.71µs)9352026/09/28 03:27:30 goose: up to current file version: 39362026/09/28 03:27:30 INFO Received push request method=POST path=/api/pushes9372026/09/28 03:27:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9382026/09/28 03:27:30 INFO Uploading lamwa1f1hxizv58p2770c5x4fw4jb3gw-unpinned-file.txt (128B)9392026/09/28 03:27:30 WARN Failed to register uploaded object key=lamwa1f1hxizv58p2770c5x4fw4jb3gw.ls error="server returned 404: 404 page not found\n"9402026/09/28 03:27:30 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign9412026/09/28 03:27:30 INFO Signed narinfos id=2 count=19422026/09/28 03:27:30 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"9432026/09/28 03:27:30 INFO Uploading 1 narinfos9442026/09/28 03:27:30 INFO Received complete push request method=POST path=/api/pushes/2/complete9452026/09/28 03:27:30 WARN Failed to register uploaded object key=lamwa1f1hxizv58p2770c5x4fw4jb3gw.narinfo error="server returned 404: 404 page not found\n"9462026/09/28 03:27:30 INFO Upload complete. (66ms)9472026/09/28 03:27:30 INFO Received create pin request method=POST path=/api/pins/myapp9482026/09/28 03:27:30 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-34546-2893374115/TestPinProtectsFromGC3933243981/001/store/fv4n2ybwhcfqirh9yh2y7kvfhi69wynl-pinned-file.txt narinfo_key=fv4n2ybwhcfqirh9yh2y7kvfhi69wynl.narinfo9492026/09/28 03:27:30 INFO Starting cleanup of old closures method=DELETE path=/api/closures9502026/09/28 03:27:30 INFO Garbage collection started9512026/09/28 03:27:30 INFO Aborted multipart uploads count=09522026/09/28 03:27:30 WARN Force mode enabled - objects will be deleted immediately without grace period9532026/09/28 03:27:30 INFO Received uploads request method=POST path=/api/pending_closures9542026/09/28 03:27:31 INFO Received cleanup request method=DELETE path=/api/pending_closures9552026/09/28 03:27:31 INFO Aborted multipart uploads count=19562026/09/28 03:27:31 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=0957--- PASS: TestMultipartCleanup (1.61s)958=== CONT TestCacheStatsHandler9592026/09/28 03:27:31 INFO Vacuumed table table=pending_closures9602026/09/28 03:27:31 INFO Vacuumed table table=pending_objects9612026/09/28 03:27:31 INFO Vacuumed table table=multipart_uploads9622026/09/28 03:27:31 INFO Vacuumed table table=closures9632026/09/28 03:27:31 INFO Vacuumed table table=objects9642026-09-28 03:27:31.400 UTC [34928] ERROR: relation "goose_db_version" does not exist at character 369652026-09-28 03:27:31.400 UTC [34928] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9662026-09-28 03:27:31.400 UTC [34929] ERROR: relation "goose_db_version" does not exist at character 369672026-09-28 03:27:31.400 UTC [34929] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC968=== NAME TestOrphanedObjectsGC969 orphaned_objects_gc_test.go:290: GC Test Summary:970 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A971 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B972 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)973 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)974 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects975--- PASS: TestOrphanedObjectsGC (1.84s)976=== CONT TestCacheConfigHandler977=== RUN TestCacheConfigHandler/full_config,_no_issuer978=== PAUSE TestCacheConfigHandler/full_config,_no_issuer979=== RUN TestCacheConfigHandler/no_cache_url_configured980=== PAUSE TestCacheConfigHandler/no_cache_url_configured981=== RUN TestCacheConfigHandler/no_signing_keys982=== PAUSE TestCacheConfigHandler/no_signing_keys983=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator984=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator985=== CONT TestService_ReadScope_PublicByDefault9862026-09-28 03:27:31.434 UTC [34930] ERROR: relation "goose_db_version" does not exist at character 369872026-09-28 03:27:31.434 UTC [34930] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC988--- PASS: TestObjectStatsTrigger (1.94s)989=== CONT TestService_RequireScope_OIDC9902026/09/28 03:27:31 OK 20241026095416_initial_model.sql (78.94ms)9912026/09/28 03:27:31 OK 20241026095416_initial_model.sql (79.41ms)9922026/09/28 03:27:31 OK 20251210153512_drop_unused_gin_index.sql (622.79µs)9932026/09/28 03:27:31 OK 20251210153512_drop_unused_gin_index.sql (615.04µs)9942026/09/28 03:27:31 OK 20251218171726_add_pins.sql (1.25ms)9952026/09/28 03:27:31 OK 20241026095416_initial_model.sql (60.3ms)9962026/09/28 03:27:31 OK 20251210153512_drop_unused_gin_index.sql (7.62ms)9972026/09/28 03:27:31 OK 20251218171726_add_pins.sql (9.24ms)9982026/09/28 03:27:31 OK 20260628120000_add_object_size_and_stats.sql (14.91ms)9992026/09/28 03:27:31 OK 20251218171726_add_pins.sql (7.58ms)10002026/09/28 03:27:31 OK 20260628120000_add_object_size_and_stats.sql (13.35ms)10012026/09/28 03:27:31 OK 20260905000000_add_claims.sql (7.61ms)10022026/09/28 03:27:31 OK 20260628120000_add_object_size_and_stats.sql (12.23ms)10032026/09/28 03:27:31 OK 20260920000000_drop_claims.sql (5.41ms)10042026/09/28 03:27:31 OK 20260905000000_add_claims.sql (13.87ms)10052026/09/28 03:27:31 OK 20260923120000_add_pushes.sql (8.51ms)10062026/09/28 03:27:31 goose: successfully migrated database to version: 2026092312000010072026/09/28 03:27:31 OK 1_commit_pending_closure.sql (1.13ms)10082026/09/28 03:27:31 OK 2_object_stats_trigger.sql (213.46µs)10092026/09/28 03:27:31 OK 3_commit_push.sql (197.63µs)10102026/09/28 03:27:31 goose: up to current file version: 310112026/09/28 03:27:31 OK 20260905000000_add_claims.sql (15.08ms)10122026/09/28 03:27:31 OK 20260920000000_drop_claims.sql (7.78ms)10132026/09/28 03:27:31 OK 20260920000000_drop_claims.sql (928.25µs)10142026/09/28 03:27:31 OK 20260923120000_add_pushes.sql (4.55ms)10152026/09/28 03:27:31 goose: successfully migrated database to version: 2026092312000010162026/09/28 03:27:31 OK 20260923120000_add_pushes.sql (4.98ms)10172026/09/28 03:27:31 goose: successfully migrated database to version: 2026092312000010182026/09/28 03:27:31 OK 1_commit_pending_closure.sql (804.46µs)10192026/09/28 03:27:31 OK 2_object_stats_trigger.sql (248.08µs)10202026/09/28 03:27:31 OK 1_commit_pending_closure.sql (783.54µs)10212026/09/28 03:27:31 OK 3_commit_push.sql (339.04µs)10222026/09/28 03:27:31 goose: up to current file version: 310232026/09/28 03:27:31 OK 2_object_stats_trigger.sql (207.21µs)10242026/09/28 03:27:31 OK 3_commit_push.sql (157.58µs)10252026/09/28 03:27:31 goose: up to current file version: 310262026/09/28 03:27:31 INFO Received uploads request method=POST path=/api/pending_closures10272026/09/28 03:27:31 INFO Received uploads request method=POST path=/api/pending_closures10282026/09/28 03:27:31 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)10292026/09/28 03:27:31 INFO Uploading d2rmg3c2pn8yrlbkv51v2b90b05ya5rd-a (248B)10302026/09/28 03:27:31 INFO Uploading 2y51fxzgd48adii35abl0pv8064l9sxn-shared-dep (136B)10312026/09/28 03:27:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63665/oidc10322026/09/28 03:27:31 INFO Received uploads request method=POST path=/api/pending_closures10332026/09/28 03:27:31 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10342026/09/28 03:27:31 WARN Failed to register uploaded object key=nar/02zrbky1mbvnv23xnw1iwkw9vwpl1cmz4pwvzm2zmry0inza341y.nar.zst error="server returned 404: 404 page not found\n"10352026/09/28 03:27:31 WARN Failed to register uploaded object key=p34rmdcgnshzxsca49waaxnawlb40n1x.ls error="server returned 404: 404 page not found\n"10362026/09/28 03:27:31 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10372026/09/28 03:27:31 WARN Failed to register uploaded object key=d2rmg3c2pn8yrlbkv51v2b90b05ya5rd.ls error="server returned 404: 404 page not found\n"10382026/09/28 03:27:31 WARN Failed to register uploaded object key=2y51fxzgd48adii35abl0pv8064l9sxn.ls error="server returned 404: 404 page not found\n"10392026/09/28 03:27:31 INFO Signed narinfos id=1 count=210402026/09/28 03:27:31 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10412026/09/28 03:27:31 INFO Signed narinfos id=2 count=210422026/09/28 03:27:31 INFO Uploading 4 narinfos10432026/09/28 03:27:31 WARN Failed to register uploaded object key=d2rmg3c2pn8yrlbkv51v2b90b05ya5rd.narinfo error="server returned 404: 404 page not found\n"10442026/09/28 03:27:31 WARN Failed to register uploaded object key=2y51fxzgd48adii35abl0pv8064l9sxn.narinfo error="server returned 404: 404 page not found\n"10452026/09/28 03:27:31 WARN Failed to register uploaded object key=p34rmdcgnshzxsca49waaxnawlb40n1x.narinfo error="server returned 404: 404 page not found\n"10462026/09/28 03:27:31 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10472026/09/28 03:27:31 WARN Failed to register uploaded object key=2y51fxzgd48adii35abl0pv8064l9sxn.narinfo error="server returned 404: 404 page not found\n"10482026/09/28 03:27:31 INFO Completed upload id=110492026/09/28 03:27:31 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10502026/09/28 03:27:31 INFO Completed upload id=210512026/09/28 03:27:31 INFO Upload complete. (119ms)1052=== NAME TestClientFallsBackToClosures1053 client_pushes_test.go:112: Retrieved narinfo from S3:1054 StorePath: /nix/var/nix/builds/nix-34546-2893374115/TestClientFallsBackToClosures975593977/001/store/2y51fxzgd48adii35abl0pv8064l9sxn-shared-dep1055 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1056 Compression: zstd1057 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821058 NarSize: 1361059 References: 1060 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1061 client_pushes_test.go:112: Retrieved narinfo from S3:1062 StorePath: /nix/var/nix/builds/nix-34546-2893374115/TestClientFallsBackToClosures975593977/001/store/d2rmg3c2pn8yrlbkv51v2b90b05ya5rd-a1063 URL: nar/02zrbky1mbvnv23xnw1iwkw9vwpl1cmz4pwvzm2zmry0inza341y.nar.zst1064 Compression: zstd1065 NarHash: sha256:02zrbky1mbvnv23xnw1iwkw9vwpl1cmz4pwvzm2zmry0inza341y1066 NarSize: 2481067 References: /nix/var/nix/builds/nix-34546-2893374115/TestClientFallsBackToClosures975593977/001/store/2y51fxzgd48adii35abl0pv8064l9sxn-shared-dep1068 CA: text:sha256:181rvzp74cc543lf4sm9imafzk2cqqvn0bs0c8h3isa3sw2g1n4r1069 client_pushes_test.go:112: Retrieved narinfo from S3:1070 StorePath: /nix/var/nix/builds/nix-34546-2893374115/TestClientFallsBackToClosures975593977/001/store/p34rmdcgnshzxsca49waaxnawlb40n1x-b1071 URL: nar/02zrbky1mbvnv23xnw1iwkw9vwpl1cmz4pwvzm2zmry0inza341y.nar.zst1072 Compression: zstd1073 NarHash: sha256:02zrbky1mbvnv23xnw1iwkw9vwpl1cmz4pwvzm2zmry0inza341y1074 NarSize: 2481075 References: /nix/var/nix/builds/nix-34546-2893374115/TestClientFallsBackToClosures975593977/001/store/2y51fxzgd48adii35abl0pv8064l9sxn-shared-dep1076 CA: text:sha256:181rvzp74cc543lf4sm9imafzk2cqqvn0bs0c8h3isa3sw2g1n4r1077--- PASS: TestClientFallsBackToClosures (2.19s)1078=== CONT TestService_AuthMiddleware_OIDC10792026/09/28 03:27:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63678/oidc10802026/09/28 03:27:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10812026/09/28 03:27:31 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NTg0YzlkZmItNmU2OC00ZDFiLWE1MTItN2JkNTNjOGQxYTQzLjcyODQ1ZTE5LTZmYzgtNDA2NS04YjA3LTFmNjhiZGU2NDQ5NHgxNzkwNTY2MDUxNjU1ODM2MDAw10822026/09/28 03:27:31 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NTg0YzlkZmItNmU2OC00ZDFiLWE1MTItN2JkNTNjOGQxYTQzLjcyODQ1ZTE5LTZmYzgtNDA2NS04YjA3LTFmNjhiZGU2NDQ5NHgxNzkwNTY2MDUxNjU1ODM2MDAw parts=11083--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.26s)1084=== CONT TestService_ReadAuthMiddleware1085=== NAME TestClientIntegration1086 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-34546-2893374115/TestClientIntegration1772981368/002/store/l7zlgn5g6hm60jkdsiwird0cd3skvmsm-test-file.txt1087=== NAME TestClientWithDependencies1088 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-34546-2893374115/TestClientWithDependencies3297699860/001/store/j0rmn8y1i92gkvl00rr3a49baldshs0f-test-script1089 client_integration_test.go:615: Found 1 dependencies (including self)10902026/09/28 03:27:32 INFO Received push request method=POST path=/api/pushes10912026-09-28 03:27:32.262 UTC [34967] ERROR: relation "goose_db_version" does not exist at character 3610922026-09-28 03:27:32.262 UTC [34967] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10932026-09-28 03:27:32.262 UTC [34965] ERROR: relation "goose_db_version" does not exist at character 3610942026-09-28 03:27:32.262 UTC [34965] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10952026/09/28 03:27:32 INFO Received push request method=POST path=/api/pushes10962026/09/28 03:27:32 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10972026/09/28 03:27:32 INFO Uploading l7zlgn5g6hm60jkdsiwird0cd3skvmsm-test-file.txt (152B)10982026/09/28 03:27:32 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10992026/09/28 03:27:32 INFO Uploading j0rmn8y1i92gkvl00rr3a49baldshs0f-test-script (136B)11002026/09/28 03:27:32 WARN Failed to register uploaded object key=l7zlgn5g6hm60jkdsiwird0cd3skvmsm.ls error="server returned 404: 404 page not found\n"11012026/09/28 03:27:32 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11022026/09/28 03:27:32 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"11032026/09/28 03:27:32 INFO Signed narinfos id=1 count=111042026/09/28 03:27:32 INFO Uploading 1 narinfos11052026/09/28 03:27:32 WARN Failed to register uploaded object key=j0rmn8y1i92gkvl00rr3a49baldshs0f.ls error="server returned 404: 404 page not found\n"11062026/09/28 03:27:32 INFO Received complete push request method=POST path=/api/pushes/1/complete11072026/09/28 03:27:32 WARN Failed to register uploaded object key=l7zlgn5g6hm60jkdsiwird0cd3skvmsm.narinfo error="server returned 404: 404 page not found\n"11082026/09/28 03:27:32 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"11092026/09/28 03:27:32 WARN Failed to register uploaded object key=log/4c9v1kk433dly9axazgkmk1jfhpxffwk-test-script.drv error="server returned 404: 404 page not found\n"11102026/09/28 03:27:32 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11112026/09/28 03:27:32 INFO Signed narinfos id=1 count=111122026/09/28 03:27:32 INFO Uploading 1 narinfos11132026/09/28 03:27:32 INFO Received complete push request method=POST path=/api/pushes/1/complete11142026/09/28 03:27:32 WARN Failed to register uploaded object key=j0rmn8y1i92gkvl00rr3a49baldshs0f.narinfo error="server returned 404: 404 page not found\n"11152026/09/28 03:27:32 INFO Upload complete. (165ms)11162026/09/28 03:27:32 INFO Upload complete. (130ms)1117 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-34546-2893374115/TestClientWithDependencies3297699860/001/store) requires matching store prefix11182026/09/28 03:27:32 INFO All 1 paths already cached1119=== NAME TestClientIntegration1120 client_integration_test.go:312: Retrieved narinfo from S3:1121 StorePath: /nix/var/nix/builds/nix-34546-2893374115/TestClientIntegration1772981368/002/store/l7zlgn5g6hm60jkdsiwird0cd3skvmsm-test-file.txt1122 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1123 Compression: zstd1124 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11125 NarSize: 1521126 References: 1127 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11128 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1129 client_integration_test.go:313: Decompressed .ls content (64 bytes):1130 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1131 client_integration_test.go:316: Testing garbage collection...1132--- PASS: TestClientWithDependencies (2.41s)1133=== CONT TestService_AuthMiddleware_MTLSBoundSubjects11342026/09/28 03:27:32 INFO Starting cleanup of old closures method=DELETE path=/api/closures11352026/09/28 03:27:32 INFO Garbage collection started11362026/09/28 03:27:32 INFO Aborted multipart uploads count=011372026/09/28 03:27:32 WARN Force mode enabled - objects will be deleted immediately without grace period11382026/09/28 03:27:32 OK 20241026095416_initial_model.sql (109.17ms)11392026/09/28 03:27:32 OK 20251210153512_drop_unused_gin_index.sql (1.65ms)11402026/09/28 03:27:32 OK 20241026095416_initial_model.sql (118.42ms)11412026/09/28 03:27:32 OK 20251210153512_drop_unused_gin_index.sql (4.96ms)11422026/09/28 03:27:32 OK 20251218171726_add_pins.sql (12.55ms)11432026/09/28 03:27:32 OK 20251218171726_add_pins.sql (12.07ms)11442026/09/28 03:27:32 OK 20260628120000_add_object_size_and_stats.sql (19.35ms)11452026/09/28 03:27:32 OK 20260628120000_add_object_size_and_stats.sql (13.21ms)11462026/09/28 03:27:32 OK 20260905000000_add_claims.sql (10ms)11472026/09/28 03:27:32 OK 20260905000000_add_claims.sql (22.12ms)11482026/09/28 03:27:32 OK 20260920000000_drop_claims.sql (8.3ms)11492026/09/28 03:27:32 OK 20260920000000_drop_claims.sql (1.65ms)11502026/09/28 03:27:32 OK 20260923120000_add_pushes.sql (1.54ms)11512026/09/28 03:27:32 goose: successfully migrated database to version: 2026092312000011522026/09/28 03:27:32 OK 20260923120000_add_pushes.sql (2.27ms)11532026/09/28 03:27:32 goose: successfully migrated database to version: 2026092312000011542026/09/28 03:27:32 OK 1_commit_pending_closure.sql (1.12ms)11552026/09/28 03:27:32 OK 2_object_stats_trigger.sql (302.46µs)11562026/09/28 03:27:32 OK 1_commit_pending_closure.sql (1.07ms)11572026/09/28 03:27:32 OK 3_commit_push.sql (233.83µs)11582026/09/28 03:27:32 goose: up to current file version: 311592026/09/28 03:27:32 OK 2_object_stats_trigger.sql (206.04µs)11602026/09/28 03:27:32 OK 3_commit_push.sql (188.25µs)11612026/09/28 03:27:32 goose: up to current file version: 31162=== NAME TestClientMultipleUploads1163 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-34546-2893374115/TestClientMultipleUploads2099718628/001/store/2cqw1ik6s883qja8pg672csd28b9c1xz-test-file-0.txt11642026-09-28 03:27:32.567 UTC [34982] ERROR: relation "goose_db_version" does not exist at character 3611652026-09-28 03:27:32.567 UTC [34982] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1166 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-34546-2893374115/TestClientMultipleUploads2099718628/001/store/ppss3f1hwzjrqm7yincfxjq28dmvd8rd-test-file-1.txt11672026/09/28 03:27:32 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=011682026/09/28 03:27:32 INFO Vacuumed table table=pending_closures1169=== NAME TestClientCADerivations1170 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-34546-2893374115/TestClientCADerivations1927994962/001/store/nmji0w0mwj7wjjahm8x8kgjw0nkiw38q-ca-test11712026/09/28 03:27:32 INFO Vacuumed table table=pending_objects11722026/09/28 03:27:32 INFO Vacuumed table table=multipart_uploads11732026/09/28 03:27:32 INFO Vacuumed table table=closures11742026/09/28 03:27:32 INFO Vacuumed table table=objects1175 client_ca_test.go:139: Found 1 dependencies (including self)1176=== NAME TestClientMultipleUploads1177 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-34546-2893374115/TestClientMultipleUploads2099718628/001/store/7s7lss5vaah6768qc786d8053lk858ni-test-file-2.txt1178--- PASS: TestService_ReadScope_PublicByDefault (1.33s)1179=== CONT TestService_AuthMiddleware_MTLSProxyHeader11802026/09/28 03:27:32 OK 20241026095416_initial_model.sql (104.36ms)11812026/09/28 03:27:32 OK 20251210153512_drop_unused_gin_index.sql (7.54ms)11822026/09/28 03:27:32 OK 20251218171726_add_pins.sql (16.53ms)11832026-09-28 03:27:32.756 UTC [34993] ERROR: relation "goose_db_version" does not exist at character 3611842026-09-28 03:27:32.756 UTC [34993] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11852026/09/28 03:27:32 OK 20260628120000_add_object_size_and_stats.sql (31.98ms)11862026/09/28 03:27:32 INFO Received push request method=POST path=/api/pushes11872026/09/28 03:27:32 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)11882026/09/28 03:27:32 INFO Uploading 2cqw1ik6s883qja8pg672csd28b9c1xz-test-file-0.txt (160B)11892026/09/28 03:27:32 INFO Uploading 7s7lss5vaah6768qc786d8053lk858ni-test-file-2.txt (160B)11902026/09/28 03:27:32 INFO Uploading ppss3f1hwzjrqm7yincfxjq28dmvd8rd-test-file-1.txt (160B)11912026/09/28 03:27:32 OK 20260905000000_add_claims.sql (32ms)11922026/09/28 03:27:32 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"11932026/09/28 03:27:32 WARN Failed to register uploaded object key=7s7lss5vaah6768qc786d8053lk858ni.ls error="server returned 404: 404 page not found\n"11942026/09/28 03:27:32 WARN Failed to register uploaded object key=2cqw1ik6s883qja8pg672csd28b9c1xz.ls error="server returned 404: 404 page not found\n"11952026/09/28 03:27:32 WARN Failed to register uploaded object key=ppss3f1hwzjrqm7yincfxjq28dmvd8rd.ls error="server returned 404: 404 page not found\n"11962026/09/28 03:27:32 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"11972026/09/28 03:27:32 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11982026/09/28 03:27:32 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"11992026/09/28 03:27:32 INFO Signed narinfos id=1 count=312002026/09/28 03:27:32 INFO Received push request method=POST path=/api/pushes12012026/09/28 03:27:32 INFO Uploading 3 narinfos12022026/09/28 03:27:32 OK 20260920000000_drop_claims.sql (23.05ms)12032026/09/28 03:27:32 WARN Failed to register uploaded object key=2cqw1ik6s883qja8pg672csd28b9c1xz.narinfo error="server returned 404: 404 page not found\n"12042026/09/28 03:27:32 WARN Failed to register uploaded object key=ppss3f1hwzjrqm7yincfxjq28dmvd8rd.narinfo error="server returned 404: 404 page not found\n"12052026/09/28 03:27:32 INFO Received complete push request method=POST path=/api/pushes/1/complete12062026/09/28 03:27:32 WARN Failed to register uploaded object key=7s7lss5vaah6768qc786d8053lk858ni.narinfo error="server returned 404: 404 page not found\n"12072026-09-28 03:27:32.849 UTC [35002] ERROR: relation "goose_db_version" does not exist at character 3612082026-09-28 03:27:32.849 UTC [35002] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12092026/09/28 03:27:32 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12102026/09/28 03:27:32 INFO Uploading nmji0w0mwj7wjjahm8x8kgjw0nkiw38q-ca-test (144B)12112026/09/28 03:27:32 OK 20260923120000_add_pushes.sql (13.4ms)12122026/09/28 03:27:32 goose: successfully migrated database to version: 2026092312000012132026/09/28 03:27:32 OK 1_commit_pending_closure.sql (898.58µs)12142026/09/28 03:27:32 OK 2_object_stats_trigger.sql (217.38µs)12152026/09/28 03:27:32 OK 3_commit_push.sql (193.5µs)12162026/09/28 03:27:32 goose: up to current file version: 312172026/09/28 03:27:32 INFO Upload complete. (129ms)1218=== NAME TestClientMultipleUploads1219 client_integration_test.go:369: Uploaded 3 paths in 164.247ms12202026/09/28 03:27:32 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"12212026/09/28 03:27:32 WARN Failed to register uploaded object key=nmji0w0mwj7wjjahm8x8kgjw0nkiw38q.ls error="server returned 404: 404 page not found\n"12222026/09/28 03:27:32 WARN Failed to register uploaded object key=log/b6cipzmynlzslvn4rmciz3aysh6148zc-ca-test.drv error="server returned 404: 404 page not found\n"12232026/09/28 03:27:32 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12242026/09/28 03:27:32 INFO Signed narinfos id=1 count=112252026/09/28 03:27:32 INFO Uploading 1 narinfos12262026/09/28 03:27:32 INFO Received complete push request method=POST path=/api/pushes/1/complete12272026/09/28 03:27:32 WARN Failed to register uploaded object key=nmji0w0mwj7wjjahm8x8kgjw0nkiw38q.narinfo error="server returned 404: 404 page not found\n"12282026/09/28 03:27:32 OK 20241026095416_initial_model.sql (105.1ms)12292026/09/28 03:27:32 OK 20251210153512_drop_unused_gin_index.sql (1.26ms)12302026/09/28 03:27:32 INFO Upload complete. (189ms)1231=== NAME TestClientCADerivations1232 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-34546-2893374115/TestClientCADerivations1927994962/001/store/nmji0w0mwj7wjjahm8x8kgjw0nkiw38q-ca-test1233 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1234 Compression: zstd1235 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1236 NarSize: 1441237 References: 1238 Deriver: /nix/var/nix/builds/nix-34546-2893374115/TestClientCADerivations1927994962/001/store/b6cipzmynlzslvn4rmciz3aysh6148zc-ca-test.drv1239 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1240 client_ca_test.go:185: Checking for realisation files in S3...1241 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1242 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1243--- PASS: TestClientMultipleUploads (2.29s)1244=== CONT TestMetricsInventory12452026/09/28 03:27:32 OK 20251218171726_add_pins.sql (14.48ms)12462026/09/28 03:27:32 OK 20260628120000_add_object_size_and_stats.sql (22.71ms)12472026/09/28 03:27:32 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01248=== NAME TestPinProtectsFromGC1249 client_integration_test.go:794: Pin successfully protected closure from garbage collection12502026/09/28 03:27:32 OK 20260905000000_add_claims.sql (41.02ms)1251--- PASS: TestCacheStatsHandler (1.83s)1252=== CONT TestServerTLSConfig1253=== RUN TestServerTLSConfig/no_client_CA1254=== PAUSE TestServerTLSConfig/no_client_CA1255=== RUN TestServerTLSConfig/missing_CA_file1256=== PAUSE TestServerTLSConfig/missing_CA_file1257=== RUN TestServerTLSConfig/not_a_PEM_file1258=== PAUSE TestServerTLSConfig/not_a_PEM_file1259=== CONT TestService_NativeMTLS12602026/09/28 03:27:33 OK 20260920000000_drop_claims.sql (15.3ms)1261=== NAME TestClientCADerivations1262 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket15?endpoint=http://localhost:63571®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-34546-2893374115/TestClientCADerivations1927994962/001/store'1263 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11264--- PASS: TestPinProtectsFromGC (3.45s)1265=== CONT TestGCTaskStore_StartNew1266--- PASS: TestGCTaskStore_StartNew (0.00s)1267=== CONT TestGCTaskStore_GetEmpty1268--- PASS: TestGCTaskStore_GetEmpty (0.00s)1269=== CONT TestGCTaskStore_ConflictDifferentParams1270--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1271=== CONT TestGCTaskStore_DeduplicateSameParams1272--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1273=== CONT TestNARDeduplicationMetadataUploadBug12742026/09/28 03:27:33 OK 20241026095416_initial_model.sql (120ms)12752026/09/28 03:27:33 OK 20260923120000_add_pushes.sql (21.73ms)12762026/09/28 03:27:33 goose: successfully migrated database to version: 2026092312000012772026/09/28 03:27:33 OK 1_commit_pending_closure.sql (850.25µs)12782026/09/28 03:27:33 OK 2_object_stats_trigger.sql (388.58µs)12792026/09/28 03:27:33 OK 20251210153512_drop_unused_gin_index.sql (5.64ms)12802026/09/28 03:27:33 OK 3_commit_push.sql (264.25µs)12812026/09/28 03:27:33 goose: up to current file version: 312822026/09/28 03:27:33 OK 20251218171726_add_pins.sql (11.98ms)1283--- PASS: TestClientCADerivations (2.39s)1284=== CONT TestCreatePendingClosureRejectsOversizedNAR12852026/09/28 03:27:33 INFO Received uploads request method=POST path=/api/pending_closures1286--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1287=== CONT TestGracefulShutdownDrainsInflight12882026/09/28 03:27:33 INFO Starting HTTP server address=127.0.0.1:6371912892026/09/28 03:27:33 INFO Shutdown signal received, draining in-flight requests timeout=10s12902026/09/28 03:27:33 OK 20260628120000_add_object_size_and_stats.sql (15.52ms)12912026/09/28 03:27:33 OK 20260905000000_add_claims.sql (12.98ms)12922026/09/28 03:27:33 OK 20260920000000_drop_claims.sql (15.09ms)12932026/09/28 03:27:33 OK 20260923120000_add_pushes.sql (5.22ms)12942026/09/28 03:27:33 goose: successfully migrated database to version: 2026092312000012952026/09/28 03:27:33 OK 1_commit_pending_closure.sql (859.54µs)12962026/09/28 03:27:33 OK 2_object_stats_trigger.sql (231.58µs)12972026/09/28 03:27:33 OK 3_commit_push.sql (204.04µs)12982026/09/28 03:27:33 goose: up to current file version: 31299--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1300=== CONT TestService_readinessHandler1301=== RUN TestService_RequireScope_OIDC/builder_may_write1302=== PAUSE TestService_RequireScope_OIDC/builder_may_write1303=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1304=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1305=== RUN TestService_RequireScope_OIDC/ops_may_admin1306=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1307=== RUN TestService_RequireScope_OIDC/ops_may_not_write1308=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1309=== RUN TestService_RequireScope_OIDC/reader_may_not_write1310=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1311=== RUN TestService_RequireScope_OIDC/static_token_may_admin1312=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1313=== RUN TestService_RequireScope_OIDC/static_token_may_write1314=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1315=== RUN TestService_RequireScope_OIDC/reader_may_read1316=== PAUSE TestService_RequireScope_OIDC/reader_may_read1317=== RUN TestService_RequireScope_OIDC/writer_implies_read1318=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1319=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1320=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1321=== CONT TestService_healthCheckHandler1322=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1323=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1324=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1325=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1326=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1327=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1328=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1329=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1330=== CONT TestProxyHeadersOnlyTrustedOnSocket13312026-09-28 03:27:33.354 UTC [35017] ERROR: relation "goose_db_version" does not exist at character 3613322026-09-28 03:27:33.354 UTC [35017] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13332026/09/28 03:27:33 OK 20241026095416_initial_model.sql (59.52ms)13342026/09/28 03:27:33 OK 20251210153512_drop_unused_gin_index.sql (7.06ms)1335--- PASS: TestService_ReadAuthMiddleware (1.64s)13362026/09/28 03:27:33 OK 20251218171726_add_pins.sql (15.82ms)1337=== CONT TestReadProxyNarinfoAlreadyDecompressed13382026/09/28 03:27:33 OK 20260628120000_add_object_size_and_stats.sql (22.2ms)13392026/09/28 03:27:33 OK 20260905000000_add_claims.sql (8.13ms)13402026/09/28 03:27:33 OK 20260920000000_drop_claims.sql (1.47ms)13412026/09/28 03:27:33 OK 20260923120000_add_pushes.sql (2ms)13422026/09/28 03:27:33 goose: successfully migrated database to version: 2026092312000013432026/09/28 03:27:33 OK 1_commit_pending_closure.sql (2.47ms)13442026/09/28 03:27:33 OK 2_object_stats_trigger.sql (1ms)13452026/09/28 03:27:33 OK 3_commit_push.sql (960.42µs)13462026/09/28 03:27:33 goose: up to current file version: 313472026/09/28 03:27:33 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"13482026/09/28 03:27:33 WARN mTLS auth: bound subjects configured but subject DN unavailable13492026/09/28 03:27:33 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1350--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.30s)1351=== CONT TestRedundantMultipartUpload13522026-09-28 03:27:33.718 UTC [35021] ERROR: relation "goose_db_version" does not exist at character 3613532026-09-28 03:27:33.718 UTC [35021] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13542026/09/28 03:27:33 OK 20241026095416_initial_model.sql (15.2ms)13552026/09/28 03:27:33 OK 20251210153512_drop_unused_gin_index.sql (1.25ms)13562026/09/28 03:27:33 OK 20251218171726_add_pins.sql (4.27ms)13572026/09/28 03:27:33 OK 20260628120000_add_object_size_and_stats.sql (5.68ms)13582026-09-28 03:27:33.771 UTC [35023] ERROR: relation "goose_db_version" does not exist at character 3613592026-09-28 03:27:33.771 UTC [35023] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13602026/09/28 03:27:33 OK 20260905000000_add_claims.sql (6.94ms)13612026/09/28 03:27:33 OK 20260920000000_drop_claims.sql (644.88µs)13622026/09/28 03:27:33 OK 20260923120000_add_pushes.sql (446.17µs)13632026/09/28 03:27:33 goose: successfully migrated database to version: 2026092312000013642026/09/28 03:27:33 OK 1_commit_pending_closure.sql (883.29µs)13652026/09/28 03:27:33 OK 2_object_stats_trigger.sql (223.38µs)13662026/09/28 03:27:33 OK 3_commit_push.sql (193.96µs)13672026/09/28 03:27:33 goose: up to current file version: 313682026/09/28 03:27:33 OK 20241026095416_initial_model.sql (68.09ms)13692026/09/28 03:27:33 OK 20251210153512_drop_unused_gin_index.sql (9.11ms)13702026/09/28 03:27:33 OK 20251218171726_add_pins.sql (24.89ms)13712026/09/28 03:27:33 OK 20260628120000_add_object_size_and_stats.sql (18.14ms)13722026/09/28 03:27:33 OK 20260905000000_add_claims.sql (28.29ms)13732026/09/28 03:27:33 OK 20260920000000_drop_claims.sql (12.38ms)13742026/09/28 03:27:33 OK 20260923120000_add_pushes.sql (23.26ms)13752026/09/28 03:27:33 goose: successfully migrated database to version: 2026092312000013762026/09/28 03:27:33 OK 1_commit_pending_closure.sql (880.96µs)13772026/09/28 03:27:33 OK 2_object_stats_trigger.sql (222.92µs)13782026/09/28 03:27:33 OK 3_commit_push.sql (201.5µs)13792026/09/28 03:27:33 goose: up to current file version: 31380--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.29s)1381=== CONT TestReadProxyNarinfo13822026-09-28 03:27:34.018 UTC [35024] ERROR: relation "goose_db_version" does not exist at character 3613832026-09-28 03:27:34.018 UTC [35024] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13842026-09-28 03:27:34.019 UTC [35025] ERROR: relation "goose_db_version" does not exist at character 3613852026-09-28 03:27:34.019 UTC [35025] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13862026/09/28 03:27:34 OK 20241026095416_initial_model.sql (107.14ms)13872026/09/28 03:27:34 OK 20251210153512_drop_unused_gin_index.sql (2.17ms)13882026/09/28 03:27:34 OK 20241026095416_initial_model.sql (110.68ms)13892026/09/28 03:27:34 OK 20251210153512_drop_unused_gin_index.sql (10.05ms)13902026/09/28 03:27:34 OK 20251218171726_add_pins.sql (15.08ms)13912026/09/28 03:27:34 OK 20251218171726_add_pins.sql (13.35ms)13922026-09-28 03:27:34.249 UTC [35030] ERROR: relation "goose_db_version" does not exist at character 3613932026-09-28 03:27:34.249 UTC [35030] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13942026-09-28 03:27:34.258 UTC [35031] ERROR: relation "goose_db_version" does not exist at character 3613952026-09-28 03:27:34.258 UTC [35031] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13962026/09/28 03:27:34 OK 20260628120000_add_object_size_and_stats.sql (33.95ms)13972026/09/28 03:27:34 OK 20260628120000_add_object_size_and_stats.sql (44.33ms)13982026/09/28 03:27:34 OK 20260905000000_add_claims.sql (36.17ms)13992026/09/28 03:27:34 OK 20260905000000_add_claims.sql (37.6ms)14002026/09/28 03:27:34 OK 20260920000000_drop_claims.sql (16.79ms)14012026/09/28 03:27:34 OK 20260920000000_drop_claims.sql (18.3ms)14022026/09/28 03:27:34 OK 20260923120000_add_pushes.sql (10.68ms)14032026/09/28 03:27:34 goose: successfully migrated database to version: 2026092312000014042026/09/28 03:27:34 OK 20260923120000_add_pushes.sql (11.07ms)14052026/09/28 03:27:34 goose: successfully migrated database to version: 202609231200001406--- PASS: TestMetricsInventory (1.41s)1407=== CONT TestIsValidCachePath1408=== RUN TestIsValidCachePath/narinfo1409=== PAUSE TestIsValidCachePath/narinfo1410=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1411=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1412=== RUN TestIsValidCachePath/nar_zst1413=== PAUSE TestIsValidCachePath/nar_zst1414=== RUN TestIsValidCachePath/nar_xz1415=== PAUSE TestIsValidCachePath/nar_xz1416=== RUN TestIsValidCachePath/nar_bz21417=== PAUSE TestIsValidCachePath/nar_bz21418=== RUN TestIsValidCachePath/nar_uncompressed1419=== PAUSE TestIsValidCachePath/nar_uncompressed1420=== RUN TestIsValidCachePath/ls1421=== PAUSE TestIsValidCachePath/ls1422=== RUN TestIsValidCachePath/log1423=== PAUSE TestIsValidCachePath/log1424=== RUN TestIsValidCachePath/realisation1425=== PAUSE TestIsValidCachePath/realisation1426=== RUN TestIsValidCachePath/nix-cache-info1427=== PAUSE TestIsValidCachePath/nix-cache-info1428=== RUN TestIsValidCachePath/index.html1429=== PAUSE TestIsValidCachePath/index.html1430=== RUN TestIsValidCachePath/traversal_parent1431=== PAUSE TestIsValidCachePath/traversal_parent1432=== RUN TestIsValidCachePath/traversal_in_middle1433=== PAUSE TestIsValidCachePath/traversal_in_middle1434=== RUN TestIsValidCachePath/invalid_char_e1435=== PAUSE TestIsValidCachePath/invalid_char_e1436=== RUN TestIsValidCachePath/invalid_char_u1437=== PAUSE TestIsValidCachePath/invalid_char_u1438=== RUN TestIsValidCachePath/random_path1439=== PAUSE TestIsValidCachePath/random_path1440=== RUN TestIsValidCachePath/empty1441=== PAUSE TestIsValidCachePath/empty1442=== RUN TestIsValidCachePath/leading_slash1443=== PAUSE TestIsValidCachePath/leading_slash1444=== RUN TestIsValidCachePath/wrong_extension1445=== PAUSE TestIsValidCachePath/wrong_extension1446=== RUN TestIsValidCachePath/short_hash1447=== PAUSE TestIsValidCachePath/short_hash1448=== CONT TestPush_SignsNarinfosOfItsPendingObjects14492026/09/28 03:27:34 OK 1_commit_pending_closure.sql (2.53ms)14502026/09/28 03:27:34 OK 1_commit_pending_closure.sql (2.87ms)14512026/09/28 03:27:34 OK 2_object_stats_trigger.sql (701.54µs)14522026/09/28 03:27:34 OK 2_object_stats_trigger.sql (565.38µs)14532026/09/28 03:27:34 OK 3_commit_push.sql (421.25µs)14542026/09/28 03:27:34 goose: up to current file version: 314552026/09/28 03:27:34 OK 3_commit_push.sql (437.58µs)14562026/09/28 03:27:34 goose: up to current file version: 314572026/09/28 03:27:34 OK 20241026095416_initial_model.sql (88.88ms)14582026/09/28 03:27:34 OK 20241026095416_initial_model.sql (79.56ms)14592026/09/28 03:27:34 OK 20251210153512_drop_unused_gin_index.sql (5.89ms)14602026/09/28 03:27:34 OK 20251210153512_drop_unused_gin_index.sql (9.66ms)14612026-09-28 03:27:34.403 UTC [35034] ERROR: relation "goose_db_version" does not exist at character 3614622026-09-28 03:27:34.403 UTC [35034] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14632026/09/28 03:27:34 OK 20251218171726_add_pins.sql (14.93ms)14642026/09/28 03:27:34 OK 20251218171726_add_pins.sql (9.97ms)14652026/09/28 03:27:34 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01466=== NAME TestClientIntegration1467 client_integration_test.go:323: Objects in database after GC:1468 client_integration_test.go:323: Successfully deleted all objects with GC --force14692026/09/28 03:27:34 OK 20260628120000_add_object_size_and_stats.sql (19.37ms)14702026/09/28 03:27:34 OK 20260628120000_add_object_size_and_stats.sql (19.29ms)1471--- PASS: TestClientIntegration (3.80s)1472=== CONT TestReadRedirectNar14732026/09/28 03:27:34 OK 20260905000000_add_claims.sql (26.99ms)14742026/09/28 03:27:34 OK 20260905000000_add_claims.sql (34.65ms)14752026/09/28 03:27:34 OK 20260920000000_drop_claims.sql (18.32ms)14762026/09/28 03:27:34 OK 20260920000000_drop_claims.sql (21.36ms)14772026/09/28 03:27:34 OK 20260923120000_add_pushes.sql (15.85ms)14782026/09/28 03:27:34 goose: successfully migrated database to version: 2026092312000014792026/09/28 03:27:34 OK 1_commit_pending_closure.sql (1.1ms)14802026/09/28 03:27:34 OK 2_object_stats_trigger.sql (206.29µs)14812026/09/28 03:27:34 OK 3_commit_push.sql (179µs)14822026/09/28 03:27:34 goose: up to current file version: 314832026/09/28 03:27:34 OK 20260923120000_add_pushes.sql (14.44ms)14842026/09/28 03:27:34 goose: successfully migrated database to version: 2026092312000014852026/09/28 03:27:34 OK 1_commit_pending_closure.sql (2.15ms)14862026/09/28 03:27:34 OK 2_object_stats_trigger.sql (515.79µs)14872026/09/28 03:27:34 OK 3_commit_push.sql (396.46µs)14882026/09/28 03:27:34 goose: up to current file version: 314892026-09-28 03:27:34.522 UTC [35037] ERROR: relation "goose_db_version" does not exist at character 3614902026-09-28 03:27:34.522 UTC [35037] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14912026/09/28 03:27:34 OK 20241026095416_initial_model.sql (118.71ms)14922026/09/28 03:27:34 OK 20251210153512_drop_unused_gin_index.sql (12.83ms)14932026/09/28 03:27:34 OK 20251218171726_add_pins.sql (26.47ms)14942026/09/28 03:27:34 OK 20260628120000_add_object_size_and_stats.sql (10.84ms)14952026/09/28 03:27:34 OK 20260905000000_add_claims.sql (24.6ms)14962026/09/28 03:27:34 OK 20260920000000_drop_claims.sql (8.16ms)14972026/09/28 03:27:34 OK 20241026095416_initial_model.sql (60.94ms)14982026/09/28 03:27:34 OK 20251210153512_drop_unused_gin_index.sql (14.68ms)14992026/09/28 03:27:34 OK 20260923120000_add_pushes.sql (22.45ms)15002026/09/28 03:27:34 goose: successfully migrated database to version: 2026092312000015012026/09/28 03:27:34 OK 1_commit_pending_closure.sql (853µs)15022026/09/28 03:27:34 OK 2_object_stats_trigger.sql (180.88µs)15032026/09/28 03:27:34 OK 3_commit_push.sql (159.33µs)15042026/09/28 03:27:34 goose: up to current file version: 315052026/09/28 03:27:34 OK 20251218171726_add_pins.sql (18.64ms)15062026/09/28 03:27:34 OK 20260628120000_add_object_size_and_stats.sql (19.87ms)15072026/09/28 03:27:34 WARN mTLS auth: subject not in bound subjects subject="CN=reader"15082026/09/28 03:27:34 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1509--- PASS: TestService_NativeMTLS (1.70s)1510=== CONT TestReadRedirectKeepsNarinfoProxied1511=== NAME TestNARDeduplicationMetadataUploadBug1512 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-34546-2893374115/TestNARDeduplicationMetadataUploadBug4218721722/001/store/a7h5li5gi885js9pmqh5yxlb39nmbyn2-file1.txt15132026/09/28 03:27:34 OK 20260905000000_add_claims.sql (27.6ms)15142026/09/28 03:27:34 OK 20260920000000_drop_claims.sql (19.87ms)15152026/09/28 03:27:34 OK 20260923120000_add_pushes.sql (4.95ms)15162026/09/28 03:27:34 goose: successfully migrated database to version: 2026092312000015172026/09/28 03:27:34 OK 1_commit_pending_closure.sql (1.45ms)15182026/09/28 03:27:34 OK 2_object_stats_trigger.sql (232.75µs)15192026/09/28 03:27:34 OK 3_commit_push.sql (169.46µs)15202026/09/28 03:27:34 goose: up to current file version: 315212026-09-28 03:27:34.769 UTC [35045] ERROR: relation "goose_db_version" does not exist at character 3615222026-09-28 03:27:34.769 UTC [35045] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15232026/09/28 03:27:34 INFO Received push request method=POST path=/api/pushes15242026/09/28 03:27:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15252026/09/28 03:27:34 INFO Uploading a7h5li5gi885js9pmqh5yxlb39nmbyn2-file1.txt (160B)15262026/09/28 03:27:34 WARN Failed to register uploaded object key=a7h5li5gi885js9pmqh5yxlb39nmbyn2.ls error="server returned 404: 404 page not found\n"15272026/09/28 03:27:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15282026/09/28 03:27:34 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"15292026/09/28 03:27:34 INFO Signed narinfos id=1 count=115302026/09/28 03:27:34 INFO Uploading 1 narinfos15312026/09/28 03:27:34 INFO Received complete push request method=POST path=/api/pushes/1/complete15322026/09/28 03:27:34 WARN Failed to register uploaded object key=a7h5li5gi885js9pmqh5yxlb39nmbyn2.narinfo error="server returned 404: 404 page not found\n"15332026/09/28 03:27:34 INFO Upload complete. (112ms)1534--- PASS: TestService_healthCheckHandler (1.72s)1535=== CONT TestGCBugBareHashReferences1536=== NAME TestNARDeduplicationMetadataUploadBug1537 metadata_upload_test.go:54: Retrieved narinfo from S3:1538 StorePath: /nix/var/nix/builds/nix-34546-2893374115/TestNARDeduplicationMetadataUploadBug4218721722/001/store/a7h5li5gi885js9pmqh5yxlb39nmbyn2-file1.txt1539 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1540 Compression: zstd1541 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1542 NarSize: 1601543 References: 1544 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1545 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1546 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1547 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1548 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-34546-2893374115/TestNARDeduplicationMetadataUploadBug4218721722/001/store/k722cpyppp25rf6a74jd2bj4zz0535c7-file2.txt15492026/09/28 03:27:34 OK 20241026095416_initial_model.sql (125.07ms)15502026/09/28 03:27:34 OK 20251210153512_drop_unused_gin_index.sql (31.28ms)15512026/09/28 03:27:34 OK 20251218171726_add_pins.sql (8.49ms)15522026/09/28 03:27:34 OK 20260628120000_add_object_size_and_stats.sql (27.37ms)15532026/09/28 03:27:34 INFO Received push request method=POST path=/api/pushes15542026/09/28 03:27:34 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)15552026/09/28 03:27:35 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15562026/09/28 03:27:35 INFO Signed narinfos id=2 count=115572026/09/28 03:27:35 WARN Failed to register uploaded object key=k722cpyppp25rf6a74jd2bj4zz0535c7.ls error="server returned 404: 404 page not found\n"15582026/09/28 03:27:35 INFO Uploading 1 narinfos15592026/09/28 03:27:35 WARN readiness check failed error="closed pool"1560--- PASS: TestService_readinessHandler (1.90s)1561=== CONT TestReadProxyDisabled15622026/09/28 03:27:35 OK 20260905000000_add_claims.sql (31.07ms)15632026/09/28 03:27:35 INFO Received complete push request method=POST path=/api/pushes/2/complete15642026-09-28 03:27:35.028 UTC [35055] ERROR: relation "goose_db_version" does not exist at character 3615652026-09-28 03:27:35.028 UTC [35055] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15662026/09/28 03:27:35 WARN Failed to register uploaded object key=k722cpyppp25rf6a74jd2bj4zz0535c7.narinfo error="server returned 404: 404 page not found\n"15672026/09/28 03:27:35 INFO Upload complete. (83ms)1568=== NAME TestNARDeduplicationMetadataUploadBug1569 metadata_upload_test.go:76: Retrieved narinfo from S3:1570 StorePath: /nix/var/nix/builds/nix-34546-2893374115/TestNARDeduplicationMetadataUploadBug4218721722/001/store/k722cpyppp25rf6a74jd2bj4zz0535c7-file2.txt1571 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1572 Compression: zstd1573 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1574 NarSize: 1601575 References: 1576 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1577 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1578 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1579 {"version":1,"root":{"type":"regular","size":44}}15802026/09/28 03:27:35 OK 20260920000000_drop_claims.sql (38.14ms)15812026/09/28 03:27:35 OK 20260923120000_add_pushes.sql (10.64ms)15822026/09/28 03:27:35 goose: successfully migrated database to version: 2026092312000015832026/09/28 03:27:35 OK 1_commit_pending_closure.sql (1.03ms)15842026/09/28 03:27:35 OK 2_object_stats_trigger.sql (197.42µs)15852026/09/28 03:27:35 OK 3_commit_push.sql (169.33µs)15862026/09/28 03:27:35 goose: up to current file version: 31587--- PASS: TestNARDeduplicationMetadataUploadBug (2.09s)1588=== CONT TestReadProxyRootRedirectsToIndexHTML15892026/09/28 03:27:35 OK 20241026095416_initial_model.sql (76.4ms)15902026/09/28 03:27:35 OK 20251210153512_drop_unused_gin_index.sql (796µs)15912026/09/28 03:27:35 OK 20251218171726_add_pins.sql (9.41ms)15922026/09/28 03:27:35 INFO Starting HTTP server address=127.0.0.1:6374015932026/09/28 03:27:35 INFO Starting HTTP server address=/nix/var/nix/builds/nix-34546-2893374115/TestProxyHeadersOnlyTrustedOnSocket1927223748/001/proxy.sock15942026/09/28 03:27:35 WARN mTLS auth: subject not in bound subjects subject="CN=someone"15952026/09/28 03:27:35 INFO Shutdown signal received, draining in-flight requests timeout=10s15962026/09/28 03:27:35 OK 20260628120000_add_object_size_and_stats.sql (23.73ms)1597--- PASS: TestProxyHeadersOnlyTrustedOnSocket (1.90s)1598=== CONT TestGCMetrics15992026/09/28 03:27:35 OK 20260905000000_add_claims.sql (44.84ms)16002026/09/28 03:27:35 OK 20260920000000_drop_claims.sql (3.34ms)16012026/09/28 03:27:35 OK 20260923120000_add_pushes.sql (11.01ms)16022026/09/28 03:27:35 goose: successfully migrated database to version: 2026092312000016032026/09/28 03:27:35 OK 1_commit_pending_closure.sql (1.47ms)16042026/09/28 03:27:35 OK 2_object_stats_trigger.sql (257.58µs)16052026/09/28 03:27:35 OK 3_commit_push.sql (231.79µs)16062026/09/28 03:27:35 goose: up to current file version: 316072026-09-28 03:27:35.357 UTC [35065] ERROR: relation "goose_db_version" does not exist at character 3616082026-09-28 03:27:35.357 UTC [35065] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1609--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.92s)1610=== CONT TestReadProxyConditionalGet16112026/09/28 03:27:35 OK 20241026095416_initial_model.sql (148.68ms)16122026/09/28 03:27:35 OK 20251210153512_drop_unused_gin_index.sql (4.94ms)16132026/09/28 03:27:35 OK 20251218171726_add_pins.sql (29.99ms)16142026/09/28 03:27:35 INFO Received uploads request method=POST path=/api/pending_closures16152026/09/28 03:27:35 OK 20260628120000_add_object_size_and_stats.sql (38.31ms)16162026-09-28 03:27:35.665 UTC [35072] ERROR: relation "goose_db_version" does not exist at character 3616172026-09-28 03:27:35.665 UTC [35072] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16182026/09/28 03:27:35 INFO Received uploads request method=POST path=/api/pending_closures16192026/09/28 03:27:35 OK 20260905000000_add_claims.sql (137.6ms)16202026/09/28 03:27:35 OK 20260920000000_drop_claims.sql (16.73ms)16212026/09/28 03:27:35 OK 20260923120000_add_pushes.sql (19.33ms)16222026/09/28 03:27:35 goose: successfully migrated database to version: 2026092312000016232026/09/28 03:27:35 OK 1_commit_pending_closure.sql (1.91ms)16242026/09/28 03:27:35 OK 2_object_stats_trigger.sql (385.75µs)16252026/09/28 03:27:35 OK 3_commit_push.sql (350.75µs)16262026/09/28 03:27:35 goose: up to current file version: 316272026/09/28 03:27:35 OK 20241026095416_initial_model.sql (144.43ms)16282026/09/28 03:27:35 OK 20251210153512_drop_unused_gin_index.sql (5.64ms)1629--- PASS: TestReadProxyNarinfo (1.93s)1630=== CONT TestReadProxyHead16312026/09/28 03:27:35 OK 20251218171726_add_pins.sql (51.76ms)16322026/09/28 03:27:36 OK 20260628120000_add_object_size_and_stats.sql (39.35ms)16332026/09/28 03:27:36 OK 20260905000000_add_claims.sql (69.25ms)16342026-09-28 03:27:36.125 UTC [35090] ERROR: relation "goose_db_version" does not exist at character 3616352026-09-28 03:27:36.125 UTC [35090] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16362026/09/28 03:27:36 OK 20260920000000_drop_claims.sql (43.62ms)16372026/09/28 03:27:36 OK 20260923120000_add_pushes.sql (19.79ms)16382026/09/28 03:27:36 goose: successfully migrated database to version: 2026092312000016392026/09/28 03:27:36 OK 1_commit_pending_closure.sql (1.32ms)16402026/09/28 03:27:36 OK 2_object_stats_trigger.sql (338.67µs)16412026/09/28 03:27:36 OK 3_commit_push.sql (323.17µs)16422026/09/28 03:27:36 goose: up to current file version: 316432026/09/28 03:27:36 INFO Received push request method=POST path=/api/pushes16442026/09/28 03:27:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16452026/09/28 03:27:36 INFO Signed narinfos id=1 count=11646--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (2.01s)1647=== CONT TestReadProxyInvalidPath16482026/09/28 03:27:36 OK 20241026095416_initial_model.sql (257.78ms)16492026/09/28 03:27:36 OK 20251210153512_drop_unused_gin_index.sql (9.97ms)16502026/09/28 03:27:36 OK 20251218171726_add_pins.sql (45.7ms)16512026/09/28 03:27:36 OK 20260628120000_add_object_size_and_stats.sql (27.25ms)16522026/09/28 03:27:36 OK 20260905000000_add_claims.sql (98.61ms)1653--- PASS: TestReadRedirectNar (2.25s)1654=== CONT TestReadProxy40416552026/09/28 03:27:36 OK 20260920000000_drop_claims.sql (65.98ms)16562026/09/28 03:27:36 OK 20260923120000_add_pushes.sql (16.12ms)16572026/09/28 03:27:36 goose: successfully migrated database to version: 2026092312000016582026/09/28 03:27:36 OK 1_commit_pending_closure.sql (1.06ms)16592026/09/28 03:27:36 OK 2_object_stats_trigger.sql (281.25µs)16602026/09/28 03:27:36 OK 3_commit_push.sql (240.5µs)16612026/09/28 03:27:36 goose: up to current file version: 316622026-09-28 03:27:36.865 UTC [35104] ERROR: relation "goose_db_version" does not exist at character 3616632026-09-28 03:27:36.865 UTC [35104] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16642026-09-28 03:27:37.036 UTC [35105] ERROR: relation "goose_db_version" does not exist at character 3616652026-09-28 03:27:37.036 UTC [35105] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1666--- PASS: TestReadRedirectKeepsNarinfoProxied (2.42s)1667=== CONT TestPush_RejectsBadRequests16682026/09/28 03:27:37 OK 20241026095416_initial_model.sql (251.72ms)16692026/09/28 03:27:37 OK 20251210153512_drop_unused_gin_index.sql (14.62ms)16702026/09/28 03:27:37 OK 20251218171726_add_pins.sql (72.1ms)16712026-09-28 03:27:37.294 UTC [35108] ERROR: relation "goose_db_version" does not exist at character 3616722026-09-28 03:27:37.294 UTC [35108] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16732026/09/28 03:27:37 OK 20260628120000_add_object_size_and_stats.sql (31.5ms)16742026/09/28 03:27:37 OK 20260905000000_add_claims.sql (16.04ms)16752026-09-28 03:27:37.316 UTC [35109] ERROR: relation "goose_db_version" does not exist at character 3616762026-09-28 03:27:37.316 UTC [35109] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16772026/09/28 03:27:37 OK 20241026095416_initial_model.sql (127.75ms)16782026/09/28 03:27:37 OK 20260920000000_drop_claims.sql (3.85ms)16792026/09/28 03:27:37 OK 20251210153512_drop_unused_gin_index.sql (2.15ms)16802026/09/28 03:27:37 OK 20260923120000_add_pushes.sql (2.25ms)16812026/09/28 03:27:37 goose: successfully migrated database to version: 2026092312000016822026/09/28 03:27:37 OK 20251218171726_add_pins.sql (3.1ms)16832026/09/28 03:27:37 OK 1_commit_pending_closure.sql (2.3ms)16842026/09/28 03:27:37 OK 2_object_stats_trigger.sql (290.88µs)16852026/09/28 03:27:37 OK 3_commit_push.sql (244.42µs)16862026/09/28 03:27:37 goose: up to current file version: 316872026-09-28 03:27:37.326 UTC [35110] ERROR: relation "goose_db_version" does not exist at character 3616882026-09-28 03:27:37.326 UTC [35110] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16892026/09/28 03:27:37 OK 20260628120000_add_object_size_and_stats.sql (25.45ms)16902026/09/28 03:27:37 OK 20241026095416_initial_model.sql (53.96ms)16912026/09/28 03:27:37 OK 20260905000000_add_claims.sql (25.41ms)16922026/09/28 03:27:37 OK 20251210153512_drop_unused_gin_index.sql (8.27ms)16932026/09/28 03:27:37 OK 20260920000000_drop_claims.sql (22.22ms)16942026/09/28 03:27:37 OK 20251218171726_add_pins.sql (16.34ms)16952026/09/28 03:27:37 OK 20260923120000_add_pushes.sql (10.29ms)16962026/09/28 03:27:37 goose: successfully migrated database to version: 2026092312000016972026/09/28 03:27:37 OK 1_commit_pending_closure.sql (2.37ms)16982026/09/28 03:27:37 OK 2_object_stats_trigger.sql (499.67µs)16992026/09/28 03:27:37 OK 3_commit_push.sql (439.38µs)17002026/09/28 03:27:37 goose: up to current file version: 317012026/09/28 03:27:37 OK 20260628120000_add_object_size_and_stats.sql (22.01ms)17022026/09/28 03:27:37 OK 20241026095416_initial_model.sql (66.67ms)17032026/09/28 03:27:37 OK 20251210153512_drop_unused_gin_index.sql (1.2ms)17042026/09/28 03:27:37 OK 20260905000000_add_claims.sql (2.86ms)17052026/09/28 03:27:37 OK 20260920000000_drop_claims.sql (25.21ms)17062026/09/28 03:27:37 OK 20251218171726_add_pins.sql (25.84ms)17072026/09/28 03:27:37 OK 20260923120000_add_pushes.sql (18.83ms)17082026/09/28 03:27:37 goose: successfully migrated database to version: 2026092312000017092026/09/28 03:27:37 OK 1_commit_pending_closure.sql (2.9ms)17102026/09/28 03:27:37 OK 2_object_stats_trigger.sql (560.21µs)17112026/09/28 03:27:37 OK 3_commit_push.sql (482.13µs)17122026/09/28 03:27:37 goose: up to current file version: 317132026/09/28 03:27:37 OK 20260628120000_add_object_size_and_stats.sql (33.6ms)17142026/09/28 03:27:37 OK 20241026095416_initial_model.sql (107.38ms)17152026/09/28 03:27:37 OK 20251210153512_drop_unused_gin_index.sql (19.37ms)17162026/09/28 03:27:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17172026/09/28 03:27:37 OK 20260905000000_add_claims.sql (81.54ms)17182026/09/28 03:27:37 OK 20251218171726_add_pins.sql (57.29ms)17192026/09/28 03:27:37 OK 20260920000000_drop_claims.sql (40.94ms)17202026/09/28 03:27:37 OK 20260628120000_add_object_size_and_stats.sql (50.74ms)17212026/09/28 03:27:37 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NTg0YzlkZmItNmU2OC00ZDFiLWE1MTItN2JkNTNjOGQxYTQzLjFhNmNlNzJjLTZmMjktNDA2NC05OTYzLTE4YWRmNTUyZTQ4ZHgxNzkwNTY2MDU1NjQ0ODIwMDAw parts=121722--- PASS: TestRedundantMultipartUpload (3.92s)1723=== CONT TestPush_CommitFailsWhenSkippedKeyWasCollected17242026/09/28 03:27:37 OK 20260923120000_add_pushes.sql (26.07ms)17252026/09/28 03:27:37 goose: successfully migrated database to version: 2026092312000017262026/09/28 03:27:37 OK 1_commit_pending_closure.sql (4.28ms)17272026/09/28 03:27:37 OK 2_object_stats_trigger.sql (917.17µs)17282026/09/28 03:27:37 OK 3_commit_push.sql (739.96µs)17292026/09/28 03:27:37 goose: up to current file version: 317302026/09/28 03:27:37 OK 20260905000000_add_claims.sql (60.36ms)17312026/09/28 03:27:37 OK 20260920000000_drop_claims.sql (29.09ms)17322026/09/28 03:27:37 OK 20260923120000_add_pushes.sql (14.4ms)17332026/09/28 03:27:37 goose: successfully migrated database to version: 2026092312000017342026/09/28 03:27:37 OK 1_commit_pending_closure.sql (2.98ms)17352026/09/28 03:27:37 OK 2_object_stats_trigger.sql (728.38µs)17362026/09/28 03:27:37 OK 3_commit_push.sql (634.08µs)17372026/09/28 03:27:37 goose: up to current file version: 31738--- PASS: TestGCBugBareHashReferences (3.00s)1739=== CONT TestPush_CompleteCommitsEveryRoot1740--- PASS: TestReadProxyDisabled (2.84s)1741=== CONT TestPush_OverlappingRootsStoreOneRowPerKey17422026-09-28 03:27:38.068 UTC [35119] ERROR: relation "goose_db_version" does not exist at character 3617432026-09-28 03:27:38.068 UTC [35119] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1744--- PASS: TestReadProxyRootRedirectsToIndexHTML (3.00s)1745=== CONT TestReadRedirectUsesPublicS3URL17462026/09/28 03:27:38 INFO Aborted multipart uploads count=017472026/09/28 03:27:38 WARN Force mode enabled - objects will be deleted immediately without grace period17482026/09/28 03:27:38 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=017492026/09/28 03:27:38 INFO Vacuumed table table=pending_closures17502026/09/28 03:27:38 INFO Vacuumed table table=pending_objects17512026/09/28 03:27:38 INFO Vacuumed table table=multipart_uploads17522026/09/28 03:27:38 INFO Vacuumed table table=closures17532026/09/28 03:27:38 INFO Vacuumed table table=objects1754--- PASS: TestGCMetrics (3.19s)1755=== CONT TestReadProxyRangeRequest17562026/09/28 03:27:38 OK 20241026095416_initial_model.sql (205.48ms)17572026/09/28 03:27:38 OK 20251210153512_drop_unused_gin_index.sql (12.1ms)17582026/09/28 03:27:38 OK 20251218171726_add_pins.sql (8.83ms)17592026/09/28 03:27:38 OK 20260628120000_add_object_size_and_stats.sql (62.81ms)17602026-09-28 03:27:38.532 UTC [35132] ERROR: relation "goose_db_version" does not exist at character 3617612026-09-28 03:27:38.532 UTC [35132] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17622026/09/28 03:27:38 OK 20260905000000_add_claims.sql (76.1ms)17632026/09/28 03:27:38 OK 20260920000000_drop_claims.sql (30.32ms)17642026/09/28 03:27:38 OK 20260923120000_add_pushes.sql (17.15ms)17652026/09/28 03:27:38 goose: successfully migrated database to version: 2026092312000017662026/09/28 03:27:38 OK 1_commit_pending_closure.sql (1.4ms)17672026/09/28 03:27:38 OK 2_object_stats_trigger.sql (256.29µs)17682026/09/28 03:27:38 OK 3_commit_push.sql (245.38µs)17692026/09/28 03:27:38 goose: up to current file version: 31770--- PASS: TestReadProxyConditionalGet (3.32s)1771=== CONT TestIsValidUploadKey1772=== RUN TestIsValidUploadKey/narinfo1773=== PAUSE TestIsValidUploadKey/narinfo1774=== RUN TestIsValidUploadKey/nar_zst1775=== PAUSE TestIsValidUploadKey/nar_zst1776=== RUN TestIsValidUploadKey/nar_xz1777=== PAUSE TestIsValidUploadKey/nar_xz1778=== RUN TestIsValidUploadKey/nar_plain1779=== PAUSE TestIsValidUploadKey/nar_plain1780=== RUN TestIsValidUploadKey/listing1781=== PAUSE TestIsValidUploadKey/listing1782=== RUN TestIsValidUploadKey/build_log1783=== PAUSE TestIsValidUploadKey/build_log1784=== RUN TestIsValidUploadKey/build_log_home-manager_file1785=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1786=== RUN TestIsValidUploadKey/build_log_plus_in_name1787=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1788=== RUN TestIsValidUploadKey/build_log_question_mark1789=== PAUSE TestIsValidUploadKey/build_log_question_mark1790=== RUN TestIsValidUploadKey/build_log_equals1791=== PAUSE TestIsValidUploadKey/build_log_equals1792=== RUN TestIsValidUploadKey/realisation1793=== PAUSE TestIsValidUploadKey/realisation1794=== RUN TestIsValidUploadKey/realisation_plus_in_output1795=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1796=== RUN TestIsValidUploadKey/nix-cache-info1797=== PAUSE TestIsValidUploadKey/nix-cache-info1798=== RUN TestIsValidUploadKey/index.html1799=== PAUSE TestIsValidUploadKey/index.html1800=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1801=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1802=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1803=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1804=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1805=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1806=== RUN TestIsValidUploadKey/traversal1807=== PAUSE TestIsValidUploadKey/traversal1808=== RUN TestIsValidUploadKey/traversal_nar1809=== PAUSE TestIsValidUploadKey/traversal_nar1810=== RUN TestIsValidUploadKey/absolute1811=== PAUSE TestIsValidUploadKey/absolute1812=== RUN TestIsValidUploadKey/empty_key1813=== PAUSE TestIsValidUploadKey/empty_key1814=== RUN TestIsValidUploadKey/unknown_type1815=== PAUSE TestIsValidUploadKey/unknown_type1816=== CONT TestGCTaskStore_PhaseUpdates1817--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1818=== CONT TestGCTaskStore_Fail1819--- PASS: TestGCTaskStore_Fail (0.00s)1820=== CONT TestCreatePin_ReservedPins18212026/09/28 03:27:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63776/oidc18222026-09-28 03:27:38.749 UTC [35133] ERROR: relation "goose_db_version" does not exist at character 3618232026-09-28 03:27:38.749 UTC [35133] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18242026/09/28 03:27:38 OK 20241026095416_initial_model.sql (190.47ms)18252026/09/28 03:27:38 OK 20251210153512_drop_unused_gin_index.sql (15.99ms)18262026/09/28 03:27:38 OK 20251218171726_add_pins.sql (8.88ms)18272026/09/28 03:27:38 OK 20260628120000_add_object_size_and_stats.sql (45.17ms)18282026/09/28 03:27:38 OK 20260905000000_add_claims.sql (38.79ms)18292026/09/28 03:27:38 OK 20260920000000_drop_claims.sql (32.52ms)18302026/09/28 03:27:38 OK 20260923120000_add_pushes.sql (7.89ms)18312026/09/28 03:27:38 goose: successfully migrated database to version: 2026092312000018322026/09/28 03:27:38 OK 1_commit_pending_closure.sql (1.04ms)18332026/09/28 03:27:38 OK 2_object_stats_trigger.sql (253.58µs)18342026/09/28 03:27:38 OK 3_commit_push.sql (220.33µs)18352026/09/28 03:27:38 goose: up to current file version: 318362026/09/28 03:27:38 OK 20241026095416_initial_model.sql (179ms)1837--- PASS: TestReadProxyHead (3.05s)1838=== CONT TestParseSingleRange1839=== RUN TestParseSingleRange/none1840=== PAUSE TestParseSingleRange/none1841=== RUN TestParseSingleRange/unknown_unit1842=== PAUSE TestParseSingleRange/unknown_unit1843=== RUN TestParseSingleRange/multi-range_ignored1844=== PAUSE TestParseSingleRange/multi-range_ignored1845=== RUN TestParseSingleRange/malformed_no_dash1846=== PAUSE TestParseSingleRange/malformed_no_dash1847=== RUN TestParseSingleRange/malformed_both_empty1848=== PAUSE TestParseSingleRange/malformed_both_empty1849=== RUN TestParseSingleRange/malformed_end_before_start1850=== PAUSE TestParseSingleRange/malformed_end_before_start1851=== RUN TestParseSingleRange/closed1852=== PAUSE TestParseSingleRange/closed1853=== RUN TestParseSingleRange/open-ended1854=== PAUSE TestParseSingleRange/open-ended1855=== RUN TestParseSingleRange/end_clamped_to_size1856=== PAUSE TestParseSingleRange/end_clamped_to_size1857=== RUN TestParseSingleRange/suffix1858=== PAUSE TestParseSingleRange/suffix1859=== RUN TestParseSingleRange/suffix_exceeds_size1860=== PAUSE TestParseSingleRange/suffix_exceeds_size1861=== RUN TestParseSingleRange/single_byte1862=== PAUSE TestParseSingleRange/single_byte1863=== RUN TestParseSingleRange/start_past_EOF1864=== PAUSE TestParseSingleRange/start_past_EOF1865=== RUN TestParseSingleRange/start_far_past_EOF1866=== PAUSE TestParseSingleRange/start_far_past_EOF1867=== CONT TestService_createPendingClosureHandler18682026/09/28 03:27:39 OK 20251210153512_drop_unused_gin_index.sql (13.05ms)18692026/09/28 03:27:39 OK 20251218171726_add_pins.sql (33.35ms)18702026/09/28 03:27:39 OK 20260628120000_add_object_size_and_stats.sql (46.55ms)18712026-09-28 03:27:39.101 UTC [35138] ERROR: relation "goose_db_version" does not exist at character 3618722026-09-28 03:27:39.101 UTC [35138] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18732026/09/28 03:27:39 OK 20260905000000_add_claims.sql (90.41ms)18742026/09/28 03:27:39 OK 20260920000000_drop_claims.sql (35.58ms)18752026/09/28 03:27:39 OK 20260923120000_add_pushes.sql (9.24ms)18762026/09/28 03:27:39 goose: successfully migrated database to version: 2026092312000018772026/09/28 03:27:39 OK 1_commit_pending_closure.sql (896µs)18782026/09/28 03:27:39 OK 2_object_stats_trigger.sql (217.83µs)18792026/09/28 03:27:39 OK 3_commit_push.sql (175.83µs)18802026/09/28 03:27:39 goose: up to current file version: 31881--- PASS: TestReadProxyInvalidPath (2.91s)1882=== CONT TestCompleteMultipartUnregistered18832026/09/28 03:27:39 OK 20241026095416_initial_model.sql (188.72ms)18842026/09/28 03:27:39 OK 20251210153512_drop_unused_gin_index.sql (10.39ms)18852026/09/28 03:27:39 OK 20251218171726_add_pins.sql (17.76ms)18862026/09/28 03:27:39 OK 20260628120000_add_object_size_and_stats.sql (36.36ms)18872026/09/28 03:27:39 OK 20260905000000_add_claims.sql (61.8ms)18882026/09/28 03:27:39 OK 20260920000000_drop_claims.sql (21.46ms)18892026/09/28 03:27:39 OK 20260923120000_add_pushes.sql (7.9ms)18902026/09/28 03:27:39 goose: successfully migrated database to version: 202609231200001891--- PASS: TestReadProxy404 (2.84s)1892=== CONT TestService_verifyS3Integrity18932026/09/28 03:27:39 OK 1_commit_pending_closure.sql (1.17ms)18942026/09/28 03:27:39 OK 2_object_stats_trigger.sql (702.46µs)18952026/09/28 03:27:39 OK 3_commit_push.sql (313.25µs)18962026/09/28 03:27:39 goose: up to current file version: 318972026-09-28 03:27:39.730 UTC [35145] ERROR: relation "goose_db_version" does not exist at character 3618982026-09-28 03:27:39.730 UTC [35145] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1899=== RUN TestPush_RejectsBadRequests/no_objects1900=== PAUSE TestPush_RejectsBadRequests/no_objects1901=== RUN TestPush_RejectsBadRequests/bad_root1902=== PAUSE TestPush_RejectsBadRequests/bad_root1903=== RUN TestPush_RejectsBadRequests/root_not_in_objects1904=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1905=== RUN TestPush_RejectsBadRequests/no_roots1906=== PAUSE TestPush_RejectsBadRequests/no_roots1907=== CONT TestResurrectedObjectNotDeleted19082026/09/28 03:27:39 OK 20241026095416_initial_model.sql (140.04ms)19092026/09/28 03:27:39 OK 20251210153512_drop_unused_gin_index.sql (4.23ms)19102026-09-28 03:27:39.931 UTC [35149] ERROR: relation "goose_db_version" does not exist at character 3619112026-09-28 03:27:39.931 UTC [35149] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19122026-09-28 03:27:39.949 UTC [35150] ERROR: relation "goose_db_version" does not exist at character 3619132026-09-28 03:27:39.949 UTC [35150] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19142026/09/28 03:27:39 OK 20251218171726_add_pins.sql (19.9ms)19152026/09/28 03:27:40 OK 20260628120000_add_object_size_and_stats.sql (56.05ms)19162026-09-28 03:27:40.009 UTC [35151] ERROR: relation "goose_db_version" does not exist at character 3619172026-09-28 03:27:40.009 UTC [35151] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19182026-09-28 03:27:40.012 UTC [35152] ERROR: relation "goose_db_version" does not exist at character 3619192026-09-28 03:27:40.012 UTC [35152] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19202026/09/28 03:27:40 OK 20260905000000_add_claims.sql (5.74ms)19212026/09/28 03:27:40 OK 20260920000000_drop_claims.sql (679.46µs)19222026/09/28 03:27:40 OK 20260923120000_add_pushes.sql (5.96ms)19232026/09/28 03:27:40 goose: successfully migrated database to version: 2026092312000019242026/09/28 03:27:40 OK 20241026095416_initial_model.sql (51.09ms)19252026/09/28 03:27:40 OK 1_commit_pending_closure.sql (2.13ms)19262026/09/28 03:27:40 OK 20251210153512_drop_unused_gin_index.sql (951.33µs)19272026/09/28 03:27:40 OK 2_object_stats_trigger.sql (811.33µs)19282026/09/28 03:27:40 OK 3_commit_push.sql (626.79µs)19292026/09/28 03:27:40 goose: up to current file version: 319302026/09/28 03:27:40 OK 20251218171726_add_pins.sql (2.14ms)19312026/09/28 03:27:40 OK 20241026095416_initial_model.sql (17.26ms)19322026/09/28 03:27:40 OK 20251210153512_drop_unused_gin_index.sql (11.87ms)19332026/09/28 03:27:40 OK 20260628120000_add_object_size_and_stats.sql (19.9ms)19342026/09/28 03:27:40 OK 20251218171726_add_pins.sql (16.19ms)19352026/09/28 03:27:40 OK 20260905000000_add_claims.sql (30.15ms)19362026/09/28 03:27:40 OK 20260628120000_add_object_size_and_stats.sql (21.36ms)19372026/09/28 03:27:40 OK 20241026095416_initial_model.sql (61.44ms)19382026/09/28 03:27:40 OK 20260920000000_drop_claims.sql (19.1ms)19392026/09/28 03:27:40 OK 20251210153512_drop_unused_gin_index.sql (7.92ms)19402026/09/28 03:27:40 OK 20241026095416_initial_model.sql (71.7ms)19412026/09/28 03:27:40 OK 20251210153512_drop_unused_gin_index.sql (7.51ms)19422026/09/28 03:27:40 OK 20260905000000_add_claims.sql (27.92ms)19432026/09/28 03:27:40 OK 20260923120000_add_pushes.sql (9.98ms)19442026/09/28 03:27:40 goose: successfully migrated database to version: 2026092312000019452026/09/28 03:27:40 OK 1_commit_pending_closure.sql (1.14ms)19462026/09/28 03:27:40 OK 2_object_stats_trigger.sql (208.75µs)19472026/09/28 03:27:40 OK 3_commit_push.sql (178.63µs)19482026/09/28 03:27:40 goose: up to current file version: 319492026/09/28 03:27:40 OK 20251218171726_add_pins.sql (19.12ms)19502026/09/28 03:27:40 OK 20260920000000_drop_claims.sql (10.82ms)19512026/09/28 03:27:40 OK 20251218171726_add_pins.sql (11.11ms)19522026/09/28 03:27:40 OK 20260923120000_add_pushes.sql (10.97ms)19532026/09/28 03:27:40 goose: successfully migrated database to version: 2026092312000019542026/09/28 03:27:40 OK 1_commit_pending_closure.sql (964.33µs)19552026/09/28 03:27:40 OK 2_object_stats_trigger.sql (221.13µs)19562026/09/28 03:27:40 OK 3_commit_push.sql (175.83µs)19572026/09/28 03:27:40 goose: up to current file version: 319582026/09/28 03:27:40 OK 20260628120000_add_object_size_and_stats.sql (20.52ms)19592026/09/28 03:27:40 OK 20260628120000_add_object_size_and_stats.sql (25.41ms)19602026/09/28 03:27:40 OK 20260905000000_add_claims.sql (19.65ms)19612026/09/28 03:27:40 OK 20260905000000_add_claims.sql (21.3ms)19622026/09/28 03:27:40 OK 20260920000000_drop_claims.sql (12.69ms)19632026/09/28 03:27:40 OK 20260920000000_drop_claims.sql (6.83ms)19642026/09/28 03:27:40 OK 20260923120000_add_pushes.sql (7.83ms)19652026/09/28 03:27:40 goose: successfully migrated database to version: 2026092312000019662026/09/28 03:27:40 OK 20260923120000_add_pushes.sql (7.98ms)19672026/09/28 03:27:40 goose: successfully migrated database to version: 2026092312000019682026/09/28 03:27:40 OK 1_commit_pending_closure.sql (811.71µs)19692026/09/28 03:27:40 OK 1_commit_pending_closure.sql (719.08µs)19702026/09/28 03:27:40 OK 2_object_stats_trigger.sql (196.33µs)19712026/09/28 03:27:40 OK 2_object_stats_trigger.sql (217.46µs)19722026/09/28 03:27:40 OK 3_commit_push.sql (156.25µs)19732026/09/28 03:27:40 goose: up to current file version: 319742026/09/28 03:27:40 OK 3_commit_push.sql (197.79µs)19752026/09/28 03:27:40 goose: up to current file version: 319762026/09/28 03:27:40 INFO Received push request method=POST path=/api/pushes19772026-09-28 03:27:40.229 UTC [35153] ERROR: relation "goose_db_version" does not exist at character 3619782026-09-28 03:27:40.229 UTC [35153] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19792026/09/28 03:27:40 INFO Received complete push request method=POST path=/api/pushes/1/complete19802026/09/28 03:27:40 INFO Received push request method=POST path=/api/pushes19812026/09/28 03:27:40 INFO Received complete push request method=POST path=/api/pushes/2/complete19822026-09-28 03:27:40.341 UTC [35154] ERROR: Push object missing: aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo19832026-09-28 03:27:40.341 UTC [35154] CONTEXT: PL/pgSQL function commit_push(bigint) line 37 at RAISE19842026-09-28 03:27:40.341 UTC [35154] STATEMENT: -- name: CommitPush :exec1985 SELECT commit_push($1::bigint)1986 1987--- PASS: TestPush_CommitFailsWhenSkippedKeyWasCollected (2.72s)1988=== CONT TestGCTaskStore_CompletedAllowsNewTask1989--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1990=== CONT TestUploadHandlersRejectOversizedBody19912026/09/28 03:27:40 OK 20241026095416_initial_model.sql (74.66ms)1992=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1993=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1994=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1995=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1996=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1997=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1998=== CONT TestService_cleanupPendingClosuresHandler19992026/09/28 03:27:40 OK 20251210153512_drop_unused_gin_index.sql (5.32ms)20002026/09/28 03:27:40 OK 20251218171726_add_pins.sql (15.63ms)20012026/09/28 03:27:40 OK 20260628120000_add_object_size_and_stats.sql (21.9ms)20022026/09/28 03:27:40 OK 20260905000000_add_claims.sql (24.26ms)20032026/09/28 03:27:40 OK 20260920000000_drop_claims.sql (13.25ms)20042026/09/28 03:27:40 OK 20260923120000_add_pushes.sql (6.62ms)20052026/09/28 03:27:40 goose: successfully migrated database to version: 2026092312000020062026/09/28 03:27:40 OK 1_commit_pending_closure.sql (827.04µs)20072026/09/28 03:27:40 OK 2_object_stats_trigger.sql (221.83µs)20082026/09/28 03:27:40 OK 3_commit_push.sql (180.42µs)20092026/09/28 03:27:40 goose: up to current file version: 320102026/09/28 03:27:40 INFO Received push request method=POST path=/api/pushes20112026-09-28 03:27:40.506 UTC [35157] ERROR: relation "goose_db_version" does not exist at character 3620122026-09-28 03:27:40.506 UTC [35157] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20132026/09/28 03:27:40 INFO Received complete push request method=POST path=/api/pushes/1/complete20142026-09-28 03:27:40.559 UTC [35159] ERROR: relation "goose_db_version" does not exist at character 3620152026-09-28 03:27:40.559 UTC [35159] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2016--- PASS: TestPush_CompleteCommitsEveryRoot (2.71s)2017=== CONT TestUploadHandlersRejectInvalidKeys2018=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info2019=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info2020=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal2021=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal2022=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key2023=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key2024=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key2025=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key2026=== CONT TestPresignedUploadRegisteredBeforeCommit20272026/09/28 03:27:40 OK 20241026095416_initial_model.sql (63.64ms)20282026/09/28 03:27:40 OK 20251210153512_drop_unused_gin_index.sql (2.22ms)20292026/09/28 03:27:40 OK 20251218171726_add_pins.sql (10.65ms)20302026/09/28 03:27:40 OK 20260628120000_add_object_size_and_stats.sql (21.09ms)20312026/09/28 03:27:40 OK 20241026095416_initial_model.sql (61.55ms)20322026/09/28 03:27:40 OK 20251210153512_drop_unused_gin_index.sql (1.48ms)20332026/09/28 03:27:40 OK 20260905000000_add_claims.sql (15.42ms)20342026/09/28 03:27:40 OK 20251218171726_add_pins.sql (12.89ms)20352026/09/28 03:27:40 OK 20260920000000_drop_claims.sql (20.76ms)20362026/09/28 03:27:40 OK 20260923120000_add_pushes.sql (6.16ms)20372026/09/28 03:27:40 goose: successfully migrated database to version: 2026092312000020382026/09/28 03:27:40 OK 1_commit_pending_closure.sql (837.63µs)20392026/09/28 03:27:40 OK 2_object_stats_trigger.sql (223.46µs)20402026/09/28 03:27:40 OK 3_commit_push.sql (181.75µs)20412026/09/28 03:27:40 goose: up to current file version: 320422026/09/28 03:27:40 INFO Received push request method=POST path=/api/pushes20432026/09/28 03:27:40 OK 20260628120000_add_object_size_and_stats.sql (23.13ms)20442026/09/28 03:27:40 OK 20260905000000_add_claims.sql (66.42ms)20452026-09-28 03:27:40.770 UTC [35163] ERROR: relation "goose_db_version" does not exist at character 3620462026-09-28 03:27:40.770 UTC [35163] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2047--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (2.91s)2048=== CONT TestService_Rustfstest20492026/09/28 03:27:40 OK 20260920000000_drop_claims.sql (23.2ms)20502026/09/28 03:27:40 OK 20260923120000_add_pushes.sql (10.71ms)20512026/09/28 03:27:40 goose: successfully migrated database to version: 2026092312000020522026/09/28 03:27:40 OK 1_commit_pending_closure.sql (847.13µs)20532026/09/28 03:27:40 OK 2_object_stats_trigger.sql (246.5µs)20542026/09/28 03:27:40 OK 3_commit_push.sql (204.46µs)20552026/09/28 03:27:40 goose: up to current file version: 320562026-09-28 03:27:40.892 UTC [35169] ERROR: relation "goose_db_version" does not exist at character 3620572026-09-28 03:27:40.892 UTC [35169] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20582026/09/28 03:27:40 OK 20241026095416_initial_model.sql (96.77ms)20592026/09/28 03:27:40 OK 20251210153512_drop_unused_gin_index.sql (1.11ms)20602026/09/28 03:27:40 OK 20251218171726_add_pins.sql (12.39ms)20612026/09/28 03:27:40 OK 20260628120000_add_object_size_and_stats.sql (14.59ms)2062--- PASS: TestReadProxyRangeRequest (2.56s)2063=== CONT TestParseSize2064--- PASS: TestParseSize (0.00s)2065=== CONT TestProxyWriteTimeout2066=== RUN TestProxyWriteTimeout/narinfo2067=== PAUSE TestProxyWriteTimeout/narinfo2068=== RUN TestProxyWriteTimeout/1_GiB_nar2069=== PAUSE TestProxyWriteTimeout/1_GiB_nar2070=== RUN TestProxyWriteTimeout/10_GiB_nar2071=== PAUSE TestProxyWriteTimeout/10_GiB_nar2072=== RUN TestProxyWriteTimeout/unknown_size2073=== PAUSE TestProxyWriteTimeout/unknown_size2074=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle20752026/09/28 03:27:40 OK 20260905000000_add_claims.sql (45.65ms)20762026/09/28 03:27:41 OK 20260920000000_drop_claims.sql (14.36ms)20772026/09/28 03:27:41 OK 20260923120000_add_pushes.sql (5.44ms)20782026/09/28 03:27:41 goose: successfully migrated database to version: 2026092312000020792026/09/28 03:27:41 OK 1_commit_pending_closure.sql (1.21ms)20802026/09/28 03:27:41 OK 2_object_stats_trigger.sql (262.5µs)20812026/09/28 03:27:41 OK 3_commit_push.sql (244.21µs)20822026/09/28 03:27:41 goose: up to current file version: 320832026/09/28 03:27:41 OK 20241026095416_initial_model.sql (102.08ms)20842026/09/28 03:27:41 OK 20251210153512_drop_unused_gin_index.sql (3.46ms)20852026/09/28 03:27:41 OK 20251218171726_add_pins.sql (16.23ms)20862026/09/28 03:27:41 OK 20260628120000_add_object_size_and_stats.sql (16.99ms)20872026/09/28 03:27:41 OK 20260905000000_add_claims.sql (32.65ms)20882026/09/28 03:27:41 OK 20260920000000_drop_claims.sql (21.56ms)20892026/09/28 03:27:41 OK 20260923120000_add_pushes.sql (8.04ms)20902026/09/28 03:27:41 goose: successfully migrated database to version: 2026092312000020912026/09/28 03:27:41 OK 1_commit_pending_closure.sql (1.98ms)20922026/09/28 03:27:41 OK 2_object_stats_trigger.sql (329.42µs)20932026/09/28 03:27:41 OK 3_commit_push.sql (236.42µs)20942026/09/28 03:27:41 goose: up to current file version: 32095--- PASS: TestReadRedirectUsesPublicS3URL (3.06s)2096=== CONT TestSkippedUploadsHandler20972026/09/28 03:27:41 INFO Client skipped oversized paths paths=3 nar_bytes=50000000002098--- PASS: TestSkippedUploadsHandler (0.00s)2099=== CONT TestCompletedNarNotReofferedAcrossClosures21002026/09/28 03:27:41 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux21012026/09/28 03:27:41 WARN Refused reserved pin name=worker-x86_64-linux21022026/09/28 03:27:41 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux21032026/09/28 03:27:41 INFO Received create pin request method=POST path=/api/pins/my-app21042026/09/28 03:27:41 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux2105--- PASS: TestCreatePin_ReservedPins (2.64s)2106=== CONT TestLeadEndsOnShutdown21072026-09-28 03:27:41.429 UTC [35178] ERROR: relation "goose_db_version" does not exist at character 3621082026-09-28 03:27:41.429 UTC [35178] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21092026/09/28 03:27:41 INFO Received uploads request method=POST path=/api/pending_closures21102026/09/28 03:27:41 INFO Received uploads request method=POST path=/api/pending_closures21112026/09/28 03:27:41 INFO Received uploads request method=POST path=/api/pending_closures21122026-09-28 03:27:41.635 UTC [35179] ERROR: relation "goose_db_version" does not exist at character 3621132026-09-28 03:27:41.635 UTC [35179] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21142026/09/28 03:27:41 OK 20241026095416_initial_model.sql (206.18ms)21152026/09/28 03:27:41 OK 20251210153512_drop_unused_gin_index.sql (4.53ms)21162026/09/28 03:27:41 OK 20251218171726_add_pins.sql (54.43ms)21172026/09/28 03:27:41 OK 20260628120000_add_object_size_and_stats.sql (40.23ms)21182026-09-28 03:27:41.780 UTC [35180] ERROR: relation "goose_db_version" does not exist at character 3621192026-09-28 03:27:41.780 UTC [35180] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21202026/09/28 03:27:41 OK 20260905000000_add_claims.sql (67.4ms)21212026/09/28 03:27:41 OK 20260920000000_drop_claims.sql (15.63ms)21222026/09/28 03:27:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21232026/09/28 03:27:41 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst2124--- PASS: TestCompleteMultipartUnregistered (2.60s)2125=== CONT TestLeadElectsOneAndHandsOver21262026/09/28 03:27:41 OK 20260923120000_add_pushes.sql (17.72ms)21272026/09/28 03:27:41 goose: successfully migrated database to version: 2026092312000021282026/09/28 03:27:41 OK 1_commit_pending_closure.sql (2.84ms)21292026/09/28 03:27:41 OK 2_object_stats_trigger.sql (836.04µs)21302026/09/28 03:27:41 OK 3_commit_push.sql (444.04µs)21312026/09/28 03:27:41 goose: up to current file version: 321322026/09/28 03:27:41 OK 20241026095416_initial_model.sql (173.44ms)21332026/09/28 03:27:41 OK 20251210153512_drop_unused_gin_index.sql (7.69ms)21342026/09/28 03:27:41 OK 20251218171726_add_pins.sql (27.53ms)21352026/09/28 03:27:41 OK 20260628120000_add_object_size_and_stats.sql (33.12ms)21362026/09/28 03:27:41 OK 20260905000000_add_claims.sql (29.4ms)21372026/09/28 03:27:42 OK 20241026095416_initial_model.sql (147.53ms)21382026/09/28 03:27:42 OK 20251210153512_drop_unused_gin_index.sql (8.38ms)21392026/09/28 03:27:42 OK 20260920000000_drop_claims.sql (19.75ms)21402026/09/28 03:27:42 OK 20260923120000_add_pushes.sql (19.46ms)21412026/09/28 03:27:42 goose: successfully migrated database to version: 2026092312000021422026/09/28 03:27:42 OK 20251218171726_add_pins.sql (29.97ms)21432026/09/28 03:27:42 OK 1_commit_pending_closure.sql (3.42ms)21442026/09/28 03:27:42 OK 2_object_stats_trigger.sql (1.24ms)21452026/09/28 03:27:42 OK 3_commit_push.sql (940.71µs)21462026/09/28 03:27:42 goose: up to current file version: 321472026/09/28 03:27:42 OK 20260628120000_add_object_size_and_stats.sql (23.01ms)21482026/09/28 03:27:42 INFO Received uploads request method=POST path=/api/pending_closures21492026/09/28 03:27:42 OK 20260905000000_add_claims.sql (57.27ms)21502026/09/28 03:27:42 OK 20260920000000_drop_claims.sql (23.54ms)21512026/09/28 03:27:42 OK 20260923120000_add_pushes.sql (12.79ms)21522026/09/28 03:27:42 goose: successfully migrated database to version: 2026092312000021532026/09/28 03:27:42 OK 1_commit_pending_closure.sql (3ms)21542026/09/28 03:27:42 OK 2_object_stats_trigger.sql (788.38µs)21552026/09/28 03:27:42 OK 3_commit_push.sql (627.96µs)21562026/09/28 03:27:42 goose: up to current file version: 321572026-09-28 03:27:42.336 UTC [35184] ERROR: relation "goose_db_version" does not exist at character 3621582026-09-28 03:27:42.336 UTC [35184] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2159--- PASS: TestResurrectedObjectNotDeleted (2.71s)2160=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT21612026/09/28 03:27:42 OK 20241026095416_initial_model.sql (256.04ms)21622026/09/28 03:27:42 OK 20251210153512_drop_unused_gin_index.sql (12.7ms)21632026/09/28 03:27:42 OK 20251218171726_add_pins.sql (42.16ms)21642026/09/28 03:27:42 INFO Received cleanup request method=DELETE path=/api/pending_closures21652026/09/28 03:27:42 INFO Aborted multipart uploads count=021662026/09/28 03:27:42 INFO Received uploads request method=POST path=/api/pending_closures21672026/09/28 03:27:42 OK 20260628120000_add_object_size_and_stats.sql (45.23ms)21682026-09-28 03:27:42.786 UTC [35187] ERROR: relation "goose_db_version" does not exist at character 3621692026-09-28 03:27:42.786 UTC [35187] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21702026/09/28 03:27:42 OK 20260905000000_add_claims.sql (64.09ms)21712026/09/28 03:27:42 INFO Received cleanup request method=DELETE path=/api/pending_closures21722026/09/28 03:27:42 INFO Aborted multipart uploads count=121732026/09/28 03:27:42 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21742026-09-28 03:27:42.832 UTC [35178] ERROR: Closure does not exist: id=121752026-09-28 03:27:42.832 UTC [35178] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE21762026-09-28 03:27:42.832 UTC [35178] STATEMENT: -- name: CommitPendingClosure :exec2177 SELECT commit_pending_closure($1::bigint)2178 2179--- PASS: TestService_cleanupPendingClosuresHandler (2.47s)2180=== CONT TestOrphanedObjectsGCStressTest21812026/09/28 03:27:42 OK 20260920000000_drop_claims.sql (62.26ms)21822026/09/28 03:27:42 OK 20260923120000_add_pushes.sql (28.01ms)21832026/09/28 03:27:42 goose: successfully migrated database to version: 2026092312000021842026/09/28 03:27:42 OK 1_commit_pending_closure.sql (2.77ms)21852026/09/28 03:27:42 OK 2_object_stats_trigger.sql (493.46µs)21862026/09/28 03:27:42 OK 3_commit_push.sql (440.79µs)21872026/09/28 03:27:42 goose: up to current file version: 321882026/09/28 03:27:43 INFO Received uploads request method=POST path=/api/pending_closures21892026/09/28 03:27:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21902026/09/28 03:27:43 OK 20241026095416_initial_model.sql (204.82ms)21912026/09/28 03:27:43 OK 20251210153512_drop_unused_gin_index.sql (13.99ms)21922026/09/28 03:27:43 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst21932026/09/28 03:27:43 INFO Received uploads request method=POST path=/api/pending_closures2194--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.53s)2195=== CONT TestResolveDBConnectionString/flag_wins2196=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2197=== CONT TestResolveDBConnectionString/nothing_configured2198=== CONT TestResolveDBConnectionString/missing_file_is_an_error2199=== CONT TestResolveDBConnectionString/file_when_flag_empty2200=== CONT TestClientErrorHandling/InvalidStorePath2201--- PASS: TestResolveDBConnectionString (0.01s)2202 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2203 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2204 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2205 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2206 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)22072026/09/28 03:27:43 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NTg0YzlkZmItNmU2OC00ZDFiLWE1MTItN2JkNTNjOGQxYTQzLjgyNWI2NTM0LWVkN2ItNDE5My05ZDE2LWM4OTMxYWJiYWQ2NHgxNzkwNTY2MDYxNTc1OTA4MDAw parts=1022082026/09/28 03:27:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22092026/09/28 03:27:43 OK 20251218171726_add_pins.sql (43.68ms)22102026/09/28 03:27:43 INFO Completed upload id=122112026/09/28 03:27:43 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000022122026/09/28 03:27:43 INFO Received uploads request method=POST path=/api/pending_closures22132026/09/28 03:27:43 INFO Starting cleanup of old closures method=DELETE path=/api/closures22142026/09/28 03:27:43 INFO Aborted multipart uploads count=022152026/09/28 03:27:43 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=0 objects-failed-to-delete=022162026/09/28 03:27:43 OK 20260628120000_add_object_size_and_stats.sql (41.53ms)22172026/09/28 03:27:43 INFO Vacuumed table table=pending_closures22182026/09/28 03:27:43 INFO Vacuumed table table=pending_objects22192026/09/28 03:27:43 OK 20260905000000_add_claims.sql (58.39ms)22202026/09/28 03:27:43 INFO Vacuumed table table=multipart_uploads22212026/09/28 03:27:43 INFO Vacuumed table table=closures22222026/09/28 03:27:43 OK 20260920000000_drop_claims.sql (34.89ms)22232026/09/28 03:27:43 INFO Vacuumed table table=objects22242026/09/28 03:27:43 OK 20260923120000_add_pushes.sql (7.06ms)22252026/09/28 03:27:43 goose: successfully migrated database to version: 2026092312000022262026-09-28 03:27:43.285 UTC [35193] ERROR: relation "goose_db_version" does not exist at character 3622272026-09-28 03:27:43.285 UTC [35193] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22282026/09/28 03:27:43 OK 1_commit_pending_closure.sql (2.82ms)22292026/09/28 03:27:43 OK 2_object_stats_trigger.sql (785.71µs)22302026/09/28 03:27:43 OK 3_commit_push.sql (509.92µs)22312026/09/28 03:27:43 goose: up to current file version: 322322026/09/28 03:27:43 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000002233--- PASS: TestService_createPendingClosureHandler (4.30s)2234=== CONT TestClientErrorHandling/ServerNotAvailable2235--- PASS: TestService_Rustfstest (2.57s)2236=== CONT TestClientErrorHandling/InvalidAuthToken22372026/09/28 03:27:43 OK 20241026095416_initial_model.sql (151.05ms)22382026/09/28 03:27:43 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22392026/09/28 03:27:43 OK 20251210153512_drop_unused_gin_index.sql (9.88ms)22402026/09/28 03:27:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22412026/09/28 03:27:43 OK 20251218171726_add_pins.sql (26.29ms)22422026/09/28 03:27:43 OK 20260628120000_add_object_size_and_stats.sql (38.27ms)22432026/09/28 03:27:43 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NTg0YzlkZmItNmU2OC00ZDFiLWE1MTItN2JkNTNjOGQxYTQzLmM2MzBkYjdmLTBkZTMtNDAyMS05YmM4LTBkOTZhODk0ZmRhYngxNzkwNTY2MDYyMTM4ODI3MDAw parts=1022442026/09/28 03:27:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22452026/09/28 03:27:43 INFO Completed upload id=122462026/09/28 03:27:43 INFO Received uploads request method=POST path=/api/pending_closures22472026/09/28 03:27:43 INFO Received uploads request method=POST path=/api/pending_closures22482026/09/28 03:27:43 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo22492026/09/28 03:27:43 WARN Found objects in DB but missing from S3, will re-upload count=12250--- PASS: TestService_verifyS3Integrity (4.08s)2251=== CONT TestCacheConfigHandler/full_config,_no_issuer2252=== CONT TestCacheConfigHandler/no_signing_keys2253=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2254=== CONT TestCacheConfigHandler/no_cache_url_configured2255--- PASS: TestCacheConfigHandler (0.00s)2256 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2257 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2258 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2259 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2260=== CONT TestServerTLSConfig/no_client_CA2261=== CONT TestServerTLSConfig/not_a_PEM_file22622026/09/28 03:27:43 INFO Received uploads request method=POST path=/api/pending_closures22632026/09/28 03:27:43 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=210.02933ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2264=== CONT TestServerTLSConfig/missing_CA_file2265--- PASS: TestServerTLSConfig (0.00s)2266 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2267 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.03s)2268 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2269=== CONT TestService_RequireScope_OIDC/builder_may_write2270=== CONT TestService_RequireScope_OIDC/static_token_may_admin2271=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2272=== CONT TestService_RequireScope_OIDC/writer_implies_read2273=== CONT TestService_RequireScope_OIDC/reader_may_read2274=== CONT TestService_RequireScope_OIDC/static_token_may_write2275=== CONT TestService_RequireScope_OIDC/ops_may_not_write2276=== CONT TestService_RequireScope_OIDC/reader_may_not_write2277=== CONT TestService_RequireScope_OIDC/ops_may_admin2278=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2279=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2280=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected22812026/09/28 03:27:43 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]2282=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2283=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected22842026/09/28 03:27:43 WARN Authentication failed token_preview=eyJhbGciOi...XNiaSvyNxA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2285=== CONT TestIsValidCachePath/narinfo2286=== CONT TestIsValidCachePath/index.html2287=== CONT TestIsValidCachePath/short_hash2288=== CONT TestIsValidCachePath/wrong_extension2289=== CONT TestIsValidCachePath/leading_slash2290=== CONT TestIsValidCachePath/empty2291=== CONT TestIsValidCachePath/random_path2292=== CONT TestIsValidCachePath/invalid_char_u2293=== CONT TestIsValidCachePath/invalid_char_e2294=== CONT TestIsValidCachePath/traversal_in_middle2295=== CONT TestIsValidCachePath/traversal_parent2296=== CONT TestIsValidCachePath/nar_uncompressed2297=== CONT TestIsValidCachePath/nix-cache-info2298=== CONT TestIsValidCachePath/realisation2299=== CONT TestIsValidCachePath/log2300=== CONT TestIsValidCachePath/ls2301=== CONT TestIsValidCachePath/nar_xz2302=== CONT TestIsValidCachePath/nar_bz22303=== CONT TestIsValidCachePath/nar_zst2304=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2305--- PASS: TestIsValidCachePath (0.00s)2306 --- PASS: TestIsValidCachePath/narinfo (0.00s)2307 --- PASS: TestIsValidCachePath/index.html (0.00s)2308 --- PASS: TestIsValidCachePath/short_hash (0.00s)2309 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2310 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2311 --- PASS: TestIsValidCachePath/empty (0.00s)2312 --- PASS: TestIsValidCachePath/random_path (0.00s)2313 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2314 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2315 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2316 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2317 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2318 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2319 --- PASS: TestIsValidCachePath/realisation (0.00s)2320 --- PASS: TestIsValidCachePath/log (0.00s)2321 --- PASS: TestIsValidCachePath/ls (0.00s)2322 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2323 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2324 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2325 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2326=== CONT TestIsValidUploadKey/narinfo2327=== CONT TestIsValidUploadKey/realisation_plus_in_output2328=== CONT TestIsValidUploadKey/unknown_type2329=== CONT TestIsValidUploadKey/empty_key2330=== CONT TestIsValidUploadKey/absolute2331=== CONT TestIsValidUploadKey/traversal_nar2332=== CONT TestIsValidUploadKey/traversal2333=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2334=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2335=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2336=== CONT TestIsValidUploadKey/index.html2337=== CONT TestIsValidUploadKey/nix-cache-info2338=== CONT TestIsValidUploadKey/build_log_home-manager_file2339=== CONT TestIsValidUploadKey/realisation2340=== CONT TestIsValidUploadKey/build_log_equals2341=== CONT TestIsValidUploadKey/build_log_question_mark2342=== CONT TestIsValidUploadKey/build_log_plus_in_name2343=== CONT TestIsValidUploadKey/nar_plain2344=== CONT TestIsValidUploadKey/build_log2345=== CONT TestIsValidUploadKey/listing2346=== CONT TestIsValidUploadKey/nar_xz2347=== CONT TestIsValidUploadKey/nar_zst2348--- PASS: TestIsValidUploadKey (0.00s)2349 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2350 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2351 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2352 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2353 --- PASS: TestIsValidUploadKey/absolute (0.00s)2354 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2355 --- PASS: TestIsValidUploadKey/traversal (0.00s)2356 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2357 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2358 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2359 --- PASS: TestIsValidUploadKey/index.html (0.00s)2360 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2361 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2362 --- PASS: TestIsValidUploadKey/realisation (0.00s)2363 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2364 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2365 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2366 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2367 --- PASS: TestIsValidUploadKey/build_log (0.00s)2368 --- PASS: TestIsValidUploadKey/listing (0.00s)2369 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2370 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2371=== CONT TestParseSingleRange/none2372=== CONT TestParseSingleRange/open-ended2373=== CONT TestParseSingleRange/start_far_past_EOF2374=== CONT TestParseSingleRange/start_past_EOF2375=== CONT TestParseSingleRange/single_byte2376=== CONT TestParseSingleRange/suffix_exceeds_size2377=== CONT TestParseSingleRange/suffix2378=== CONT TestParseSingleRange/end_clamped_to_size2379=== CONT TestParseSingleRange/malformed_both_empty2380=== CONT TestParseSingleRange/closed2381=== CONT TestParseSingleRange/malformed_end_before_start2382=== CONT TestParseSingleRange/multi-range_ignored2383=== CONT TestParseSingleRange/unknown_unit2384=== CONT TestParseSingleRange/malformed_no_dash2385--- PASS: TestParseSingleRange (0.00s)2386 --- PASS: TestParseSingleRange/none (0.00s)2387 --- PASS: TestParseSingleRange/open-ended (0.00s)2388 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2389 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2390 --- PASS: TestParseSingleRange/single_byte (0.00s)2391 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2392 --- PASS: TestParseSingleRange/suffix (0.00s)2393 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2394 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2395 --- PASS: TestParseSingleRange/closed (0.00s)2396 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2397 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2398 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2399 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2400=== CONT TestPush_RejectsBadRequests/no_objects24012026/09/28 03:27:43 INFO Received push request method=POST path=/api/pushes2402=== CONT TestPush_RejectsBadRequests/root_not_in_objects24032026/09/28 03:27:43 INFO Received push request method=POST path=/api/pushes2404=== CONT TestPush_RejectsBadRequests/no_roots24052026/09/28 03:27:43 INFO Received push request method=POST path=/api/pushes2406=== CONT TestPush_RejectsBadRequests/bad_root24072026/09/28 03:27:43 INFO Received push request method=POST path=/api/pushes2408=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure24092026/09/28 03:27:43 INFO Received uploads request method=POST path=/2410--- PASS: TestPush_RejectsBadRequests (2.72s)2411 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2412 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2413 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2414 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2415--- PASS: TestService_AuthMiddleware_OIDC (1.56s)2416 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2417 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2418 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2419 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2420--- PASS: TestService_RequireScope_OIDC (1.65s)2421 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2422 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2423 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2424 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2425 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2426 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2427 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2428 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2429 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2430 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)24312026/09/28 03:27:43 OK 20260905000000_add_claims.sql (63.54ms)24322026/09/28 03:27:43 OK 20260920000000_drop_claims.sql (16.37ms)24332026/09/28 03:27:43 OK 20260923120000_add_pushes.sql (14.18ms)24342026/09/28 03:27:43 goose: successfully migrated database to version: 2026092312000024352026/09/28 03:27:43 OK 1_commit_pending_closure.sql (1.09ms)24362026/09/28 03:27:43 OK 2_object_stats_trigger.sql (253.29µs)24372026/09/28 03:27:43 OK 3_commit_push.sql (202.38µs)24382026/09/28 03:27:43 goose: up to current file version: 324392026-09-28 03:27:43.725 UTC [35200] ERROR: relation "goose_db_version" does not exist at character 3624402026-09-28 03:27:43.725 UTC [35200] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24412026/09/28 03:27:43 INFO Received uploads request method=POST path=/api/pending_closures24422026/09/28 03:27:43 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=408.035801ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present24432026/09/28 03:27:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete24442026/09/28 03:27:43 OK 20241026095416_initial_model.sql (99.59ms)24452026/09/28 03:27:43 OK 20251210153512_drop_unused_gin_index.sql (4.04ms)24462026/09/28 03:27:43 OK 20251218171726_add_pins.sql (1.17ms)24472026/09/28 03:27:43 OK 20260628120000_add_object_size_and_stats.sql (17.75ms)2448=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart24492026/09/28 03:27:43 INFO Received complete multipart upload request method=POST path=/24502026/09/28 03:27:43 OK 20260905000000_add_claims.sql (37.79ms)2451=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts24522026/09/28 03:27:43 INFO Received request for more parts method=POST path=/24532026/09/28 03:27:43 OK 20260920000000_drop_claims.sql (21.89ms)2454--- PASS: TestUploadHandlersRejectOversizedBody (0.02s)2455 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.28s)2456 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)2457 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)2458=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info24592026/09/28 03:27:43 INFO Received uploads request method=POST path=/2460=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key24612026/09/28 03:27:43 INFO Received complete multipart upload request method=POST path=/2462=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key24632026/09/28 03:27:43 INFO Received request for more parts method=POST path=/2464=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal24652026/09/28 03:27:43 INFO Received uploads request method=POST path=/2466--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2467 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2468 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2469 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2470 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2471=== CONT TestProxyWriteTimeout/narinfo2472=== CONT TestProxyWriteTimeout/10_GiB_nar2473=== CONT TestProxyWriteTimeout/unknown_size2474=== CONT TestProxyWriteTimeout/1_GiB_nar2475--- PASS: TestProxyWriteTimeout (0.00s)2476 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2477 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2478 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2479 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)24802026/09/28 03:27:43 OK 20260923120000_add_pushes.sql (13.04ms)24812026/09/28 03:27:43 goose: successfully migrated database to version: 2026092312000024822026/09/28 03:27:43 OK 1_commit_pending_closure.sql (933.46µs)24832026/09/28 03:27:43 OK 2_object_stats_trigger.sql (230µs)24842026/09/28 03:27:43 OK 3_commit_push.sql (212.17µs)24852026/09/28 03:27:43 goose: up to current file version: 324862026/09/28 03:27:44 INFO lead: acquired remote=192.0.2.1:123424872026/09/28 03:27:44 INFO lead: released remote=192.0.2.1:12342488--- PASS: TestLeadEndsOnShutdown (2.69s)24892026-09-28 03:27:44.155 UTC [35201] ERROR: relation "goose_db_version" does not exist at character 3624902026-09-28 03:27:44.155 UTC [35201] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24912026/09/28 03:27:44 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=722.592165ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present24922026/09/28 03:27:44 INFO lead: acquired remote=192.0.2.1:123424932026/09/28 03:27:44 OK 20241026095416_initial_model.sql (98.24ms)24942026/09/28 03:27:44 OK 20251210153512_drop_unused_gin_index.sql (4.03ms)24952026/09/28 03:27:44 OK 20251218171726_add_pins.sql (7.24ms)24962026/09/28 03:27:44 OK 20260628120000_add_object_size_and_stats.sql (3.62ms)24972026/09/28 03:27:44 OK 20260905000000_add_claims.sql (24.57ms)24982026/09/28 03:27:44 OK 20260920000000_drop_claims.sql (10.3ms)24992026/09/28 03:27:44 OK 20260923120000_add_pushes.sql (7.78ms)25002026/09/28 03:27:44 goose: successfully migrated database to version: 2026092312000025012026/09/28 03:27:44 OK 1_commit_pending_closure.sql (2.46ms)25022026/09/28 03:27:44 OK 2_object_stats_trigger.sql (509.75µs)25032026/09/28 03:27:44 OK 3_commit_push.sql (359.63µs)25042026/09/28 03:27:44 goose: up to current file version: 325052026-09-28 03:27:44.366 UTC [35203] ERROR: relation "goose_db_version" does not exist at character 3625062026-09-28 03:27:44.366 UTC [35203] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25072026-09-28 03:27:44.378 UTC [35204] ERROR: relation "goose_db_version" does not exist at character 3625082026-09-28 03:27:44.378 UTC [35204] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25092026/09/28 03:27:44 INFO lead: released remote=192.0.2.1:123425102026/09/28 03:27:44 INFO lead: acquired remote=192.0.2.1:123425112026/09/28 03:27:44 INFO lead: released remote=192.0.2.1:12342512--- PASS: TestLeadElectsOneAndHandsOver (2.61s)25132026/09/28 03:27:44 OK 20241026095416_initial_model.sql (117.61ms)25142026/09/28 03:27:44 OK 20251210153512_drop_unused_gin_index.sql (12.18ms)25152026/09/28 03:27:44 OK 20251218171726_add_pins.sql (21.68ms)25162026/09/28 03:27:44 OK 20260628120000_add_object_size_and_stats.sql (27.61ms)25172026/09/28 03:27:44 OK 20241026095416_initial_model.sql (143.78ms)25182026/09/28 03:27:44 INFO Received uploads request method=POST path=/api/pending_closures25192026/09/28 03:27:44 OK 20251210153512_drop_unused_gin_index.sql (9.85ms)25202026/09/28 03:27:44 OK 20251218171726_add_pins.sql (27.38ms)25212026/09/28 03:27:44 OK 20260905000000_add_claims.sql (45.67ms)25222026/09/28 03:27:44 OK 20260628120000_add_object_size_and_stats.sql (29.92ms)25232026/09/28 03:27:44 OK 20260920000000_drop_claims.sql (29.05ms)2524--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (2.08s)25252026/09/28 03:27:44 OK 20260923120000_add_pushes.sql (3.72ms)25262026/09/28 03:27:44 goose: successfully migrated database to version: 2026092312000025272026/09/28 03:27:44 OK 20260905000000_add_claims.sql (5.76ms)25282026/09/28 03:27:44 OK 1_commit_pending_closure.sql (2.92ms)25292026/09/28 03:27:44 OK 2_object_stats_trigger.sql (498.13µs)25302026/09/28 03:27:44 OK 3_commit_push.sql (424.42µs)25312026/09/28 03:27:44 goose: up to current file version: 325322026/09/28 03:27:44 OK 20260920000000_drop_claims.sql (6.68ms)25332026/09/28 03:27:44 OK 20260923120000_add_pushes.sql (6.07ms)25342026/09/28 03:27:44 goose: successfully migrated database to version: 2026092312000025352026/09/28 03:27:44 OK 1_commit_pending_closure.sql (1.98ms)25362026/09/28 03:27:44 OK 2_object_stats_trigger.sql (448µs)25372026/09/28 03:27:44 OK 3_commit_push.sql (407.88µs)25382026/09/28 03:27:44 goose: up to current file version: 325392026-09-28 03:27:44.688 UTC [35206] ERROR: relation "goose_db_version" does not exist at character 3625402026-09-28 03:27:44.688 UTC [35206] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25412026/09/28 03:27:44 OK 20241026095416_initial_model.sql (91.62ms)25422026/09/28 03:27:44 OK 20251210153512_drop_unused_gin_index.sql (12.35ms)25432026/09/28 03:27:44 OK 20251218171726_add_pins.sql (30.08ms)25442026/09/28 03:27:44 OK 20260628120000_add_object_size_and_stats.sql (29.63ms)25452026/09/28 03:27:44 OK 20260905000000_add_claims.sql (47.05ms)25462026/09/28 03:27:44 OK 20260920000000_drop_claims.sql (30.95ms)25472026/09/28 03:27:44 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.466978228s error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present25482026/09/28 03:27:44 OK 20260923120000_add_pushes.sql (21.56ms)25492026/09/28 03:27:44 goose: successfully migrated database to version: 2026092312000025502026/09/28 03:27:44 OK 1_commit_pending_closure.sql (2.99ms)25512026/09/28 03:27:44 OK 2_object_stats_trigger.sql (680.42µs)25522026/09/28 03:27:44 OK 3_commit_push.sql (488.88µs)25532026/09/28 03:27:44 goose: up to current file version: 325542026/09/28 03:27:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete25552026/09/28 03:27:45 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NTg0YzlkZmItNmU2OC00ZDFiLWE1MTItN2JkNTNjOGQxYTQzLjNjMTIyZTlhLTk0MmMtNDk1Yi1hNzY0LWRlMWIzYmQ3ZGFlOXgxNzkwNTY2MDYzODQzOTI2MDAw parts=1225562026/09/28 03:27:45 INFO Received uploads request method=POST path=/api/pending_closures2557--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.02s)25582026/09/28 03:27:45 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"25592026/09/28 03:27:45 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"25602026/09/28 03:27:46 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25612026/09/28 03:27:46 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=187.282475ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25622026/09/28 03:27:46 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=361.580734ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2563=== NAME TestOrphanedObjectsGCStressTest2564 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2565 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion2566 orphaned_objects_gc_test.go:509: Stress test completed successfully:2567 orphaned_objects_gc_test.go:510: - Active objects preserved: 202568 orphaned_objects_gc_test.go:511: - Objects deleted: 2102569 orphaned_objects_gc_test.go:512: - Total GC'd: 2102570--- PASS: TestOrphanedObjectsGCStressTest (4.15s)25712026/09/28 03:27:47 WARN Rate limiter enabled after throttle name=s3-test rate=525722026/09/28 03:27:47 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2573=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2574 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102575 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002576--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.14s)25772026/09/28 03:27:47 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=805.656817ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25782026/09/28 03:27:47 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.510454985s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25792026/09/28 03:27:49 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused"25802026/09/28 03:27:49 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25812026/09/28 03:27:49 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=217.907018ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25822026/09/28 03:27:49 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=382.747652ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25832026/09/28 03:27:50 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=844.34743ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25842026/09/28 03:27:51 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.746466418s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25852026/09/28 03:27:52 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures25862026/09/28 03:27:52 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=198.179817ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures25872026/09/28 03:27:53 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=396.861864ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures25882026/09/28 03:27:53 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=837.932719ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures25892026/09/28 03:27:54 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.717016548s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2590--- PASS: TestClientErrorHandling (0.00s)2591 --- PASS: TestClientErrorHandling/InvalidStorePath (2.01s)2592 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.10s)2593 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.78s)2594PASS2595{"timestamp":"2026-09-28T03:27:56.084851Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:63816","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2260,"threadName":"rustfs-worker","threadId":"ThreadId(7)"}25962026-09-28 03:27:56.287 UTC [34758] LOG: received smart shutdown request25972026-09-28 03:27:56.288 UTC [34758] LOG: background worker "logical replication launcher" (PID 34768) exited with exit code 125982026-09-28 03:27:56.296 UTC [34763] LOG: shutting down25992026-09-28 03:27:56.297 UTC [34763] LOG: checkpoint starting: shutdown immediate26002026-09-28 03:27:57.452 UTC [34763] LOG: checkpoint complete: wrote 13118 buffers (80.1%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 18 recycled; write=0.752 s, sync=0.367 s, total=1.156 s; sync files=21874, longest=0.001 s, average=0.001 s; distance=302637 kB, estimate=302637 kB; lsn=0/13F18360, redo lsn=0/13F1836026012026-09-28 03:27:57.456 UTC [34758] LOG: database system is shut down2602Running OIDC tests...2603=== RUN TestAudienceForIssuer2604=== PAUSE TestAudienceForIssuer2605=== RUN TestGlobMatch2606=== PAUSE TestGlobMatch2607=== RUN TestValidateToken_ValidToken2608=== PAUSE TestValidateToken_ValidToken2609=== RUN TestValidateToken_WrongAudience2610=== PAUSE TestValidateToken_WrongAudience2611=== RUN TestValidateToken_Expired2612=== PAUSE TestValidateToken_Expired2613=== RUN TestValidateToken_BoundClaimsMismatch2614=== PAUSE TestValidateToken_BoundClaimsMismatch2615=== RUN TestValidateToken_BoundSubjectMismatch2616=== PAUSE TestValidateToken_BoundSubjectMismatch2617=== RUN TestValidateToken_MultipleProviders2618=== PAUSE TestValidateToken_MultipleProviders2619=== RUN TestValidateToken_NoMatchingProvider2620=== PAUSE TestValidateToken_NoMatchingProvider2621=== RUN TestValidateToken_KubernetesServiceAccount2622=== PAUSE TestValidateToken_KubernetesServiceAccount2623=== RUN TestNewValidator_KubernetesRequiresCA2624=== PAUSE TestNewValidator_KubernetesRequiresCA2625=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2626=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2627=== RUN TestPins_ReservedForMatchingRule2628=== PAUSE TestPins_ReservedForMatchingRule2629=== RUN TestPins_TopLevelShorthand2630=== PAUSE TestPins_TopLevelShorthand2631=== RUN TestPins_ConfigValidation2632=== PAUSE TestPins_ConfigValidation2633=== RUN TestScopes_LegacyProviderDefaultsToWrite2634=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2635=== RUN TestScopes_Rules2636=== PAUSE TestScopes_Rules2637=== RUN TestScopes_ConfigValidation2638=== PAUSE TestScopes_ConfigValidation2639=== CONT TestAudienceForIssuer2640--- PASS: TestAudienceForIssuer (0.00s)2641=== CONT TestValidateToken_Expired2642=== CONT TestValidateToken_BoundClaimsMismatch2643=== CONT TestValidateToken_KubernetesServiceAccount2644=== CONT TestPins_ConfigValidation2645=== CONT TestPins_ReservedForMatchingRule2646=== CONT TestScopes_Rules2647=== CONT TestValidateToken_ValidToken2648=== CONT TestValidateToken_WrongAudience2649--- PASS: TestPins_ConfigValidation (0.00s)2650=== CONT TestScopes_LegacyProviderDefaultsToWrite2651=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2652=== CONT TestNewValidator_KubernetesRequiresCA26532026/09/28 03:27:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63877/oidc2654--- PASS: TestValidateToken_BoundClaimsMismatch (0.02s)2655=== CONT TestValidateToken_NoMatchingProvider26562026/09/28 03:27:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63879/oidc2657--- PASS: TestValidateToken_WrongAudience (0.04s)2658=== CONT TestValidateToken_MultipleProviders26592026/09/28 03:27:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63881/oidc2660--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.06s)2661=== CONT TestValidateToken_BoundSubjectMismatch26622026/09/28 03:27:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63885/oidc2663--- PASS: TestValidateToken_ValidToken (0.07s)2664=== CONT TestGlobMatch2665=== RUN TestGlobMatch/foo_foo2666=== PAUSE TestGlobMatch/foo_foo2667=== RUN TestGlobMatch/foo_bar2668=== PAUSE TestGlobMatch/foo_bar2669=== RUN TestGlobMatch/*_2670=== PAUSE TestGlobMatch/*_2671=== RUN TestGlobMatch/*_anything2672=== PAUSE TestGlobMatch/*_anything2673=== RUN TestGlobMatch/foo*_foo2674=== PAUSE TestGlobMatch/foo*_foo2675=== RUN TestGlobMatch/foo*_foobar2676=== PAUSE TestGlobMatch/foo*_foobar2677=== RUN TestGlobMatch/foo*_bar2678=== PAUSE TestGlobMatch/foo*_bar2679=== RUN TestGlobMatch/*bar_bar2680=== PAUSE TestGlobMatch/*bar_bar2681=== RUN TestGlobMatch/*bar_foobar2682=== PAUSE TestGlobMatch/*bar_foobar2683=== RUN TestGlobMatch/*bar_foo2684=== PAUSE TestGlobMatch/*bar_foo2685=== RUN TestGlobMatch/foo*bar_foobar2686=== PAUSE TestGlobMatch/foo*bar_foobar2687=== RUN TestGlobMatch/foo*bar_foo123bar2688=== PAUSE TestGlobMatch/foo*bar_foo123bar2689=== RUN TestGlobMatch/foo*bar_foobarbaz2690=== PAUSE TestGlobMatch/foo*bar_foobarbaz2691=== RUN TestGlobMatch/*/*_foo/bar2692=== PAUSE TestGlobMatch/*/*_foo/bar2693=== RUN TestGlobMatch/*/*_foo2694=== PAUSE TestGlobMatch/*/*_foo2695=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2696=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2697=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02698=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02699=== RUN TestGlobMatch/refs/*/main_refs/heads/main2700=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2701=== RUN TestGlobMatch/fo?_foo2702=== PAUSE TestGlobMatch/fo?_foo2703=== RUN TestGlobMatch/fo?_fo2704=== PAUSE TestGlobMatch/fo?_fo2705=== RUN TestGlobMatch/fo?_fooo2706=== PAUSE TestGlobMatch/fo?_fooo2707=== RUN TestGlobMatch/?oo_foo2708=== PAUSE TestGlobMatch/?oo_foo2709=== RUN TestGlobMatch/?oo_boo2710=== PAUSE TestGlobMatch/?oo_boo2711=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2712=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2713=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2714=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2715=== CONT TestPins_TopLevelShorthand27162026/09/28 03:27:58 http: TLS handshake error from 127.0.0.1:63884: read tcp 127.0.0.1:63883->127.0.0.1:63884: use of closed network connection2717--- PASS: TestNewValidator_KubernetesRequiresCA (0.07s)2718=== CONT TestScopes_ConfigValidation2719--- PASS: TestScopes_ConfigValidation (0.00s)2720=== CONT TestGlobMatch/foo_foo2721=== CONT TestGlobMatch/*/*_foo/bar2722=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2723=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2724=== CONT TestGlobMatch/?oo_boo2725=== CONT TestGlobMatch/?oo_foo2726=== CONT TestGlobMatch/fo?_fooo2727=== CONT TestGlobMatch/fo?_fo2728=== CONT TestGlobMatch/fo?_foo2729=== CONT TestGlobMatch/refs/*/main_refs/heads/main2730=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02731=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2732=== CONT TestGlobMatch/*/*_foo2733=== CONT TestGlobMatch/*bar_bar2734=== CONT TestGlobMatch/foo*bar_foobarbaz2735=== CONT TestGlobMatch/foo*bar_foo123bar2736=== CONT TestGlobMatch/foo*bar_foobar2737=== CONT TestGlobMatch/*bar_foo2738=== CONT TestGlobMatch/*bar_foobar2739=== CONT TestGlobMatch/foo*_foo2740=== CONT TestGlobMatch/foo*_bar2741=== CONT TestGlobMatch/foo*_foobar2742=== CONT TestGlobMatch/*_2743=== CONT TestGlobMatch/*_anything2744=== CONT TestGlobMatch/foo_bar2745--- PASS: TestGlobMatch (0.00s)2746 --- PASS: TestGlobMatch/foo_foo (0.00s)2747 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2748 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2749 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2750 --- PASS: TestGlobMatch/?oo_boo (0.00s)2751 --- PASS: TestGlobMatch/?oo_foo (0.00s)2752 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2753 --- PASS: TestGlobMatch/fo?_fo (0.00s)2754 --- PASS: TestGlobMatch/fo?_foo (0.00s)2755 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2756 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2757 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2758 --- PASS: TestGlobMatch/*/*_foo (0.00s)2759 --- PASS: TestGlobMatch/*bar_bar (0.00s)2760 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2761 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2762 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2763 --- PASS: TestGlobMatch/*bar_foo (0.00s)2764 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2765 --- PASS: TestGlobMatch/foo*_foo (0.00s)2766 --- PASS: TestGlobMatch/foo*_bar (0.00s)2767 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2768 --- PASS: TestGlobMatch/*_ (0.00s)2769 --- PASS: TestGlobMatch/*_anything (0.00s)2770 --- PASS: TestGlobMatch/foo_bar (0.00s)27712026/09/28 03:27:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63888/oidc27722026/09/28 03:27:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63890/oidc2773--- PASS: TestScopes_Rules (0.08s)2774--- PASS: TestValidateToken_Expired (0.09s)27752026/09/28 03:27:58 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12327762026/09/28 03:27:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63895/oidc2777--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.09s)2778--- PASS: TestPins_TopLevelShorthand (0.02s)27792026/09/28 03:27:58 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:638982780--- PASS: TestValidateToken_KubernetesServiceAccount (0.10s)27812026/09/28 03:27:58 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:63893/oidc27822026/09/28 03:27:58 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:63900/oidc2783--- PASS: TestValidateToken_MultipleProviders (0.07s)27842026/09/28 03:27:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63903/oidc27852026/09/28 03:27:58 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:63887/oidc2786--- PASS: TestPins_ReservedForMatchingRule (0.12s)2787--- PASS: TestValidateToken_NoMatchingProvider (0.10s)27882026/09/28 03:27:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63907/oidc2789--- PASS: TestValidateToken_BoundSubjectMismatch (0.06s)2790PASS2791Running hook tests...2792=== RUN TestSendPathsEmpty2793=== PAUSE TestSendPathsEmpty2794=== RUN TestQueueEnqueueAndFetch2795=== PAUSE TestQueueEnqueueAndFetch2796=== RUN TestQueueDeduplication2797=== PAUSE TestQueueDeduplication2798=== RUN TestQueueRemove2799=== PAUSE TestQueueRemove2800=== RUN TestQueueFetchBatchLimit2801=== PAUSE TestQueueFetchBatchLimit2802=== RUN TestQueueRetryMovesToBack2803=== PAUSE TestQueueRetryMovesToBack2804=== RUN TestQueueFetchRemoveLifecycle2805=== PAUSE TestQueueFetchRemoveLifecycle2806=== RUN TestQueueConcurrentWriters2807=== PAUSE TestQueueConcurrentWriters2808=== RUN TestQueueRemoveLargeClosure2809=== PAUSE TestQueueRemoveLargeClosure2810=== RUN TestServerClientIntegration2811=== PAUSE TestServerClientIntegration2812=== RUN TestServerQueueError2813=== PAUSE TestServerQueueError2814=== RUN TestGetListenerSocketActivation2815 server_test.go:210: === RUN TestGetListenerSocketActivation2816 --- PASS: TestGetListenerSocketActivation (0.00s)2817 PASS2818 2819--- PASS: TestGetListenerSocketActivation (0.01s)2820=== RUN TestDrainIsolatesPoisonPath2821=== PAUSE TestDrainIsolatesPoisonPath2822=== RUN TestRunNotBlockedByPoisonHead2823=== PAUSE TestRunNotBlockedByPoisonHead2824=== RUN TestDrainGivesUpWhenServerDown2825=== PAUSE TestDrainGivesUpWhenServerDown2826=== RUN TestFailedPathPrunedByLaterClosure2827=== PAUSE TestFailedPathPrunedByLaterClosure2828=== RUN TestWorkerUploadsAndRemoves2829=== PAUSE TestWorkerUploadsAndRemoves2830=== RUN TestWorkerSkipsGCdPaths2831=== PAUSE TestWorkerSkipsGCdPaths2832=== RUN TestWorkerPrunesClosureDeps2833=== PAUSE TestWorkerPrunesClosureDeps2834=== RUN TestDrainTimeout2835=== PAUSE TestDrainTimeout2836=== CONT TestSendPathsEmpty2837=== CONT TestServerQueueError2838=== CONT TestQueueEnqueueAndFetch2839=== CONT TestQueueRetryMovesToBack2840=== CONT TestWorkerUploadsAndRemoves2841=== CONT TestWorkerPrunesClosureDeps2842=== CONT TestWorkerSkipsGCdPaths2843=== CONT TestDrainTimeout2844--- PASS: TestSendPathsEmpty (0.00s)2845=== CONT TestQueueFetchBatchLimit2846=== CONT TestQueueRemove2847=== CONT TestQueueDeduplication28482026/09/28 03:27:58 ERROR Failed to queue paths error="permission denied" count=12849--- PASS: TestServerQueueError (0.00s)2850=== CONT TestQueueRemoveLargeClosure28512026/09/28 03:27:58 INFO Uploading batch count=22852--- PASS: TestQueueEnqueueAndFetch (0.01s)2853=== CONT TestServerClientIntegration28542026/09/28 03:27:58 INFO Upload queue status pending=228552026/09/28 03:27:58 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-34546-2893374115/TestWorkerSkipsGCdPaths3898522723/002/nonexistent28562026/09/28 03:27:58 INFO Upload queue status pending=228572026/09/28 03:27:58 INFO Upload queue status pending=228582026/09/28 03:27:58 INFO Uploading batch count=228592026/09/28 03:27:58 INFO Uploading batch count=128602026/09/28 03:27:58 INFO Uploading batch count=12861--- PASS: TestQueueFetchBatchLimit (0.01s)2862=== CONT TestQueueConcurrentWriters2863--- PASS: TestQueueDeduplication (0.01s)2864=== CONT TestQueueFetchRemoveLifecycle2865--- PASS: TestQueueRetryMovesToBack (0.01s)2866=== CONT TestDrainGivesUpWhenServerDown2867--- PASS: TestQueueRemove (0.01s)2868=== CONT TestFailedPathPrunedByLaterClosure2869--- PASS: TestServerClientIntegration (0.00s)2870=== CONT TestRunNotBlockedByPoisonHead28712026/09/28 03:27:58 INFO Uploading batch count=128722026/09/28 03:27:58 ERROR Upload failed error="upload failed" count=128732026/09/28 03:27:58 INFO Upload queue status pending=328742026/09/28 03:27:58 INFO Uploading batch count=128752026/09/28 03:27:58 ERROR Upload failed error="upload failed" count=128762026/09/28 03:27:58 INFO Uploading batch count=12877--- PASS: TestQueueFetchRemoveLifecycle (0.00s)2878=== CONT TestDrainIsolatesPoisonPath28792026/09/28 03:27:58 INFO Uploading batch count=128802026/09/28 03:27:58 INFO Uploading batch count=228812026/09/28 03:27:58 ERROR Upload failed error="upload failed" count=228822026/09/28 03:27:58 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-34546-2893374115/TestDrainGivesUpWhenServerDown1328190854/002/a28832026/09/28 03:27:58 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-34546-2893374115/TestDrainGivesUpWhenServerDown1328190854/002/b28842026/09/28 03:27:58 INFO Uploading batch count=228852026/09/28 03:27:58 ERROR Upload failed error="upload failed" count=228862026/09/28 03:27:58 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-34546-2893374115/TestDrainGivesUpWhenServerDown1328190854/002/c28872026/09/28 03:27:58 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-34546-2893374115/TestDrainGivesUpWhenServerDown1328190854/002/d28882026/09/28 03:27:58 INFO Uploading batch count=228892026/09/28 03:27:58 ERROR Upload failed error="upload failed" count=228902026/09/28 03:27:58 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-34546-2893374115/TestDrainGivesUpWhenServerDown1328190854/002/e2891--- PASS: TestFailedPathPrunedByLaterClosure (0.00s)28922026/09/28 03:27:58 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-34546-2893374115/TestDrainGivesUpWhenServerDown1328190854/002/f28932026/09/28 03:27:58 ERROR Drain finished with paths left in queue remaining=1028942026/09/28 03:27:58 INFO Uploading batch count=428952026/09/28 03:27:58 ERROR Upload failed error="upload failed" count=428962026/09/28 03:27:58 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-34546-2893374115/TestDrainIsolatesPoisonPath2777235594/002/bbb28972026/09/28 03:27:58 INFO Uploading batch count=128982026/09/28 03:27:58 ERROR Upload failed error="upload failed" count=128992026/09/28 03:27:58 INFO Uploading batch count=129002026/09/28 03:27:58 ERROR Upload failed error="upload failed" count=12901--- PASS: TestDrainGivesUpWhenServerDown (0.01s)29022026/09/28 03:27:58 INFO Uploading batch count=129032026/09/28 03:27:58 ERROR Upload failed error="upload failed" count=129042026/09/28 03:27:58 ERROR Drain finished with paths left in queue remaining=12905--- PASS: TestDrainIsolatesPoisonPath (0.00s)2906--- PASS: TestWorkerUploadsAndRemoves (0.03s)2907--- PASS: TestWorkerSkipsGCdPaths (0.03s)2908--- PASS: TestWorkerPrunesClosureDeps (0.03s)2909--- PASS: TestQueueRemoveLargeClosure (0.05s)2910--- PASS: TestQueueConcurrentWriters (0.15s)29112026/09/28 03:27:59 ERROR Upload failed error="context deadline exceeded" count=229122026/09/28 03:27:59 ERROR Drain finished with paths left in queue remaining=42913--- PASS: TestDrainTimeout (0.21s)29142026/09/28 03:27:59 INFO Uploading batch count=129152026/09/28 03:27:59 INFO Uploading batch count=129162026/09/28 03:27:59 INFO Uploading batch count=129172026/09/28 03:27:59 ERROR Upload failed error="upload failed" count=129182026/09/28 03:27:59 INFO Uploading batch count=129192026/09/28 03:27:59 ERROR Upload failed error="upload failed" count=129202026/09/28 03:27:59 INFO Uploading batch count=129212026/09/28 03:27:59 ERROR Upload failed error="upload failed" count=129222026/09/28 03:27:59 INFO Uploading batch count=129232026/09/28 03:27:59 ERROR Upload failed error="upload failed" count=129242026/09/28 03:27:59 ERROR Drain finished with paths left in queue remaining=12925--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2926PASS