niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #261
· 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.03s)18=== RUN TestDumpPathCaseHackCollision19--- PASS: TestDumpPathCaseHackCollision (0.00s)20=== RUN TestDumpPathMatchesNix21=== PAUSE TestDumpPathMatchesNix22=== RUN TestDumpPathSingleFile23=== PAUSE TestDumpPathSingleFile24=== RUN TestDumpPathWriterError25=== PAUSE TestDumpPathWriterError26=== RUN TestEncodeNixBase3227=== PAUSE TestEncodeNixBase3228=== RUN TestEncodeNixBase32WithRealHash29=== PAUSE TestEncodeNixBase32WithRealHash30=== RUN TestConvertHashToNix3231=== PAUSE TestConvertHashToNix3232=== RUN TestGetStorePathHash33=== PAUSE TestGetStorePathHash34=== RUN TestPathInfoHashCompatibility35=== PAUSE TestPathInfoHashCompatibility36=== RUN TestParsePathInfoJSON37=== PAUSE TestParsePathInfoJSON38=== RUN TestParsePathInfoJSONMultiplePaths39=== PAUSE TestParsePathInfoJSONMultiplePaths40=== RUN TestPathInfoCACompatibility41=== PAUSE TestPathInfoCACompatibility42=== RUN TestRateLimiterFeedback43=== PAUSE TestRateLimiterFeedback44=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess45=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== RUN TestResolveStorePath47=== PAUSE TestResolveStorePath48=== RUN TestDoWithRetry_BodyReplayedViaGetBody49=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody50=== RUN TestShellSplit51=== PAUSE TestShellSplit52=== RUN TestShellSplitErrors53=== PAUSE TestShellSplitErrors54=== RUN TestStreamPushReportsEveryPath55=== PAUSE TestStreamPushReportsEveryPath56=== RUN TestStreamPushBatchesUnderLoad57=== PAUSE TestStreamPushBatchesUnderLoad58=== RUN TestStreamPushIsolatesFailures59=== PAUSE TestStreamPushIsolatesFailures60=== RUN TestStreamPushGivesUpOnDeadServer61=== PAUSE TestStreamPushGivesUpOnDeadServer62=== RUN TestStreamPushRequestLine63=== PAUSE TestStreamPushRequestLine64=== RUN TestStreamPushReportsSignatures65=== PAUSE TestStreamPushReportsSignatures66=== RUN TestClientSignaturesByStorePath67=== PAUSE TestClientSignaturesByStorePath68=== RUN TestSetClientTLS69=== PAUSE TestSetClientTLS70=== RUN TestSetClientTLSDoesNotMutateDefaultTransport71=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport72=== RUN TestSetClientTLSErrors73=== PAUSE TestSetClientTLSErrors74=== RUN TestStaticToken75=== PAUSE TestStaticToken76=== RUN TestFileTokenReadsAndCaches77=== PAUSE TestFileTokenReadsAndCaches78=== RUN TestFileTokenMissing79=== PAUSE TestFileTokenMissing80=== RUN TestFileTokenEmpty81=== PAUSE TestFileTokenEmpty82=== RUN TestScriptTokenNoExpiryRerunsEveryCall83=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall84=== RUN TestScriptTokenCachesUntilRefresh85=== PAUSE TestScriptTokenCachesUntilRefresh86=== RUN TestScriptTokenEmptyToken87=== PAUSE TestScriptTokenEmptyToken88=== RUN TestScriptTokenBadJSON89=== PAUSE TestScriptTokenBadJSON90=== RUN TestScriptTokenScriptFails91=== PAUSE TestScriptTokenScriptFails92=== RUN TestScriptTokenEmptyCommand93=== PAUSE TestScriptTokenEmptyCommand94=== CONT TestDoServerRequestAttachesToken95=== CONT TestShellSplit96=== CONT TestEncodeNixBase32WithRealHash97=== CONT TestSetClientTLSErrors98=== CONT TestFileTokenMissing99=== CONT TestScriptTokenEmptyCommand100=== CONT TestFileTokenReadsAndCaches101=== CONT TestScriptTokenScriptFails102=== CONT TestScriptTokenBadJSON103=== CONT TestScriptTokenEmptyToken104=== CONT TestScriptTokenCachesUntilRefresh105=== CONT TestScriptTokenNoExpiryRerunsEveryCall106=== CONT TestPathInfoHashCompatibility107--- PASS: TestEncodeNixBase32WithRealHash (0.00s)108--- PASS: TestShellSplit (0.00s)109--- PASS: TestScriptTokenEmptyCommand (0.00s)110--- PASS: TestFileTokenMissing (0.00s)111--- PASS: TestFileTokenReadsAndCaches (0.00s)112=== CONT TestFileTokenEmpty113=== CONT TestStaticToken114--- PASS: TestStaticToken (0.00s)115=== CONT TestParsePathInfoJSONMultiplePaths116=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths117=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)118=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)119=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths120=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon121=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon122=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI123=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI124=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths125=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths126=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512127=== CONT TestParsePathInfoJSON128=== RUN TestParsePathInfoJSON/Nix_format129=== PAUSE TestParsePathInfoJSON/Nix_format130=== RUN TestParsePathInfoJSON/Lix_format131=== PAUSE TestParsePathInfoJSON/Lix_format132--- PASS: TestScriptTokenScriptFails (0.00s)133=== RUN TestParsePathInfoJSON/empty_input134=== CONT TestUploadMultipart_SupersededByPeer135=== PAUSE TestParsePathInfoJSON/empty_input136=== RUN TestParsePathInfoJSON/whitespace_only137=== PAUSE TestParsePathInfoJSON/whitespace_only138--- PASS: TestFileTokenEmpty (0.00s)139=== RUN TestParsePathInfoJSON/invalid_JSON140=== PAUSE TestParsePathInfoJSON/invalid_JSON141=== RUN TestUploadMultipart_SupersededByPeer/exists142=== CONT TestEncodeNixBase32143=== PAUSE TestUploadMultipart_SupersededByPeer/exists144=== RUN TestEncodeNixBase32/test_string_hash145=== RUN TestUploadMultipart_SupersededByPeer/missing146=== PAUSE TestUploadMultipart_SupersededByPeer/missing147=== CONT TestDumpPathWriterError148=== PAUSE TestEncodeNixBase32/test_string_hash149=== RUN TestEncodeNixBase32/empty_input150=== PAUSE TestEncodeNixBase32/empty_input151=== CONT TestDumpPathMatchesNix152=== CONT TestDumpPathSingleFile153=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512154=== RUN TestSetClientTLSErrors/missing_cert_file155=== PAUSE TestSetClientTLSErrors/missing_cert_file156=== RUN TestSetClientTLSErrors/missing_key_file157=== PAUSE TestSetClientTLSErrors/missing_key_file158=== RUN TestSetClientTLSErrors/missing_ca_file159=== PAUSE TestSetClientTLSErrors/missing_ca_file160=== RUN TestSetClientTLSErrors/invalid_ca_file161=== PAUSE TestSetClientTLSErrors/invalid_ca_file162=== CONT TestSetClientTLSDoesNotMutateDefaultTransport163=== CONT TestStreamPushRequestLine1642026/09/23 13:01:36 ERROR Upload failed error=boom count=1165--- PASS: TestDoServerRequestAttachesToken (0.01s)166=== CONT TestPathInfoCACompatibility167=== RUN TestPathInfoCACompatibility/null_ca_field168=== PAUSE TestPathInfoCACompatibility/null_ca_field169=== RUN TestPathInfoCACompatibility/old_string_format_-_text170=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text171=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive172=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive173=== RUN TestPathInfoCACompatibility/new_structured_format_-_text174=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text175=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method176=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method177=== CONT TestSetClientTLS178--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)179=== CONT TestDoWithRetry_BodyReplayedViaGetBody1802026/09/23 13:01:36 WARN Rate limiter enabled after throttle name=server-test rate=51812026/09/23 13:01:36 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:57053182=== RUN TestSetClientTLS/rejects_connection_without_client_cert183=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert1842026/09/23 13:01:36 WARN Rate limiter backed off name=server-test rate=5185=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA186=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA187=== RUN TestSetClientTLS/preserves_debug_logging_transport1882026/09/23 13:01:36 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:57053189=== PAUSE TestSetClientTLS/preserves_debug_logging_transport190=== CONT TestClientSignaturesByStorePath191--- PASS: TestClientSignaturesByStorePath (0.00s)192=== CONT TestResolveStorePath193--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)194=== CONT TestStreamPushReportsSignatures1952026/09/23 13:01:36 ERROR Upload failed error=boom count=1196--- PASS: TestStreamPushReportsSignatures (0.00s)197=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1982026/09/23 13:01:36 WARN Rate limiter enabled after throttle name=server-test rate=5199--- PASS: TestResolveStorePath (0.00s)200=== CONT TestRateLimiterFeedback201=== RUN TestRateLimiterFeedback/429_enables_limiter202=== PAUSE TestRateLimiterFeedback/429_enables_limiter203=== RUN TestRateLimiterFeedback/503_enables_limiter204=== PAUSE TestRateLimiterFeedback/503_enables_limiter205=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter206=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter207=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter208=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter209=== CONT TestStreamPushBatchesUnderLoad210--- PASS: TestStreamPushRequestLine (0.01s)211=== CONT TestStreamPushGivesUpOnDeadServer2122026/09/23 13:01:36 ERROR Upload failed error="connection refused" count=202132026/09/23 13:01:36 ERROR Server seems unavailable, giving up on batch untried=17214--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)215=== CONT TestGetStorePathHash216=== RUN TestGetStorePathHash/valid_store_path217=== PAUSE TestGetStorePathHash/valid_store_path218=== RUN TestGetStorePathHash/basename_without_hyphen_should_error219=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error220=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error221=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error222=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error223=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error224=== CONT TestStreamPushIsolatesFailures2252026/09/23 13:01:36 ERROR Upload failed error="bad path" count=3226--- PASS: TestStreamPushIsolatesFailures (0.00s)227=== CONT TestFilterOversizedClosures228=== RUN TestFilterOversizedClosures/no_limit_keeps_everything229=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything230=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped231=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped232=== RUN TestFilterOversizedClosures/all_closures_skipped233=== PAUSE TestFilterOversizedClosures/all_closures_skipped234=== CONT TestCaseHackSuffix235--- PASS: TestScriptTokenBadJSON (0.01s)236=== CONT TestPartSizeForNAR237=== RUN TestPartSizeForNAR/zero_stays_at_minimum238=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum239=== RUN TestPartSizeForNAR/small_stays_at_minimum240=== PAUSE TestPartSizeForNAR/small_stays_at_minimum241--- PASS: TestScriptTokenEmptyToken (0.01s)242=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum243=== CONT TestUploadMultipart_PartsInParallel244=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum245=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts246=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts247=== RUN TestPartSizeForNAR/1_TiB248=== PAUSE TestPartSizeForNAR/1_TiB249=== RUN TestPartSizeForNAR/5_TiB_S3_max_object250=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object251=== RUN TestPartSizeForNAR/capped_at_5_GiB252=== PAUSE TestPartSizeForNAR/capped_at_5_GiB253=== CONT TestStreamPushReportsEveryPath254--- PASS: TestStreamPushReportsEveryPath (0.00s)255=== CONT TestConvertHashToNix32256=== RUN TestConvertHashToNix32/SRI_format_to_Nix32257=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32258=== RUN TestConvertHashToNix32/already_Nix32_format259=== PAUSE TestConvertHashToNix32/already_Nix32_format260=== RUN TestConvertHashToNix32/invalid_format261=== PAUSE TestConvertHashToNix32/invalid_format262=== CONT TestShellSplitErrors263--- PASS: TestShellSplitErrors (0.00s)264=== CONT TestRegisterUploadedObjectReusesConnections265--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)266=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths267=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths268--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)269 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)270 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)271=== CONT TestParsePathInfoJSON/Nix_format272=== CONT TestUploadMultipart_SupersededByPeer/exists273--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)274=== CONT TestParsePathInfoJSON/invalid_JSON275=== CONT TestParsePathInfoJSON/whitespace_only276=== CONT TestEncodeNixBase32/test_string_hash277=== CONT TestEncodeNixBase32/empty_input278--- PASS: TestEncodeNixBase32 (0.00s)279 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)280 --- PASS: TestEncodeNixBase32/empty_input (0.00s)281=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)282=== CONT TestParsePathInfoJSON/Lix_format283=== CONT TestSetClientTLSErrors/missing_cert_file284=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512285=== CONT TestUploadMultipart_SupersededByPeer/missing286=== CONT TestParsePathInfoJSON/empty_input287--- PASS: TestParsePathInfoJSON (0.00s)288 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)289 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)290 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)291 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)292 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)293=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI294=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon295--- PASS: TestPathInfoHashCompatibility (0.00s)296 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)297 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)298 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)299 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)300=== CONT TestSetClientTLSErrors/missing_ca_file301=== CONT TestSetClientTLSErrors/invalid_ca_file302=== CONT TestSetClientTLSErrors/missing_key_file303=== CONT TestPathInfoCACompatibility/null_ca_field304--- PASS: TestSetClientTLSErrors (0.00s)305 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)306 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)307 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)308 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)309=== CONT TestPathInfoCACompatibility/new_structured_format_-_text310=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive311=== CONT TestPathInfoCACompatibility/old_string_format_-_text312--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)313 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)314 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)315=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method316--- PASS: TestPathInfoCACompatibility (0.00s)317 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)318 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)319 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)320 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)321 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)322=== CONT TestSetClientTLS/rejects_connection_without_client_cert323=== CONT TestSetClientTLS/preserves_debug_logging_transport324=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA325=== CONT TestRateLimiterFeedback/429_enables_limiter3262026/09/23 13:01:36 WARN Rate limiter enabled after throttle name=server-test rate=53272026/09/23 13:01:36 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:571353282026/09/23 13:01:36 WARN Rate limiter backed off name=server-test rate=5329=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter330--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)331=== CONT TestRateLimiterFeedback/503_enables_limiter3322026/09/23 13:01:36 WARN Rate limiter enabled after throttle name=server-test rate=53332026/09/23 13:01:36 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:57139334=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter3352026/09/23 13:01:36 WARN Rate limiter backed off name=server-test rate=5336=== CONT TestGetStorePathHash/valid_store_path337=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error338=== CONT TestGetStorePathHash/basename_without_hyphen_should_error339=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error340=== CONT TestFilterOversizedClosures/no_limit_keeps_everything341=== CONT TestFilterOversizedClosures/all_closures_skipped342--- PASS: TestGetStorePathHash (0.00s)343 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)344 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)345 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)346 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)3472026/09/23 13:01:36 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=50348=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3492026/09/23 13:01:36 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=2000350--- PASS: TestFilterOversizedClosures (0.00s)351 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)352 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)353 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)354=== CONT TestPartSizeForNAR/zero_stays_at_minimum355=== CONT TestPartSizeForNAR/capped_at_5_GiB356=== CONT TestPartSizeForNAR/5_TiB_S3_max_object357=== CONT TestPartSizeForNAR/1_TiB358=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts359=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum360=== CONT TestPartSizeForNAR/small_stays_at_minimum361--- PASS: TestPartSizeForNAR (0.00s)362 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)363 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)364 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)365 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)366 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)367 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)368 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)369=== CONT TestConvertHashToNix32/SRI_format_to_Nix32370=== CONT TestConvertHashToNix32/invalid_format371=== CONT TestConvertHashToNix32/already_Nix32_format372--- PASS: TestConvertHashToNix32 (0.00s)373 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)374 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)375 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)376--- PASS: TestRateLimiterFeedback (0.00s)377 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)378 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)379 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)380 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)3812026/09/23 13:01:36 http: TLS handshake error from 127.0.0.1:57132: read tcp 127.0.0.1:57055->127.0.0.1:57132: use of closed network connection382--- PASS: TestSetClientTLS (0.00s)383 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)384 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)385 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)386--- PASS: TestDumpPathWriterError (0.05s)387--- PASS: TestDumpPathSingleFile (0.05s)388--- PASS: TestCaseHackSuffix (0.04s)389--- PASS: TestDumpPathMatchesNix (0.08s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestUploadMultipart_PartsInParallel (0.62s)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-51385-2205677552/postgres4046588485/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-51385-2205677552/postgres4046588485/data -l logfile start421422/nix/var/nix/builds/nix-51385-2205677552/postgres4046588485:5432 - no response4232026-09-23 13:01:37.925 UTC [51480] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4242026-09-23 13:01:37.925 UTC [51480] LOG: listening on Unix socket "/nix/var/nix/builds/nix-51385-2205677552/postgres4046588485/.s.PGSQL.5432"4252026-09-23 13:01:37.927 UTC [51487] LOG: database system was shut down at 2026-09-23 13:01:37 UTC4262026-09-23 13:01:37.928 UTC [51480] LOG: database system is ready to accept connections427/nix/var/nix/builds/nix-51385-2205677552/postgres4046588485:5432 - accepting connections428{"timestamp":"2026-09-23T13:01:38.14212Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"b00dd940-0edb-4d1d-b804-b30236b2be96","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":463,"threadName":"rustfs-worker","threadId":"ThreadId(7)"}429{"timestamp":"2026-09-23T13:01:38.245938Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"4f818ca1-42db-4df3-b0b3-45129b4bb19b","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":463,"threadName":"rustfs-worker","threadId":"ThreadId(4)"}430=== RUN TestService_AuthMiddleware431=== PAUSE TestService_AuthMiddleware432=== RUN TestService_AuthMiddleware_MTLSProxyHeader433=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader434=== RUN TestService_AuthMiddleware_MTLSBoundSubjects435=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects436=== RUN TestService_ReadAuthMiddleware437=== PAUSE TestService_ReadAuthMiddleware438=== RUN TestService_AuthMiddleware_OIDC439=== PAUSE TestService_AuthMiddleware_OIDC440=== RUN TestService_RequireScope_OIDC441=== PAUSE TestService_RequireScope_OIDC442=== RUN TestService_ReadScope_PublicByDefault443=== PAUSE TestService_ReadScope_PublicByDefault444=== RUN TestCacheConfigHandler445=== PAUSE TestCacheConfigHandler446=== RUN TestCacheStatsHandler447=== PAUSE TestCacheStatsHandler448=== RUN TestClientCADerivations449=== PAUSE TestClientCADerivations450=== RUN TestClientErrorHandling451=== PAUSE TestClientErrorHandling452=== RUN TestClientIntegration453=== PAUSE TestClientIntegration454=== RUN TestClientMultipleUploads455=== PAUSE TestClientMultipleUploads456=== RUN TestClientWithDependencies457=== PAUSE TestClientWithDependencies458=== RUN TestClientSharedPathCommittedMidPush459=== PAUSE TestClientSharedPathCommittedMidPush460=== RUN TestPinProtectsFromGC461=== PAUSE TestPinProtectsFromGC462=== RUN TestClientPushesUseOnePush463=== PAUSE TestClientPushesUseOnePush464=== RUN TestClientFallsBackToClosures465=== PAUSE TestClientFallsBackToClosures466=== RUN TestResolveDBConnectionString467=== PAUSE TestResolveDBConnectionString468=== RUN TestLeadElectsOneAndHandsOver469=== PAUSE TestLeadElectsOneAndHandsOver470=== RUN TestLeadIncumbentWinsAfterRestart4712026-09-23 13:01:38.440 UTC [51524] ERROR: relation "goose_db_version" does not exist at character 364722026-09-23 13:01:38.440 UTC [51524] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4732026/09/23 13:01:38 OK 20241026095416_initial_model.sql (3.93ms)4742026/09/23 13:01:38 OK 20251210153512_drop_unused_gin_index.sql (625.79µs)4752026/09/23 13:01:38 OK 20251218171726_add_pins.sql (944.42µs)4762026/09/23 13:01:38 OK 20260628120000_add_object_size_and_stats.sql (903.46µs)4772026/09/23 13:01:38 OK 20260905000000_add_claims.sql (1.03ms)4782026/09/23 13:01:38 OK 20260920000000_drop_claims.sql (620.21µs)4792026/09/23 13:01:38 OK 20260923120000_add_pushes.sql (412.38µs)4802026/09/23 13:01:38 goose: successfully migrated database to version: 202609231200004812026/09/23 13:01:38 OK 1_commit_pending_closure.sql (829.42µs)4822026/09/23 13:01:38 OK 2_object_stats_trigger.sql (191.08µs)4832026/09/23 13:01:38 OK 3_commit_push.sql (191.58µs)4842026/09/23 13:01:38 goose: up to current file version: 34852026/09/23 13:01:38 INFO lead: acquired remote=192.0.2.1:12344862026/09/23 13:01:39 INFO lead: released remote=192.0.2.1:12344872026/09/23 13:01:39 INFO lead: acquired remote=192.0.2.1:12344882026/09/23 13:01:39 INFO lead: released remote=192.0.2.1:1234489--- PASS: TestLeadIncumbentWinsAfterRestart (0.82s)490=== RUN TestLeadEndsOnShutdown491=== PAUSE TestLeadEndsOnShutdown492=== RUN TestGCAdvisoryLockBlocksConcurrentRun4932026-09-23 13:01:39.222 UTC [51536] ERROR: relation "goose_db_version" does not exist at character 364942026-09-23 13:01:39.222 UTC [51536] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4952026/09/23 13:01:39 OK 20241026095416_initial_model.sql (3.22ms)4962026/09/23 13:01:39 OK 20251210153512_drop_unused_gin_index.sql (523.88µs)4972026/09/23 13:01:39 OK 20251218171726_add_pins.sql (694.71µs)4982026/09/23 13:01:39 OK 20260628120000_add_object_size_and_stats.sql (795.38µs)4992026/09/23 13:01:39 OK 20260905000000_add_claims.sql (927.71µs)5002026/09/23 13:01:39 OK 20260920000000_drop_claims.sql (562.54µs)5012026/09/23 13:01:39 OK 20260923120000_add_pushes.sql (362.71µs)5022026/09/23 13:01:39 goose: successfully migrated database to version: 202609231200005032026/09/23 13:01:39 OK 1_commit_pending_closure.sql (856.58µs)5042026/09/23 13:01:39 OK 2_object_stats_trigger.sql (186.21µs)5052026/09/23 13:01:39 OK 3_commit_push.sql (174.33µs)5062026/09/23 13:01:39 goose: up to current file version: 3507--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.13s)508=== RUN TestGCBugBareHashReferences509=== PAUSE TestGCBugBareHashReferences510=== RUN TestGCMetrics511=== PAUSE TestGCMetrics512=== RUN TestGCTaskStore_StartNew513=== PAUSE TestGCTaskStore_StartNew514=== RUN TestGCTaskStore_DeduplicateSameParams515=== PAUSE TestGCTaskStore_DeduplicateSameParams516=== RUN TestGCTaskStore_ConflictDifferentParams517=== PAUSE TestGCTaskStore_ConflictDifferentParams518=== RUN TestGCTaskStore_GetEmpty519=== PAUSE TestGCTaskStore_GetEmpty520=== RUN TestGCTaskStore_GetReturnsLatest521=== PAUSE TestGCTaskStore_GetReturnsLatest522=== RUN TestGCTaskStore_CompletedAllowsNewTask523=== PAUSE TestGCTaskStore_CompletedAllowsNewTask524=== RUN TestGCTaskStore_PhaseUpdates525=== PAUSE TestGCTaskStore_PhaseUpdates526=== RUN TestGCTaskStore_Fail527=== PAUSE TestGCTaskStore_Fail528=== RUN TestGracefulShutdownDrainsInflight529=== PAUSE TestGracefulShutdownDrainsInflight530=== RUN TestService_healthCheckHandler531=== PAUSE TestService_healthCheckHandler532=== RUN TestService_readinessHandler533=== PAUSE TestService_readinessHandler534=== RUN TestGenerateLandingPage535=== PAUSE TestGenerateLandingPage536=== RUN TestCacheConfigHandlerMaxNarSize537=== PAUSE TestCacheConfigHandlerMaxNarSize538=== RUN TestCreatePendingClosureRejectsOversizedNAR539=== PAUSE TestCreatePendingClosureRejectsOversizedNAR540=== RUN TestNARDeduplicationMetadataUploadBug541=== PAUSE TestNARDeduplicationMetadataUploadBug542=== RUN TestMetricsInventory543=== PAUSE TestMetricsInventory544=== RUN TestService_NativeMTLS545=== PAUSE TestService_NativeMTLS546=== RUN TestServerTLSConfig547=== PAUSE TestServerTLSConfig548=== RUN TestMultipartCleanup549=== PAUSE TestMultipartCleanup550=== RUN TestObjectStatsTrigger551=== PAUSE TestObjectStatsTrigger552=== RUN TestOrphanedObjectsGC553=== PAUSE TestOrphanedObjectsGC554=== RUN TestOrphanedObjectsGCStressTest555=== PAUSE TestOrphanedObjectsGCStressTest556=== RUN TestResurrectedObjectNotDeleted557=== PAUSE TestResurrectedObjectNotDeleted558=== RUN TestCreatePin_ReservedPins559=== PAUSE TestCreatePin_ReservedPins560=== RUN TestParseSingleRange561=== PAUSE TestParseSingleRange562=== RUN TestProxyHeadersOnlyTrustedOnSocket563=== PAUSE TestProxyHeadersOnlyTrustedOnSocket564=== RUN TestIsValidCachePath565=== PAUSE TestIsValidCachePath566=== RUN TestReadProxyNarinfo567=== PAUSE TestReadProxyNarinfo568=== RUN TestReadProxyNarinfoAlreadyDecompressed569=== PAUSE TestReadProxyNarinfoAlreadyDecompressed570=== RUN TestReadProxyNarStreaming571=== PAUSE TestReadProxyNarStreaming572=== RUN TestReadProxy404573=== PAUSE TestReadProxy404574=== RUN TestReadProxyInvalidPath575=== PAUSE TestReadProxyInvalidPath576=== RUN TestReadProxyHead577=== PAUSE TestReadProxyHead578=== RUN TestReadProxyConditionalGet579=== PAUSE TestReadProxyConditionalGet580=== RUN TestReadProxyRootRedirectsToIndexHTML581=== PAUSE TestReadProxyRootRedirectsToIndexHTML582=== RUN TestReadProxyDisabled583=== PAUSE TestReadProxyDisabled584=== RUN TestReadRedirectNar585=== PAUSE TestReadRedirectNar586=== RUN TestReadRedirectKeepsNarinfoProxied587=== PAUSE TestReadRedirectKeepsNarinfoProxied588=== RUN TestReadProxyRangeRequest589=== PAUSE TestReadProxyRangeRequest590=== RUN TestReadRedirectUsesPublicS3URL591=== PAUSE TestReadRedirectUsesPublicS3URL592=== RUN TestPush_OverlappingRootsStoreOneRowPerKey593=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey594=== RUN TestPush_CompleteCommitsEveryRoot595=== PAUSE TestPush_CompleteCommitsEveryRoot596=== RUN TestPush_CommitFailsWhenSkippedKeyWasCollected597=== PAUSE TestPush_CommitFailsWhenSkippedKeyWasCollected598=== RUN TestPush_RejectsBadRequests599=== PAUSE TestPush_RejectsBadRequests600=== RUN TestPush_SignsNarinfosOfItsPendingObjects601=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects602=== RUN TestRedundantMultipartUpload603=== PAUSE TestRedundantMultipartUpload604=== RUN TestCompleteMultipartUpload_ErrorButObjectExists605=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists606=== RUN TestCompletedNarNotReofferedAcrossClosures607=== PAUSE TestCompletedNarNotReofferedAcrossClosures608=== RUN TestPresignedUploadRegisteredBeforeCommit609=== PAUSE TestPresignedUploadRegisteredBeforeCommit610=== RUN TestService_Rustfstest611=== PAUSE TestService_Rustfstest612=== RUN TestParseSize613=== PAUSE TestParseSize614=== RUN TestSkippedUploadsHandler615=== PAUSE TestSkippedUploadsHandler616=== RUN TestSystemdListenerNotActivated617--- PASS: TestSystemdListenerNotActivated (0.00s)618=== RUN TestWatchdogBeatsWhenHealthy619--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)620=== RUN TestWatchdogSkipsWhenUnhealthy6212026/09/23 13:01:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6222026/09/23 13:01:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6232026/09/23 13:01:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6242026/09/23 13:01:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6252026/09/23 13:01:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6262026/09/23 13:01:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6272026/09/23 13:01:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6282026/09/23 13:01:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6292026/09/23 13:01:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6302026/09/23 13:01:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"631--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)632=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle633=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle634=== RUN TestProxyWriteTimeout635=== PAUSE TestProxyWriteTimeout636=== RUN TestIsValidUploadKey637=== PAUSE TestIsValidUploadKey638=== RUN TestUploadHandlersRejectInvalidKeys639=== PAUSE TestUploadHandlersRejectInvalidKeys640=== RUN TestUploadHandlersRejectOversizedBody641=== PAUSE TestUploadHandlersRejectOversizedBody642=== RUN TestService_cleanupPendingClosuresHandler643=== PAUSE TestService_cleanupPendingClosuresHandler644=== RUN TestService_createPendingClosureHandler645=== PAUSE TestService_createPendingClosureHandler646=== RUN TestService_verifyS3Integrity647=== PAUSE TestService_verifyS3Integrity648=== RUN TestCompleteMultipartUnregistered649=== PAUSE TestCompleteMultipartUnregistered650=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT651=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT652=== CONT TestService_AuthMiddleware653=== CONT TestOrphanedObjectsGC654=== CONT TestGCMetrics655=== CONT TestPush_CompleteCommitsEveryRoot656=== CONT TestClientIntegration657=== CONT TestObjectStatsTrigger658=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT659=== CONT TestCompleteMultipartUnregistered660=== CONT TestService_verifyS3Integrity661=== CONT TestService_createPendingClosureHandler6622026-09-23 13:01:39.790 UTC [51577] ERROR: relation "goose_db_version" does not exist at character 366632026-09-23 13:01:39.790 UTC [51577] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6642026-09-23 13:01:39.792 UTC [51578] ERROR: relation "goose_db_version" does not exist at character 366652026-09-23 13:01:39.792 UTC [51578] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6662026-09-23 13:01:39.797 UTC [51579] ERROR: relation "goose_db_version" does not exist at character 366672026-09-23 13:01:39.797 UTC [51579] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6682026-09-23 13:01:39.799 UTC [51580] ERROR: relation "goose_db_version" does not exist at character 366692026-09-23 13:01:39.799 UTC [51580] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6702026-09-23 13:01:39.799 UTC [51582] ERROR: relation "goose_db_version" does not exist at character 366712026-09-23 13:01:39.799 UTC [51582] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6722026-09-23 13:01:39.800 UTC [51583] ERROR: relation "goose_db_version" does not exist at character 366732026-09-23 13:01:39.800 UTC [51583] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6742026-09-23 13:01:39.800 UTC [51581] ERROR: relation "goose_db_version" does not exist at character 366752026-09-23 13:01:39.800 UTC [51581] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6762026-09-23 13:01:39.800 UTC [51585] ERROR: relation "goose_db_version" does not exist at character 366772026-09-23 13:01:39.800 UTC [51585] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6782026-09-23 13:01:39.801 UTC [51584] ERROR: relation "goose_db_version" does not exist at character 366792026-09-23 13:01:39.801 UTC [51584] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6802026-09-23 13:01:39.801 UTC [51586] ERROR: relation "goose_db_version" does not exist at character 366812026-09-23 13:01:39.801 UTC [51586] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6822026/09/23 13:01:39 OK 20241026095416_initial_model.sql (5.38ms)6832026/09/23 13:01:39 OK 20251210153512_drop_unused_gin_index.sql (895.58µs)6842026/09/23 13:01:39 OK 20241026095416_initial_model.sql (7.36ms)6852026/09/23 13:01:39 OK 20251218171726_add_pins.sql (1.67ms)6862026/09/23 13:01:39 OK 20251210153512_drop_unused_gin_index.sql (876.25µs)6872026/09/23 13:01:39 OK 20260628120000_add_object_size_and_stats.sql (1.55ms)6882026/09/23 13:01:39 OK 20251218171726_add_pins.sql (1.54ms)6892026/09/23 13:01:39 OK 20241026095416_initial_model.sql (7.33ms)6902026/09/23 13:01:39 OK 20251210153512_drop_unused_gin_index.sql (658.71µs)6912026/09/23 13:01:39 OK 20260628120000_add_object_size_and_stats.sql (2ms)6922026/09/23 13:01:39 OK 20241026095416_initial_model.sql (6.41ms)6932026/09/23 13:01:39 OK 20260905000000_add_claims.sql (2.66ms)6942026/09/23 13:01:39 OK 20241026095416_initial_model.sql (7.48ms)6952026/09/23 13:01:39 OK 20251210153512_drop_unused_gin_index.sql (578.46µs)6962026/09/23 13:01:39 OK 20251218171726_add_pins.sql (1.52ms)6972026/09/23 13:01:39 OK 20251210153512_drop_unused_gin_index.sql (860.67µs)6982026/09/23 13:01:39 OK 20241026095416_initial_model.sql (7.09ms)6992026/09/23 13:01:39 OK 20260920000000_drop_claims.sql (1.55ms)7002026/09/23 13:01:39 OK 20251210153512_drop_unused_gin_index.sql (626.96µs)7012026/09/23 13:01:39 OK 20251218171726_add_pins.sql (2.02ms)7022026/09/23 13:01:39 OK 20241026095416_initial_model.sql (6.95ms)7032026/09/23 13:01:39 OK 20260905000000_add_claims.sql (2.91ms)7042026/09/23 13:01:39 OK 20251218171726_add_pins.sql (1.46ms)7052026/09/23 13:01:39 OK 20241026095416_initial_model.sql (8.16ms)7062026/09/23 13:01:39 OK 20260923120000_add_pushes.sql (1.16ms)7072026/09/23 13:01:39 goose: successfully migrated database to version: 202609231200007082026/09/23 13:01:39 OK 20241026095416_initial_model.sql (7.42ms)7092026/09/23 13:01:39 OK 20251210153512_drop_unused_gin_index.sql (636.58µs)7102026/09/23 13:01:39 OK 20251210153512_drop_unused_gin_index.sql (579.29µs)7112026/09/23 13:01:39 OK 20260628120000_add_object_size_and_stats.sql (2.43ms)7122026/09/23 13:01:39 OK 20251210153512_drop_unused_gin_index.sql (591.88µs)7132026/09/23 13:01:39 OK 20251218171726_add_pins.sql (1.78ms)7142026/09/23 13:01:39 OK 20241026095416_initial_model.sql (7.38ms)7152026/09/23 13:01:39 OK 20260920000000_drop_claims.sql (1.27ms)7162026/09/23 13:01:39 OK 20260628120000_add_object_size_and_stats.sql (1.43ms)7172026/09/23 13:01:39 OK 1_commit_pending_closure.sql (1.24ms)7182026/09/23 13:01:39 OK 20260628120000_add_object_size_and_stats.sql (1.79ms)7192026/09/23 13:01:39 OK 20251210153512_drop_unused_gin_index.sql (859.96µs)7202026/09/23 13:01:39 OK 2_object_stats_trigger.sql (554µs)7212026/09/23 13:01:39 OK 20251218171726_add_pins.sql (1.77ms)7222026/09/23 13:01:39 OK 20260923120000_add_pushes.sql (1.16ms)7232026/09/23 13:01:39 goose: successfully migrated database to version: 202609231200007242026/09/23 13:01:39 OK 3_commit_push.sql (385.13µs)7252026/09/23 13:01:39 goose: up to current file version: 37262026/09/23 13:01:39 OK 20260905000000_add_claims.sql (1.7ms)7272026/09/23 13:01:39 OK 20251218171726_add_pins.sql (1.95ms)7282026/09/23 13:01:39 OK 20260628120000_add_object_size_and_stats.sql (1.72ms)7292026/09/23 13:01:39 OK 20260905000000_add_claims.sql (1.57ms)7302026/09/23 13:01:39 OK 20251218171726_add_pins.sql (2.14ms)7312026/09/23 13:01:39 OK 1_commit_pending_closure.sql (864µs)7322026/09/23 13:01:39 OK 20260905000000_add_claims.sql (1.7ms)7332026/09/23 13:01:39 OK 20251218171726_add_pins.sql (1.75ms)7342026/09/23 13:01:39 OK 2_object_stats_trigger.sql (370.71µs)7352026/09/23 13:01:39 OK 20260920000000_drop_claims.sql (1.28ms)7362026/09/23 13:01:39 OK 3_commit_push.sql (287.17µs)7372026/09/23 13:01:39 goose: up to current file version: 37382026/09/23 13:01:39 OK 20260905000000_add_claims.sql (1.47ms)7392026/09/23 13:01:39 OK 20260628120000_add_object_size_and_stats.sql (1.63ms)7402026/09/23 13:01:39 OK 20260628120000_add_object_size_and_stats.sql (1.26ms)7412026/09/23 13:01:39 OK 20260920000000_drop_claims.sql (1.48ms)7422026/09/23 13:01:39 OK 20260923120000_add_pushes.sql (778.71µs)7432026/09/23 13:01:39 goose: successfully migrated database to version: 202609231200007442026/09/23 13:01:39 OK 20260628120000_add_object_size_and_stats.sql (2.36ms)7452026/09/23 13:01:39 OK 20260920000000_drop_claims.sql (1.5ms)7462026/09/23 13:01:39 OK 20260923120000_add_pushes.sql (804.75µs)7472026/09/23 13:01:39 goose: successfully migrated database to version: 202609231200007482026/09/23 13:01:39 OK 20260920000000_drop_claims.sql (1.25ms)7492026/09/23 13:01:39 OK 20260628120000_add_object_size_and_stats.sql (1.81ms)7502026/09/23 13:01:39 OK 20260905000000_add_claims.sql (1.35ms)7512026/09/23 13:01:39 OK 20260923120000_add_pushes.sql (693.25µs)7522026/09/23 13:01:39 goose: successfully migrated database to version: 202609231200007532026/09/23 13:01:39 OK 1_commit_pending_closure.sql (1.44ms)7542026/09/23 13:01:39 OK 2_object_stats_trigger.sql (208.33µs)7552026/09/23 13:01:39 OK 1_commit_pending_closure.sql (1.03ms)7562026/09/23 13:01:39 OK 3_commit_push.sql (180.46µs)7572026/09/23 13:01:39 goose: up to current file version: 37582026/09/23 13:01:39 OK 2_object_stats_trigger.sql (174.17µs)7592026/09/23 13:01:39 OK 1_commit_pending_closure.sql (878.71µs)7602026/09/23 13:01:39 OK 3_commit_push.sql (165.79µs)7612026/09/23 13:01:39 goose: up to current file version: 37622026/09/23 13:01:39 OK 2_object_stats_trigger.sql (191.83µs)7632026/09/23 13:01:39 OK 3_commit_push.sql (178.29µs)7642026/09/23 13:01:39 goose: up to current file version: 37652026/09/23 13:01:39 OK 20260905000000_add_claims.sql (6.67ms)7662026/09/23 13:01:39 OK 20260920000000_drop_claims.sql (7.36ms)7672026/09/23 13:01:39 OK 20260905000000_add_claims.sql (8.65ms)7682026/09/23 13:01:39 OK 20260923120000_add_pushes.sql (7.93ms)7692026/09/23 13:01:39 goose: successfully migrated database to version: 202609231200007702026/09/23 13:01:39 OK 20260923120000_add_pushes.sql (522.17µs)7712026/09/23 13:01:39 goose: successfully migrated database to version: 202609231200007722026/09/23 13:01:39 OK 20260905000000_add_claims.sql (8.06ms)7732026/09/23 13:01:39 OK 1_commit_pending_closure.sql (621.63µs)7742026/09/23 13:01:39 OK 1_commit_pending_closure.sql (757.25µs)7752026/09/23 13:01:39 OK 2_object_stats_trigger.sql (180.63µs)7762026/09/23 13:01:39 OK 2_object_stats_trigger.sql (207.96µs)7772026/09/23 13:01:39 OK 3_commit_push.sql (147.33µs)7782026/09/23 13:01:39 goose: up to current file version: 37792026/09/23 13:01:39 OK 3_commit_push.sql (166.38µs)7802026/09/23 13:01:39 goose: up to current file version: 37812026/09/23 13:01:39 OK 20260920000000_drop_claims.sql (32.06ms)7822026/09/23 13:01:39 OK 20260920000000_drop_claims.sql (33.66ms)7832026/09/23 13:01:39 OK 20260920000000_drop_claims.sql (32.19ms)7842026/09/23 13:01:39 OK 20260923120000_add_pushes.sql (686.13µs)7852026/09/23 13:01:39 goose: successfully migrated database to version: 202609231200007862026/09/23 13:01:39 OK 20260923120000_add_pushes.sql (714.88µs)7872026/09/23 13:01:39 goose: successfully migrated database to version: 202609231200007882026/09/23 13:01:39 OK 1_commit_pending_closure.sql (705.04µs)7892026/09/23 13:01:39 OK 1_commit_pending_closure.sql (721.5µs)7902026/09/23 13:01:39 OK 2_object_stats_trigger.sql (178.92µs)7912026/09/23 13:01:39 OK 2_object_stats_trigger.sql (186.17µs)7922026/09/23 13:01:39 OK 3_commit_push.sql (165.96µs)7932026/09/23 13:01:39 goose: up to current file version: 37942026/09/23 13:01:39 OK 3_commit_push.sql (181.92µs)7952026/09/23 13:01:39 goose: up to current file version: 37962026/09/23 13:01:39 OK 20260923120000_add_pushes.sql (6.41ms)7972026/09/23 13:01:39 goose: successfully migrated database to version: 202609231200007982026/09/23 13:01:39 OK 1_commit_pending_closure.sql (646.29µs)7992026/09/23 13:01:39 OK 2_object_stats_trigger.sql (177.17µs)8002026/09/23 13:01:39 OK 3_commit_push.sql (174.5µs)8012026/09/23 13:01:39 goose: up to current file version: 38022026/09/23 13:01:39 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"803--- PASS: TestService_AuthMiddleware (0.38s)804=== CONT TestMultipartCleanup8052026/09/23 13:01:40 INFO Aborted multipart uploads count=08062026/09/23 13:01:40 WARN Force mode enabled - objects will be deleted immediately without grace period8072026/09/23 13:01:40 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=08082026/09/23 13:01:40 INFO Vacuumed table table=pending_closures8092026/09/23 13:01:40 INFO Vacuumed table table=pending_objects8102026/09/23 13:01:40 INFO Vacuumed table table=multipart_uploads8112026/09/23 13:01:40 INFO Vacuumed table table=closures8122026/09/23 13:01:40 INFO Vacuumed table table=objects813--- PASS: TestGCMetrics (0.53s)814=== CONT TestService_cleanupPendingClosuresHandler8152026/09/23 13:01:40 INFO Received uploads request method=POST path=/api/pending_closures8162026/09/23 13:01:40 INFO Received uploads request method=POST path=/api/pending_closures8172026/09/23 13:01:40 INFO Received uploads request method=POST path=/api/pending_closures8182026/09/23 13:01:40 INFO Received push request method=POST path=/api/pushes8192026/09/23 13:01:40 INFO Received complete push request method=POST path=/api/pushes/1/complete820--- PASS: TestPush_CompleteCommitsEveryRoot (0.97s)821=== CONT TestUploadHandlersRejectOversizedBody822=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure823=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure824=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart825=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart826=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts827=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts828=== CONT TestServerTLSConfig829=== RUN TestServerTLSConfig/no_client_CA830=== PAUSE TestServerTLSConfig/no_client_CA831=== RUN TestServerTLSConfig/missing_CA_file832=== PAUSE TestServerTLSConfig/missing_CA_file833=== RUN TestServerTLSConfig/not_a_PEM_file834=== PAUSE TestServerTLSConfig/not_a_PEM_file835=== CONT TestUploadHandlersRejectInvalidKeys836=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info837=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info838=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal839=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal840=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key841=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key842=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key843=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key844=== CONT TestIsValidUploadKey845=== RUN TestIsValidUploadKey/narinfo846=== PAUSE TestIsValidUploadKey/narinfo847=== RUN TestIsValidUploadKey/nar_zst848=== PAUSE TestIsValidUploadKey/nar_zst849=== RUN TestIsValidUploadKey/nar_xz850=== PAUSE TestIsValidUploadKey/nar_xz851=== RUN TestIsValidUploadKey/nar_plain852=== PAUSE TestIsValidUploadKey/nar_plain853=== RUN TestIsValidUploadKey/listing854=== PAUSE TestIsValidUploadKey/listing855=== RUN TestIsValidUploadKey/build_log856=== PAUSE TestIsValidUploadKey/build_log857=== RUN TestIsValidUploadKey/build_log_home-manager_file858=== PAUSE TestIsValidUploadKey/build_log_home-manager_file859=== RUN TestIsValidUploadKey/build_log_plus_in_name860=== PAUSE TestIsValidUploadKey/build_log_plus_in_name861=== RUN TestIsValidUploadKey/build_log_question_mark862=== PAUSE TestIsValidUploadKey/build_log_question_mark863=== RUN TestIsValidUploadKey/build_log_equals864=== PAUSE TestIsValidUploadKey/build_log_equals865=== RUN TestIsValidUploadKey/realisation866=== PAUSE TestIsValidUploadKey/realisation867=== RUN TestIsValidUploadKey/realisation_plus_in_output868=== PAUSE TestIsValidUploadKey/realisation_plus_in_output869=== RUN TestIsValidUploadKey/nix-cache-info870=== PAUSE TestIsValidUploadKey/nix-cache-info871=== RUN TestIsValidUploadKey/index.html872=== PAUSE TestIsValidUploadKey/index.html873=== RUN TestIsValidUploadKey/narinfo_key,_nar_type874=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type875=== RUN TestIsValidUploadKey/nar_key,_narinfo_type876=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type877=== RUN TestIsValidUploadKey/listing_key,_narinfo_type878=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type879=== RUN TestIsValidUploadKey/traversal880=== PAUSE TestIsValidUploadKey/traversal881=== RUN TestIsValidUploadKey/traversal_nar882=== PAUSE TestIsValidUploadKey/traversal_nar883=== RUN TestIsValidUploadKey/absolute884=== PAUSE TestIsValidUploadKey/absolute885=== RUN TestIsValidUploadKey/empty_key886=== PAUSE TestIsValidUploadKey/empty_key887=== RUN TestIsValidUploadKey/unknown_type888=== PAUSE TestIsValidUploadKey/unknown_type889=== CONT TestProxyWriteTimeout890=== RUN TestProxyWriteTimeout/narinfo891=== PAUSE TestProxyWriteTimeout/narinfo892=== RUN TestProxyWriteTimeout/1_GiB_nar893=== PAUSE TestProxyWriteTimeout/1_GiB_nar894=== RUN TestProxyWriteTimeout/10_GiB_nar895=== PAUSE TestProxyWriteTimeout/10_GiB_nar896=== RUN TestProxyWriteTimeout/unknown_size897=== PAUSE TestProxyWriteTimeout/unknown_size898=== CONT TestService_NativeMTLS8992026-09-23 13:01:40.771 UTC [51598] ERROR: relation "goose_db_version" does not exist at character 369002026-09-23 13:01:40.771 UTC [51598] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC901--- PASS: TestObjectStatsTrigger (1.34s)902=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle9032026/09/23 13:01:40 OK 20241026095416_initial_model.sql (72.98ms)9042026/09/23 13:01:40 OK 20251210153512_drop_unused_gin_index.sql (12.55ms)9052026-09-23 13:01:40.931 UTC [51604] ERROR: relation "goose_db_version" does not exist at character 369062026-09-23 13:01:40.931 UTC [51604] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9072026/09/23 13:01:40 OK 20251218171726_add_pins.sql (39.96ms)9082026/09/23 13:01:40 OK 20260628120000_add_object_size_and_stats.sql (27.95ms)9092026/09/23 13:01:40 OK 20260905000000_add_claims.sql (32.8ms)9102026/09/23 13:01:41 OK 20260920000000_drop_claims.sql (39.88ms)9112026/09/23 13:01:41 OK 20260923120000_add_pushes.sql (22.01ms)9122026/09/23 13:01:41 goose: successfully migrated database to version: 202609231200009132026/09/23 13:01:41 OK 1_commit_pending_closure.sql (1.4ms)9142026/09/23 13:01:41 OK 2_object_stats_trigger.sql (332.25µs)9152026/09/23 13:01:41 OK 3_commit_push.sql (278.54µs)9162026/09/23 13:01:41 goose: up to current file version: 39172026/09/23 13:01:41 OK 20241026095416_initial_model.sql (139.65ms)9182026/09/23 13:01:41 OK 20251210153512_drop_unused_gin_index.sql (11.25ms)9192026/09/23 13:01:41 OK 20251218171726_add_pins.sql (24.79ms)9202026/09/23 13:01:41 OK 20260628120000_add_object_size_and_stats.sql (14.23ms)921=== NAME TestOrphanedObjectsGC922 orphaned_objects_gc_test.go:290: GC Test Summary:923 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A924 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B925 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)926 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)927 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects928--- PASS: TestOrphanedObjectsGC (1.66s)929=== CONT TestSkippedUploadsHandler9302026/09/23 13:01:41 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000931--- PASS: TestSkippedUploadsHandler (0.00s)932=== CONT TestMetricsInventory9332026/09/23 13:01:41 OK 20260905000000_add_claims.sql (45.71ms)9342026/09/23 13:01:41 OK 20260920000000_drop_claims.sql (26.98ms)9352026/09/23 13:01:41 OK 20260923120000_add_pushes.sql (8.66ms)9362026/09/23 13:01:41 goose: successfully migrated database to version: 202609231200009372026/09/23 13:01:41 OK 1_commit_pending_closure.sql (1.49ms)9382026/09/23 13:01:41 OK 2_object_stats_trigger.sql (293.92µs)939=== NAME TestClientIntegration940 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-51385-2205677552/TestClientIntegration3000681552/002/store/pi2bqcqbr82d35w7w3wdhh7gmb60b4dp-test-file.txt9412026/09/23 13:01:41 OK 3_commit_push.sql (519.96µs)9422026/09/23 13:01:41 goose: up to current file version: 39432026/09/23 13:01:41 INFO Received uploads request method=POST path=/api/pending_closures944--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.80s)945=== CONT TestParseSize946--- PASS: TestParseSize (0.00s)947=== CONT TestNARDeduplicationMetadataUploadBug9482026/09/23 13:01:41 INFO Received uploads request method=POST path=/api/pending_closures9492026/09/23 13:01:41 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9502026/09/23 13:01:41 INFO Uploading pi2bqcqbr82d35w7w3wdhh7gmb60b4dp-test-file.txt (152B)9512026/09/23 13:01:41 WARN Failed to register uploaded object key=pi2bqcqbr82d35w7w3wdhh7gmb60b4dp.ls error="server returned 404: 404 page not found\n"9522026/09/23 13:01:41 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"9532026/09/23 13:01:41 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9542026/09/23 13:01:41 INFO Signed narinfos id=1 count=19552026/09/23 13:01:41 INFO Uploading 1 narinfos9562026/09/23 13:01:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9572026/09/23 13:01:41 WARN Failed to register uploaded object key=pi2bqcqbr82d35w7w3wdhh7gmb60b4dp.narinfo error="server returned 404: 404 page not found\n"9582026/09/23 13:01:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9592026/09/23 13:01:41 INFO Completed upload id=19602026/09/23 13:01:41 INFO Upload complete. (157ms)9612026-09-23 13:01:41.490 UTC [51620] ERROR: relation "goose_db_version" does not exist at character 369622026-09-23 13:01:41.490 UTC [51620] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9632026/09/23 13:01:41 INFO All 1 paths already cached9642026/09/23 13:01:41 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ODUzMWU5NzgtZjVjMi00ZTZkLTg4ZTItNTEyMWViNmExMDkzLmY1MzJiMGVmLTFjYTItNGZkYy04MGQ0LTY4ZDZkOWY5NzgzZngxNzkwMTY4NTAwMjgyNjI2MDAw parts=109652026/09/23 13:01:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete966=== NAME TestClientIntegration967 client_integration_test.go:312: Retrieved narinfo from S3:968 StorePath: /nix/var/nix/builds/nix-51385-2205677552/TestClientIntegration3000681552/002/store/pi2bqcqbr82d35w7w3wdhh7gmb60b4dp-test-file.txt969 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst970 Compression: zstd971 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1972 NarSize: 152973 References: 974 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1975 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)976 client_integration_test.go:313: Decompressed .ls content (64 bytes):977 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}978 client_integration_test.go:316: Testing garbage collection...9792026/09/23 13:01:41 INFO Completed upload id=19802026/09/23 13:01:41 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009812026/09/23 13:01:41 INFO Received uploads request method=POST path=/api/pending_closures9822026/09/23 13:01:41 INFO Starting cleanup of old closures method=DELETE path=/api/closures9832026/09/23 13:01:41 INFO Aborted multipart uploads count=09842026/09/23 13:01:41 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=09852026/09/23 13:01:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9862026/09/23 13:01:41 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst987--- PASS: TestCompleteMultipartUnregistered (2.00s)988=== CONT TestService_Rustfstest9892026/09/23 13:01:41 INFO Vacuumed table table=pending_closures9902026/09/23 13:01:41 INFO Starting cleanup of old closures method=DELETE path=/api/closures9912026/09/23 13:01:41 INFO Garbage collection started9922026/09/23 13:01:41 INFO Aborted multipart uploads count=09932026/09/23 13:01:41 WARN Force mode enabled - objects will be deleted immediately without grace period9942026/09/23 13:01:41 INFO Vacuumed table table=pending_objects9952026/09/23 13:01:41 INFO Vacuumed table table=multipart_uploads9962026/09/23 13:01:41 INFO Vacuumed table table=closures9972026/09/23 13:01:41 INFO Vacuumed table table=objects9982026/09/23 13:01:41 OK 20241026095416_initial_model.sql (65.02ms)9992026/09/23 13:01:41 OK 20251210153512_drop_unused_gin_index.sql (5.93ms)10002026/09/23 13:01:41 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010012026/09/23 13:01:41 OK 20251218171726_add_pins.sql (10.05ms)1002--- PASS: TestService_createPendingClosureHandler (2.09s)1003=== CONT TestCreatePendingClosureRejectsOversizedNAR10042026/09/23 13:01:41 INFO Received uploads request method=POST path=/api/pending_closures1005--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1006=== CONT TestPresignedUploadRegisteredBeforeCommit10072026/09/23 13:01:41 OK 20260628120000_add_object_size_and_stats.sql (14.23ms)10082026/09/23 13:01:41 OK 20260905000000_add_claims.sql (18.07ms)10092026/09/23 13:01:41 OK 20260920000000_drop_claims.sql (14.26ms)10102026/09/23 13:01:41 INFO Received uploads request method=POST path=/api/pending_closures10112026/09/23 13:01:41 OK 20260923120000_add_pushes.sql (12.52ms)10122026/09/23 13:01:41 goose: successfully migrated database to version: 2026092312000010132026/09/23 13:01:41 OK 1_commit_pending_closure.sql (1.06ms)10142026/09/23 13:01:41 OK 2_object_stats_trigger.sql (278.54µs)10152026/09/23 13:01:41 OK 3_commit_push.sql (305.92µs)10162026/09/23 13:01:41 goose: up to current file version: 310172026/09/23 13:01:41 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=010182026/09/23 13:01:41 INFO Vacuumed table table=pending_closures10192026/09/23 13:01:41 INFO Vacuumed table table=pending_objects10202026/09/23 13:01:41 INFO Vacuumed table table=multipart_uploads10212026/09/23 13:01:41 INFO Vacuumed table table=closures10222026/09/23 13:01:41 INFO Vacuumed table table=objects10232026/09/23 13:01:41 INFO Received uploads request method=POST path=/api/pending_closures10242026/09/23 13:01:42 INFO Received cleanup request method=DELETE path=/api/pending_closures10252026/09/23 13:01:42 INFO Aborted multipart uploads count=11026--- PASS: TestMultipartCleanup (2.19s)1027=== CONT TestCacheConfigHandlerMaxNarSize1028--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1029=== CONT TestCompletedNarNotReofferedAcrossClosures10302026/09/23 13:01:42 INFO Received cleanup request method=DELETE path=/api/pending_closures10312026-09-23 13:01:42.126 UTC [51631] ERROR: relation "goose_db_version" does not exist at character 3610322026-09-23 13:01:42.126 UTC [51631] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10332026/09/23 13:01:42 INFO Aborted multipart uploads count=010342026/09/23 13:01:42 INFO Received uploads request method=POST path=/api/pending_closures10352026/09/23 13:01:42 INFO Received cleanup request method=DELETE path=/api/pending_closures10362026/09/23 13:01:42 INFO Aborted multipart uploads count=110372026/09/23 13:01:42 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10382026-09-23 13:01:42.207 UTC [51604] ERROR: Closure does not exist: id=110392026-09-23 13:01:42.207 UTC [51604] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE10402026-09-23 13:01:42.207 UTC [51604] STATEMENT: -- name: CommitPendingClosure :exec1041 SELECT commit_pending_closure($1::bigint)1042 1043--- PASS: TestService_cleanupPendingClosuresHandler (2.15s)1044=== CONT TestGenerateLandingPage1045--- PASS: TestGenerateLandingPage (0.00s)1046=== CONT TestCompleteMultipartUpload_ErrorButObjectExists10472026/09/23 13:01:42 OK 20241026095416_initial_model.sql (146.83ms)10482026/09/23 13:01:42 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10492026/09/23 13:01:42 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1050--- PASS: TestService_NativeMTLS (1.80s)1051=== CONT TestRedundantMultipartUpload10522026/09/23 13:01:42 OK 20251210153512_drop_unused_gin_index.sql (11.27ms)10532026/09/23 13:01:42 OK 20251218171726_add_pins.sql (33.72ms)10542026/09/23 13:01:42 OK 20260628120000_add_object_size_and_stats.sql (13.84ms)10552026/09/23 13:01:42 OK 20260905000000_add_claims.sql (3.38ms)10562026-09-23 13:01:42.404 UTC [51638] ERROR: relation "goose_db_version" does not exist at character 3610572026-09-23 13:01:42.404 UTC [51638] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10582026/09/23 13:01:42 OK 20260920000000_drop_claims.sql (1.22ms)10592026/09/23 13:01:42 OK 20260923120000_add_pushes.sql (753.17µs)10602026/09/23 13:01:42 goose: successfully migrated database to version: 2026092312000010612026/09/23 13:01:42 OK 1_commit_pending_closure.sql (1.38ms)10622026/09/23 13:01:42 OK 2_object_stats_trigger.sql (293.92µs)10632026/09/23 13:01:42 OK 3_commit_push.sql (308.21µs)10642026/09/23 13:01:42 goose: up to current file version: 310652026/09/23 13:01:42 OK 20241026095416_initial_model.sql (119.69ms)10662026/09/23 13:01:42 OK 20251210153512_drop_unused_gin_index.sql (12.45ms)10672026/09/23 13:01:42 INFO Received uploads request method=POST path=/api/pending_closures10682026/09/23 13:01:42 OK 20251218171726_add_pins.sql (33.2ms)10692026/09/23 13:01:42 OK 20260628120000_add_object_size_and_stats.sql (28.44ms)10702026/09/23 13:01:42 OK 20260905000000_add_claims.sql (47.38ms)10712026/09/23 13:01:42 OK 20260920000000_drop_claims.sql (7.5ms)10722026/09/23 13:01:42 OK 20260923120000_add_pushes.sql (1.83ms)10732026/09/23 13:01:42 goose: successfully migrated database to version: 2026092312000010742026/09/23 13:01:42 OK 1_commit_pending_closure.sql (2.07ms)10752026/09/23 13:01:42 OK 2_object_stats_trigger.sql (742.92µs)10762026/09/23 13:01:42 OK 3_commit_push.sql (619.83µs)10772026/09/23 13:01:42 goose: up to current file version: 310782026-09-23 13:01:42.815 UTC [51641] ERROR: relation "goose_db_version" does not exist at character 3610792026-09-23 13:01:42.815 UTC [51641] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10802026/09/23 13:01:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10812026-09-23 13:01:42.885 UTC [51642] ERROR: relation "goose_db_version" does not exist at character 3610822026-09-23 13:01:42.885 UTC [51642] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10832026/09/23 13:01:42 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ODUzMWU5NzgtZjVjMi00ZTZkLTg4ZTItNTEyMWViNmExMDkzLjk1MDMwNDU4LWJkOTMtNDg4Ny05NjhjLTU4Nzg3MjllMWM3ZHgxNzkwMTY4NTAxNzAxMzYwMDAw parts=1010842026/09/23 13:01:42 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10852026/09/23 13:01:42 INFO Completed upload id=110862026/09/23 13:01:42 INFO Received uploads request method=POST path=/api/pending_closures10872026/09/23 13:01:42 INFO Received uploads request method=POST path=/api/pending_closures10882026/09/23 13:01:42 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10892026/09/23 13:01:42 WARN Found objects in DB but missing from S3, will re-upload count=11090--- PASS: TestService_verifyS3Integrity (3.40s)1091=== CONT TestService_readinessHandler10922026/09/23 13:01:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10932026/09/23 13:01:42 OK 20241026095416_initial_model.sql (121.52ms)10942026/09/23 13:01:42 OK 20251210153512_drop_unused_gin_index.sql (7.01ms)10952026/09/23 13:01:43 OK 20251218171726_add_pins.sql (7.2ms)1096--- PASS: TestMetricsInventory (1.82s)1097=== CONT TestPush_SignsNarinfosOfItsPendingObjects10982026/09/23 13:01:43 OK 20241026095416_initial_model.sql (54.93ms)10992026/09/23 13:01:43 OK 20251210153512_drop_unused_gin_index.sql (2.72ms)11002026/09/23 13:01:43 OK 20251218171726_add_pins.sql (2.86ms)11012026/09/23 13:01:43 OK 20260628120000_add_object_size_and_stats.sql (8.27ms)11022026-09-23 13:01:43.014 UTC [51646] ERROR: relation "goose_db_version" does not exist at character 3611032026-09-23 13:01:43.014 UTC [51646] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11042026/09/23 13:01:43 OK 20260905000000_add_claims.sql (3.05ms)11052026/09/23 13:01:43 OK 20260628120000_add_object_size_and_stats.sql (4.4ms)11062026/09/23 13:01:43 OK 20260920000000_drop_claims.sql (1.63ms)11072026/09/23 13:01:43 OK 20260905000000_add_claims.sql (2.46ms)11082026/09/23 13:01:43 OK 20260923120000_add_pushes.sql (1.58ms)11092026/09/23 13:01:43 goose: successfully migrated database to version: 2026092312000011102026/09/23 13:01:43 OK 20260920000000_drop_claims.sql (1.11ms)11112026/09/23 13:01:43 OK 1_commit_pending_closure.sql (1.75ms)11122026/09/23 13:01:43 OK 2_object_stats_trigger.sql (628.21µs)11132026/09/23 13:01:43 OK 20260923120000_add_pushes.sql (1.93ms)11142026/09/23 13:01:43 goose: successfully migrated database to version: 2026092312000011152026/09/23 13:01:43 OK 3_commit_push.sql (585.67µs)11162026/09/23 13:01:43 goose: up to current file version: 311172026/09/23 13:01:43 OK 1_commit_pending_closure.sql (1.47ms)11182026/09/23 13:01:43 OK 2_object_stats_trigger.sql (659µs)11192026/09/23 13:01:43 OK 3_commit_push.sql (418.17µs)11202026/09/23 13:01:43 goose: up to current file version: 311212026/09/23 13:01:43 OK 20241026095416_initial_model.sql (42.09ms)11222026/09/23 13:01:43 OK 20251210153512_drop_unused_gin_index.sql (762.5µs)11232026/09/23 13:01:43 OK 20251218171726_add_pins.sql (10.67ms)11242026/09/23 13:01:43 OK 20260628120000_add_object_size_and_stats.sql (12.1ms)11252026/09/23 13:01:43 OK 20260905000000_add_claims.sql (31.33ms)11262026/09/23 13:01:43 OK 20260920000000_drop_claims.sql (15.91ms)11272026/09/23 13:01:43 OK 20260923120000_add_pushes.sql (5.01ms)11282026/09/23 13:01:43 goose: successfully migrated database to version: 2026092312000011292026/09/23 13:01:43 OK 1_commit_pending_closure.sql (1.48ms)11302026/09/23 13:01:43 OK 2_object_stats_trigger.sql (316.13µs)11312026/09/23 13:01:43 OK 3_commit_push.sql (262.04µs)11322026/09/23 13:01:43 goose: up to current file version: 311332026-09-23 13:01:43.310 UTC [51651] ERROR: relation "goose_db_version" does not exist at character 3611342026-09-23 13:01:43.310 UTC [51651] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1135=== NAME TestNARDeduplicationMetadataUploadBug1136 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-51385-2205677552/TestNARDeduplicationMetadataUploadBug274621891/001/store/zmqk5ahg8n3y93xxgxb4ic3jv6npibyn-file1.txt1137--- PASS: TestService_Rustfstest (1.83s)1138=== CONT TestService_healthCheckHandler11392026-09-23 13:01:43.388 UTC [51655] ERROR: relation "goose_db_version" does not exist at character 3611402026-09-23 13:01:43.388 UTC [51655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11412026/09/23 13:01:43 INFO Received uploads request method=POST path=/api/pending_closures11422026/09/23 13:01:43 OK 20241026095416_initial_model.sql (61.17ms)11432026/09/23 13:01:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11442026/09/23 13:01:43 INFO Uploading zmqk5ahg8n3y93xxgxb4ic3jv6npibyn-file1.txt (160B)11452026/09/23 13:01:43 OK 20251210153512_drop_unused_gin_index.sql (6.91ms)11462026/09/23 13:01:43 WARN Failed to register uploaded object key=zmqk5ahg8n3y93xxgxb4ic3jv6npibyn.ls error="server returned 404: 404 page not found\n"11472026/09/23 13:01:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11482026/09/23 13:01:43 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11492026/09/23 13:01:43 INFO Signed narinfos id=1 count=111502026/09/23 13:01:43 INFO Uploading 1 narinfos11512026/09/23 13:01:43 OK 20251218171726_add_pins.sql (7.76ms)11522026/09/23 13:01:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11532026/09/23 13:01:43 WARN Failed to register uploaded object key=zmqk5ahg8n3y93xxgxb4ic3jv6npibyn.narinfo error="server returned 404: 404 page not found\n"11542026-09-23 13:01:43.438 UTC [51659] ERROR: relation "goose_db_version" does not exist at character 3611552026-09-23 13:01:43.438 UTC [51659] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11562026/09/23 13:01:43 OK 20260628120000_add_object_size_and_stats.sql (26.12ms)11572026/09/23 13:01:43 INFO Completed upload id=111582026/09/23 13:01:43 INFO Upload complete. (100ms)1159=== NAME TestNARDeduplicationMetadataUploadBug1160 metadata_upload_test.go:54: Retrieved narinfo from S3:1161 StorePath: /nix/var/nix/builds/nix-51385-2205677552/TestNARDeduplicationMetadataUploadBug274621891/001/store/zmqk5ahg8n3y93xxgxb4ic3jv6npibyn-file1.txt1162 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1163 Compression: zstd1164 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1165 NarSize: 1601166 References: 1167 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1168 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1169 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1170 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}11712026/09/23 13:01:43 OK 20260905000000_add_claims.sql (29.73ms)11722026/09/23 13:01:43 OK 20260920000000_drop_claims.sql (15.3ms)11732026/09/23 13:01:43 OK 20241026095416_initial_model.sql (91.2ms)11742026/09/23 13:01:43 OK 20260923120000_add_pushes.sql (5.66ms)11752026/09/23 13:01:43 goose: successfully migrated database to version: 2026092312000011762026/09/23 13:01:43 OK 1_commit_pending_closure.sql (813.5µs)11772026/09/23 13:01:43 OK 2_object_stats_trigger.sql (212.96µs)11782026/09/23 13:01:43 OK 3_commit_push.sql (187.21µs)11792026/09/23 13:01:43 goose: up to current file version: 311802026/09/23 13:01:43 OK 20251210153512_drop_unused_gin_index.sql (13.53ms)11812026/09/23 13:01:43 OK 20251218171726_add_pins.sql (18.98ms)1182 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-51385-2205677552/TestNARDeduplicationMetadataUploadBug274621891/001/store/vhial05552j8l0m876f02k3w1mnjbl4p-file2.txt11832026/09/23 13:01:43 OK 20260628120000_add_object_size_and_stats.sql (6.7ms)11842026/09/23 13:01:43 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01185=== NAME TestClientIntegration1186 client_integration_test.go:323: Objects in database after GC:1187 client_integration_test.go:323: Successfully deleted all objects with GC --force11882026/09/23 13:01:43 INFO Received uploads request method=POST path=/api/pending_closures11892026/09/23 13:01:43 OK 20260905000000_add_claims.sql (23.81ms)11902026/09/23 13:01:43 OK 20241026095416_initial_model.sql (69.72ms)1191--- PASS: TestClientIntegration (4.03s)1192=== CONT TestGracefulShutdownDrainsInflight11932026/09/23 13:01:43 INFO Starting HTTP server address=127.0.0.1:5729111942026/09/23 13:01:43 INFO Shutdown signal received, draining in-flight requests timeout=10s11952026/09/23 13:01:43 OK 20260920000000_drop_claims.sql (6.05ms)11962026/09/23 13:01:43 OK 20251210153512_drop_unused_gin_index.sql (11.26ms)11972026/09/23 13:01:43 OK 20260923120000_add_pushes.sql (12.66ms)11982026/09/23 13:01:43 goose: successfully migrated database to version: 2026092312000011992026/09/23 13:01:43 OK 1_commit_pending_closure.sql (796.71µs)12002026/09/23 13:01:43 OK 2_object_stats_trigger.sql (216.5µs)12012026/09/23 13:01:43 OK 3_commit_push.sql (176.88µs)12022026/09/23 13:01:43 goose: up to current file version: 312032026/09/23 13:01:43 OK 20251218171726_add_pins.sql (22.57ms)12042026/09/23 13:01:43 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst12052026/09/23 13:01:43 INFO Received uploads request method=POST path=/api/pending_closures1206--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.98s)1207=== CONT TestPush_RejectsBadRequests12082026/09/23 13:01:43 INFO Received uploads request method=POST path=/api/pending_closures12092026/09/23 13:01:43 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12102026/09/23 13:01:43 OK 20260628120000_add_object_size_and_stats.sql (19.34ms)12112026/09/23 13:01:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12122026/09/23 13:01:43 INFO Signed narinfos id=2 count=112132026/09/23 13:01:43 INFO Uploading 1 narinfos12142026/09/23 13:01:43 WARN Failed to register uploaded object key=vhial05552j8l0m876f02k3w1mnjbl4p.ls error="server returned 404: 404 page not found\n"1215--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1216=== CONT TestGCTaskStore_Fail1217--- PASS: TestGCTaskStore_Fail (0.00s)1218=== CONT TestPush_CommitFailsWhenSkippedKeyWasCollected12192026/09/23 13:01:43 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12202026/09/23 13:01:43 WARN Failed to register uploaded object key=vhial05552j8l0m876f02k3w1mnjbl4p.narinfo error="server returned 404: 404 page not found\n"12212026/09/23 13:01:43 INFO Completed upload id=212222026/09/23 13:01:43 INFO Upload complete. (70ms)1223=== NAME TestNARDeduplicationMetadataUploadBug1224 metadata_upload_test.go:76: Retrieved narinfo from S3:1225 StorePath: /nix/var/nix/builds/nix-51385-2205677552/TestNARDeduplicationMetadataUploadBug274621891/001/store/vhial05552j8l0m876f02k3w1mnjbl4p-file2.txt1226 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1227 Compression: zstd1228 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1229 NarSize: 1601230 References: 1231 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1232 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1233 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1234 {"version":1,"root":{"type":"regular","size":44}}12352026/09/23 13:01:43 OK 20260905000000_add_claims.sql (51.42ms)12362026/09/23 13:01:43 OK 20260920000000_drop_claims.sql (31.78ms)12372026/09/23 13:01:43 OK 20260923120000_add_pushes.sql (5.03ms)12382026/09/23 13:01:43 goose: successfully migrated database to version: 2026092312000012392026/09/23 13:01:43 OK 1_commit_pending_closure.sql (823µs)12402026/09/23 13:01:43 OK 2_object_stats_trigger.sql (208.58µs)12412026/09/23 13:01:43 OK 3_commit_push.sql (193.96µs)12422026/09/23 13:01:43 goose: up to current file version: 31243--- PASS: TestNARDeduplicationMetadataUploadBug (2.37s)1244=== CONT TestGCTaskStore_PhaseUpdates1245--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1246=== CONT TestClientFallsBackToClosures12472026/09/23 13:01:43 INFO Received uploads request method=POST path=/api/pending_closures12482026-09-23 13:01:43.849 UTC [51672] ERROR: relation "goose_db_version" does not exist at character 3612492026-09-23 13:01:43.849 UTC [51672] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12502026/09/23 13:01:43 INFO Received uploads request method=POST path=/api/pending_closures12512026-09-23 13:01:43.979 UTC [51674] ERROR: relation "goose_db_version" does not exist at character 3612522026-09-23 13:01:43.979 UTC [51674] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12532026/09/23 13:01:44 OK 20241026095416_initial_model.sql (159.09ms)12542026/09/23 13:01:44 OK 20251210153512_drop_unused_gin_index.sql (11.89ms)12552026/09/23 13:01:44 OK 20251218171726_add_pins.sql (28.56ms)12562026/09/23 13:01:44 OK 20260628120000_add_object_size_and_stats.sql (42.27ms)12572026/09/23 13:01:44 OK 20260905000000_add_claims.sql (58.82ms)12582026/09/23 13:01:44 OK 20241026095416_initial_model.sql (160.17ms)12592026/09/23 13:01:44 OK 20260920000000_drop_claims.sql (34.93ms)12602026/09/23 13:01:44 OK 20251210153512_drop_unused_gin_index.sql (9.5ms)12612026/09/23 13:01:44 INFO Received uploads request method=POST path=/api/pending_closures12622026/09/23 13:01:44 OK 20260923120000_add_pushes.sql (20.72ms)12632026/09/23 13:01:44 goose: successfully migrated database to version: 2026092312000012642026/09/23 13:01:44 OK 1_commit_pending_closure.sql (3.37ms)12652026/09/23 13:01:44 OK 2_object_stats_trigger.sql (816.75µs)12662026/09/23 13:01:44 OK 3_commit_push.sql (656.96µs)12672026/09/23 13:01:44 goose: up to current file version: 312682026/09/23 13:01:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12692026/09/23 13:01:44 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ODUzMWU5NzgtZjVjMi00ZTZkLTg4ZTItNTEyMWViNmExMDkzLjVjNmVkZWMzLTVmZDItNDg2MS1iOTY1LTFmMDg3MDAyYWYwNXgxNzkwMTY4NTA0MDMwNTU5MDAw12702026/09/23 13:01:44 OK 20251218171726_add_pins.sql (30.56ms)12712026/09/23 13:01:44 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ODUzMWU5NzgtZjVjMi00ZTZkLTg4ZTItNTEyMWViNmExMDkzLjVjNmVkZWMzLTVmZDItNDg2MS1iOTY1LTFmMDg3MDAyYWYwNXgxNzkwMTY4NTA0MDMwNTU5MDAw parts=11272--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.06s)1273=== CONT TestGCTaskStore_CompletedAllowsNewTask1274--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1275=== CONT TestPush_OverlappingRootsStoreOneRowPerKey12762026/09/23 13:01:44 OK 20260628120000_add_object_size_and_stats.sql (41.22ms)12772026/09/23 13:01:44 INFO Received uploads request method=POST path=/api/pending_closures12782026/09/23 13:01:44 OK 20260905000000_add_claims.sql (72.51ms)12792026/09/23 13:01:44 OK 20260920000000_drop_claims.sql (34.04ms)12802026/09/23 13:01:44 OK 20260923120000_add_pushes.sql (18.05ms)12812026/09/23 13:01:44 goose: successfully migrated database to version: 2026092312000012822026/09/23 13:01:44 OK 1_commit_pending_closure.sql (1.88ms)12832026/09/23 13:01:44 OK 2_object_stats_trigger.sql (417.5µs)12842026/09/23 13:01:44 OK 3_commit_push.sql (337.5µs)12852026/09/23 13:01:44 goose: up to current file version: 312862026/09/23 13:01:44 WARN readiness check failed error="closed pool"1287--- PASS: TestService_readinessHandler (1.57s)1288=== CONT TestGCBugBareHashReferences12892026/09/23 13:01:44 INFO Received push request method=POST path=/api/pushes12902026/09/23 13:01:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12912026/09/23 13:01:44 INFO Signed narinfos id=1 count=11292--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (1.86s)1293=== CONT TestGCTaskStore_GetReturnsLatest1294--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1295=== CONT TestReadRedirectUsesPublicS3URL12962026-09-23 13:01:44.923 UTC [51681] ERROR: relation "goose_db_version" does not exist at character 3612972026-09-23 13:01:44.923 UTC [51681] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12982026-09-23 13:01:45.029 UTC [51682] ERROR: relation "goose_db_version" does not exist at character 3612992026-09-23 13:01:45.029 UTC [51682] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13002026-09-23 13:01:45.029 UTC [51683] ERROR: relation "goose_db_version" does not exist at character 3613012026-09-23 13:01:45.029 UTC [51683] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13022026/09/23 13:01:45 OK 20241026095416_initial_model.sql (115.85ms)13032026/09/23 13:01:45 OK 20251210153512_drop_unused_gin_index.sql (5.38ms)13042026/09/23 13:01:45 OK 20251218171726_add_pins.sql (8.09ms)13052026-09-23 13:01:45.125 UTC [51684] ERROR: relation "goose_db_version" does not exist at character 3613062026-09-23 13:01:45.125 UTC [51684] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13072026/09/23 13:01:45 OK 20241026095416_initial_model.sql (37.75ms)13082026/09/23 13:01:45 OK 20251210153512_drop_unused_gin_index.sql (610.38µs)13092026/09/23 13:01:45 OK 20260628120000_add_object_size_and_stats.sql (26.2ms)13102026/09/23 13:01:45 OK 20251218171726_add_pins.sql (100.65ms)13112026/09/23 13:01:45 OK 20260905000000_add_claims.sql (83.71ms)13122026/09/23 13:01:45 OK 20241026095416_initial_model.sql (144.18ms)13132026/09/23 13:01:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13142026/09/23 13:01:45 OK 20260920000000_drop_claims.sql (8.75ms)13152026/09/23 13:01:45 OK 20251210153512_drop_unused_gin_index.sql (8.58ms)13162026/09/23 13:01:45 OK 20260923120000_add_pushes.sql (1.96ms)13172026/09/23 13:01:45 goose: successfully migrated database to version: 2026092312000013182026/09/23 13:01:45 OK 20260628120000_add_object_size_and_stats.sql (11.47ms)13192026/09/23 13:01:45 OK 20251218171726_add_pins.sql (3.26ms)13202026/09/23 13:01:45 OK 1_commit_pending_closure.sql (2.4ms)13212026/09/23 13:01:45 OK 2_object_stats_trigger.sql (475.88µs)13222026/09/23 13:01:45 OK 3_commit_push.sql (468.75µs)13232026/09/23 13:01:45 goose: up to current file version: 313242026/09/23 13:01:45 OK 20260905000000_add_claims.sql (3.37ms)13252026/09/23 13:01:45 OK 20260628120000_add_object_size_and_stats.sql (43.59ms)13262026/09/23 13:01:45 OK 20260920000000_drop_claims.sql (41.71ms)13272026/09/23 13:01:45 OK 20260923120000_add_pushes.sql (9.73ms)13282026/09/23 13:01:45 goose: successfully migrated database to version: 2026092312000013292026/09/23 13:01:45 OK 1_commit_pending_closure.sql (6.27ms)13302026/09/23 13:01:45 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ODUzMWU5NzgtZjVjMi00ZTZkLTg4ZTItNTEyMWViNmExMDkzLmZlZWM0OGNiLTU3MDktNDRkZS04OTEwLTY2YWNmZDkyMzQ0ZHgxNzkwMTY4NTAzNzg4MTQ4MDAw parts=1213312026/09/23 13:01:45 OK 2_object_stats_trigger.sql (574.67µs)13322026/09/23 13:01:45 INFO Received uploads request method=POST path=/api/pending_closures13332026/09/23 13:01:45 OK 3_commit_push.sql (385.79µs)13342026/09/23 13:01:45 goose: up to current file version: 31335--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.20s)1336=== CONT TestLeadEndsOnShutdown13372026/09/23 13:01:45 OK 20260905000000_add_claims.sql (55.49ms)13382026/09/23 13:01:45 OK 20241026095416_initial_model.sql (113.03ms)13392026/09/23 13:01:45 OK 20260920000000_drop_claims.sql (10.65ms)13402026/09/23 13:01:45 OK 20251210153512_drop_unused_gin_index.sql (7.81ms)13412026/09/23 13:01:45 OK 20260923120000_add_pushes.sql (8.84ms)13422026/09/23 13:01:45 goose: successfully migrated database to version: 2026092312000013432026/09/23 13:01:45 OK 1_commit_pending_closure.sql (1.42ms)13442026/09/23 13:01:45 OK 2_object_stats_trigger.sql (304.13µs)13452026/09/23 13:01:45 OK 3_commit_push.sql (280.04µs)13462026/09/23 13:01:45 goose: up to current file version: 313472026/09/23 13:01:45 OK 20251218171726_add_pins.sql (15.7ms)13482026/09/23 13:01:45 OK 20260628120000_add_object_size_and_stats.sql (22.04ms)13492026/09/23 13:01:45 OK 20260905000000_add_claims.sql (42.18ms)13502026/09/23 13:01:45 OK 20260920000000_drop_claims.sql (16.51ms)13512026/09/23 13:01:45 OK 20260923120000_add_pushes.sql (1.54ms)13522026/09/23 13:01:45 goose: successfully migrated database to version: 2026092312000013532026/09/23 13:01:45 OK 1_commit_pending_closure.sql (1.74ms)13542026/09/23 13:01:45 OK 2_object_stats_trigger.sql (396.54µs)13552026/09/23 13:01:45 OK 3_commit_push.sql (356.46µs)13562026/09/23 13:01:45 goose: up to current file version: 31357--- PASS: TestService_healthCheckHandler (2.13s)1358=== CONT TestGCTaskStore_GetEmpty1359--- PASS: TestGCTaskStore_GetEmpty (0.00s)1360=== CONT TestReadProxyRangeRequest1361=== RUN TestPush_RejectsBadRequests/no_objects1362=== PAUSE TestPush_RejectsBadRequests/no_objects1363=== RUN TestPush_RejectsBadRequests/bad_root1364=== PAUSE TestPush_RejectsBadRequests/bad_root1365=== RUN TestPush_RejectsBadRequests/root_not_in_objects1366=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1367=== RUN TestPush_RejectsBadRequests/no_roots1368=== PAUSE TestPush_RejectsBadRequests/no_roots1369=== CONT TestLeadElectsOneAndHandsOver13702026/09/23 13:01:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13712026/09/23 13:01:45 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ODUzMWU5NzgtZjVjMi00ZTZkLTg4ZTItNTEyMWViNmExMDkzLjRkZGYyZGI2LTAyYzEtNGE5Yi1iZTIxLTMyZmRlMzBlOThjNngxNzkwMTY4NTA0MjY5NDk4MDAw parts=121372--- PASS: TestRedundantMultipartUpload (3.55s)1373=== CONT TestGCTaskStore_ConflictDifferentParams1374--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1375=== CONT TestResolveDBConnectionString1376=== RUN TestResolveDBConnectionString/flag_wins1377=== PAUSE TestResolveDBConnectionString/flag_wins1378=== RUN TestResolveDBConnectionString/file_when_flag_empty1379=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1380=== RUN TestResolveDBConnectionString/missing_file_is_an_error1381=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1382=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1383=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1384=== RUN TestResolveDBConnectionString/nothing_configured1385=== PAUSE TestResolveDBConnectionString/nothing_configured1386=== CONT TestReadRedirectKeepsNarinfoProxied13872026/09/23 13:01:46 INFO Received push request method=POST path=/api/pushes13882026/09/23 13:01:46 INFO Received complete push request method=POST path=/api/pushes/1/complete13892026/09/23 13:01:46 INFO Received push request method=POST path=/api/pushes13902026/09/23 13:01:46 INFO Received complete push request method=POST path=/api/pushes/2/complete13912026-09-23 13:01:46.245 UTC [51682] ERROR: Push object missing: aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo13922026-09-23 13:01:46.245 UTC [51682] CONTEXT: PL/pgSQL function commit_push(bigint) line 37 at RAISE13932026-09-23 13:01:46.245 UTC [51682] STATEMENT: -- name: CommitPush :exec1394 SELECT commit_push($1::bigint)1395 1396--- PASS: TestPush_CommitFailsWhenSkippedKeyWasCollected (2.62s)1397=== CONT TestGCTaskStore_DeduplicateSameParams1398--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1399=== CONT TestReadProxyNarStreaming14002026-09-23 13:01:46.338 UTC [51709] ERROR: relation "goose_db_version" does not exist at character 3614012026-09-23 13:01:46.338 UTC [51709] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14022026-09-23 13:01:46.495 UTC [51711] ERROR: relation "goose_db_version" does not exist at character 3614032026-09-23 13:01:46.495 UTC [51711] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14042026/09/23 13:01:46 OK 20241026095416_initial_model.sql (153ms)14052026/09/23 13:01:46 OK 20251210153512_drop_unused_gin_index.sql (13.76ms)14062026/09/23 13:01:46 OK 20251218171726_add_pins.sql (19.05ms)14072026/09/23 13:01:46 OK 20260628120000_add_object_size_and_stats.sql (23.38ms)14082026/09/23 13:01:46 OK 20241026095416_initial_model.sql (135.43ms)14092026/09/23 13:01:46 OK 20251210153512_drop_unused_gin_index.sql (6.71ms)14102026/09/23 13:01:46 OK 20260905000000_add_claims.sql (37.48ms)14112026-09-23 13:01:46.697 UTC [51737] ERROR: relation "goose_db_version" does not exist at character 3614122026-09-23 13:01:46.697 UTC [51737] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14132026/09/23 13:01:46 OK 20251218171726_add_pins.sql (10.02ms)14142026/09/23 13:01:46 OK 20260920000000_drop_claims.sql (11.21ms)14152026/09/23 13:01:46 OK 20260923120000_add_pushes.sql (10.71ms)14162026/09/23 13:01:46 goose: successfully migrated database to version: 2026092312000014172026/09/23 13:01:46 OK 1_commit_pending_closure.sql (868.92µs)14182026/09/23 13:01:46 OK 2_object_stats_trigger.sql (242.67µs)14192026/09/23 13:01:46 OK 3_commit_push.sql (168.54µs)14202026/09/23 13:01:46 goose: up to current file version: 314212026/09/23 13:01:46 OK 20260628120000_add_object_size_and_stats.sql (30.75ms)14222026/09/23 13:01:46 OK 20260905000000_add_claims.sql (67.62ms)14232026/09/23 13:01:46 OK 20260920000000_drop_claims.sql (29.84ms)14242026/09/23 13:01:46 OK 20260923120000_add_pushes.sql (14.67ms)14252026/09/23 13:01:46 goose: successfully migrated database to version: 2026092312000014262026/09/23 13:01:46 OK 1_commit_pending_closure.sql (866.71µs)14272026/09/23 13:01:46 OK 2_object_stats_trigger.sql (245.25µs)14282026/09/23 13:01:46 OK 3_commit_push.sql (206.04µs)14292026/09/23 13:01:46 goose: up to current file version: 314302026/09/23 13:01:46 INFO Received uploads request method=POST path=/api/pending_closures14312026/09/23 13:01:46 INFO Received uploads request method=POST path=/api/pending_closures14322026/09/23 13:01:46 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14332026/09/23 13:01:46 INFO Uploading 3nhdqsq1ngflix4namdbnngs52w9gl0j-shared-dep (136B)14342026/09/23 13:01:46 INFO Uploading nawfq4f7g8hg99mfahz5xv7hpnxn8512-b (248B)14352026/09/23 13:01:46 OK 20241026095416_initial_model.sql (173.44ms)14362026/09/23 13:01:46 OK 20251210153512_drop_unused_gin_index.sql (12.11ms)14372026/09/23 13:01:46 WARN Failed to register uploaded object key=nawfq4f7g8hg99mfahz5xv7hpnxn8512.ls error="server returned 404: 404 page not found\n"14382026/09/23 13:01:46 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14392026/09/23 13:01:46 WARN Failed to register uploaded object key=3nhdqsq1ngflix4namdbnngs52w9gl0j.ls error="server returned 404: 404 page not found\n"14402026/09/23 13:01:46 WARN Failed to register uploaded object key=nar/07jpvmjccmqnqq9mag6bg552lq17ma3jnm405hx2gv5b92kp0cn6.nar.zst error="server returned 404: 404 page not found\n"14412026/09/23 13:01:46 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14422026/09/23 13:01:46 WARN Failed to register uploaded object key=g8r4gk5qp181dbb40ii7nf4hf6afqijz.ls error="server returned 404: 404 page not found\n"14432026/09/23 13:01:46 INFO Signed narinfos id=1 count=214442026/09/23 13:01:46 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14452026/09/23 13:01:46 INFO Signed narinfos id=2 count=214462026/09/23 13:01:46 INFO Uploading 4 narinfos14472026/09/23 13:01:46 OK 20251218171726_add_pins.sql (33.21ms)14482026/09/23 13:01:46 WARN Failed to register uploaded object key=3nhdqsq1ngflix4namdbnngs52w9gl0j.narinfo error="server returned 404: 404 page not found\n"14492026/09/23 13:01:46 WARN Failed to register uploaded object key=nawfq4f7g8hg99mfahz5xv7hpnxn8512.narinfo error="server returned 404: 404 page not found\n"14502026/09/23 13:01:46 WARN Failed to register uploaded object key=g8r4gk5qp181dbb40ii7nf4hf6afqijz.narinfo error="server returned 404: 404 page not found\n"14512026/09/23 13:01:47 INFO Received push request method=POST path=/api/pushes14522026/09/23 13:01:47 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14532026/09/23 13:01:47 WARN Failed to register uploaded object key=3nhdqsq1ngflix4namdbnngs52w9gl0j.narinfo error="server returned 404: 404 page not found\n"14542026/09/23 13:01:47 OK 20260628120000_add_object_size_and_stats.sql (55.89ms)14552026/09/23 13:01:47 INFO Completed upload id=114562026/09/23 13:01:47 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14572026/09/23 13:01:47 INFO Completed upload id=214582026/09/23 13:01:47 INFO Upload complete. (254ms)1459=== NAME TestClientFallsBackToClosures1460 client_pushes_test.go:112: Retrieved narinfo from S3:1461 StorePath: /nix/var/nix/builds/nix-51385-2205677552/TestClientFallsBackToClosures3463716387/001/store/3nhdqsq1ngflix4namdbnngs52w9gl0j-shared-dep1462 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1463 Compression: zstd1464 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821465 NarSize: 1361466 References: 1467 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1468 client_pushes_test.go:112: Retrieved narinfo from S3:1469 StorePath: /nix/var/nix/builds/nix-51385-2205677552/TestClientFallsBackToClosures3463716387/001/store/g8r4gk5qp181dbb40ii7nf4hf6afqijz-a1470 URL: nar/07jpvmjccmqnqq9mag6bg552lq17ma3jnm405hx2gv5b92kp0cn6.nar.zst1471 Compression: zstd1472 NarHash: sha256:07jpvmjccmqnqq9mag6bg552lq17ma3jnm405hx2gv5b92kp0cn61473 NarSize: 2481474 References: /nix/var/nix/builds/nix-51385-2205677552/TestClientFallsBackToClosures3463716387/001/store/3nhdqsq1ngflix4namdbnngs52w9gl0j-shared-dep1475 CA: text:sha256:189scdkhl3844bahqxi6ng2bifjfhc6gxyca9pckngqmb6qhqjzz1476 client_pushes_test.go:112: Retrieved narinfo from S3:1477 StorePath: /nix/var/nix/builds/nix-51385-2205677552/TestClientFallsBackToClosures3463716387/001/store/nawfq4f7g8hg99mfahz5xv7hpnxn8512-b1478 URL: nar/07jpvmjccmqnqq9mag6bg552lq17ma3jnm405hx2gv5b92kp0cn6.nar.zst1479 Compression: zstd1480 NarHash: sha256:07jpvmjccmqnqq9mag6bg552lq17ma3jnm405hx2gv5b92kp0cn61481 NarSize: 2481482 References: /nix/var/nix/builds/nix-51385-2205677552/TestClientFallsBackToClosures3463716387/001/store/3nhdqsq1ngflix4namdbnngs52w9gl0j-shared-dep1483 CA: text:sha256:189scdkhl3844bahqxi6ng2bifjfhc6gxyca9pckngqmb6qhqjzz1484--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (2.84s)1485=== CONT TestReadProxyNarinfoAlreadyDecompressed14862026/09/23 13:01:47 OK 20260905000000_add_claims.sql (97.7ms)14872026/09/23 13:01:47 OK 20260920000000_drop_claims.sql (61.68ms)1488--- PASS: TestClientFallsBackToClosures (3.50s)1489=== CONT TestGCTaskStore_StartNew1490--- PASS: TestGCTaskStore_StartNew (0.00s)1491=== CONT TestReadRedirectNar14922026/09/23 13:01:47 OK 20260923120000_add_pushes.sql (15.5ms)14932026/09/23 13:01:47 goose: successfully migrated database to version: 2026092312000014942026/09/23 13:01:47 OK 1_commit_pending_closure.sql (2.05ms)14952026/09/23 13:01:47 OK 2_object_stats_trigger.sql (585.54µs)14962026/09/23 13:01:47 OK 3_commit_push.sql (375.08µs)14972026/09/23 13:01:47 goose: up to current file version: 314982026/09/23 13:01:47 WARN Rate limiter enabled after throttle name=s3-test rate=514992026/09/23 13:01:47 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1500=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1501 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101502 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001503--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.50s)1504=== CONT TestReadProxyNarinfo15052026-09-23 13:01:47.487 UTC [51753] ERROR: relation "goose_db_version" does not exist at character 3615062026-09-23 13:01:47.487 UTC [51753] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1507--- PASS: TestGCBugBareHashReferences (3.16s)1508=== CONT TestReadProxyHead1509--- PASS: TestReadRedirectUsesPublicS3URL (2.82s)1510=== CONT TestIsValidCachePath1511=== RUN TestIsValidCachePath/narinfo1512=== PAUSE TestIsValidCachePath/narinfo1513=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1514=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1515=== RUN TestIsValidCachePath/nar_zst1516=== PAUSE TestIsValidCachePath/nar_zst1517=== RUN TestIsValidCachePath/nar_xz1518=== PAUSE TestIsValidCachePath/nar_xz1519=== RUN TestIsValidCachePath/nar_bz21520=== PAUSE TestIsValidCachePath/nar_bz21521=== RUN TestIsValidCachePath/nar_uncompressed1522=== PAUSE TestIsValidCachePath/nar_uncompressed1523=== RUN TestIsValidCachePath/ls1524=== PAUSE TestIsValidCachePath/ls1525=== RUN TestIsValidCachePath/log1526=== PAUSE TestIsValidCachePath/log1527=== RUN TestIsValidCachePath/realisation1528=== PAUSE TestIsValidCachePath/realisation1529=== RUN TestIsValidCachePath/nix-cache-info1530=== PAUSE TestIsValidCachePath/nix-cache-info1531=== RUN TestIsValidCachePath/index.html1532=== PAUSE TestIsValidCachePath/index.html1533=== RUN TestIsValidCachePath/traversal_parent1534=== PAUSE TestIsValidCachePath/traversal_parent1535=== RUN TestIsValidCachePath/traversal_in_middle1536=== PAUSE TestIsValidCachePath/traversal_in_middle1537=== RUN TestIsValidCachePath/invalid_char_e1538=== PAUSE TestIsValidCachePath/invalid_char_e1539=== RUN TestIsValidCachePath/invalid_char_u1540=== PAUSE TestIsValidCachePath/invalid_char_u1541=== RUN TestIsValidCachePath/random_path1542=== PAUSE TestIsValidCachePath/random_path1543=== RUN TestIsValidCachePath/empty1544=== PAUSE TestIsValidCachePath/empty1545=== RUN TestIsValidCachePath/leading_slash1546=== PAUSE TestIsValidCachePath/leading_slash1547=== RUN TestIsValidCachePath/wrong_extension1548=== PAUSE TestIsValidCachePath/wrong_extension1549=== RUN TestIsValidCachePath/short_hash1550=== PAUSE TestIsValidCachePath/short_hash1551=== CONT TestReadProxyDisabled15522026-09-23 13:01:47.733 UTC [51754] ERROR: relation "goose_db_version" does not exist at character 3615532026-09-23 13:01:47.733 UTC [51754] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15542026/09/23 13:01:47 OK 20241026095416_initial_model.sql (202.38ms)15552026/09/23 13:01:47 OK 20251210153512_drop_unused_gin_index.sql (3.59ms)15562026/09/23 13:01:47 OK 20251218171726_add_pins.sql (23.03ms)15572026/09/23 13:01:47 OK 20260628120000_add_object_size_and_stats.sql (31.95ms)15582026-09-23 13:01:47.850 UTC [51759] ERROR: relation "goose_db_version" does not exist at character 3615592026-09-23 13:01:47.850 UTC [51759] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15602026/09/23 13:01:47 OK 20260905000000_add_claims.sql (8.82ms)15612026/09/23 13:01:47 OK 20260920000000_drop_claims.sql (3.04ms)15622026/09/23 13:01:47 OK 20241026095416_initial_model.sql (67.85ms)15632026/09/23 13:01:47 OK 20251210153512_drop_unused_gin_index.sql (1.59ms)15642026/09/23 13:01:47 OK 20260923120000_add_pushes.sql (2.12ms)15652026/09/23 13:01:47 goose: successfully migrated database to version: 2026092312000015662026-09-23 13:01:47.856 UTC [51760] ERROR: relation "goose_db_version" does not exist at character 3615672026-09-23 13:01:47.856 UTC [51760] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15682026/09/23 13:01:47 OK 1_commit_pending_closure.sql (2.39ms)15692026/09/23 13:01:47 OK 20251218171726_add_pins.sql (2.63ms)15702026/09/23 13:01:47 OK 2_object_stats_trigger.sql (560.75µs)15712026/09/23 13:01:47 OK 3_commit_push.sql (555.71µs)15722026/09/23 13:01:47 goose: up to current file version: 315732026/09/23 13:01:47 OK 20260628120000_add_object_size_and_stats.sql (26.41ms)15742026-09-23 13:01:47.891 UTC [51761] ERROR: relation "goose_db_version" does not exist at character 3615752026-09-23 13:01:47.891 UTC [51761] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15762026/09/23 13:01:47 OK 20260905000000_add_claims.sql (24.12ms)15772026/09/23 13:01:47 OK 20260920000000_drop_claims.sql (19.8ms)15782026/09/23 13:01:47 OK 20241026095416_initial_model.sql (76.49ms)15792026/09/23 13:01:47 OK 20260923120000_add_pushes.sql (14.62ms)15802026/09/23 13:01:47 goose: successfully migrated database to version: 2026092312000015812026/09/23 13:01:47 OK 1_commit_pending_closure.sql (2.39ms)15822026/09/23 13:01:47 OK 2_object_stats_trigger.sql (494.13µs)15832026/09/23 13:01:47 OK 3_commit_push.sql (349µs)15842026/09/23 13:01:47 goose: up to current file version: 315852026/09/23 13:01:47 OK 20251210153512_drop_unused_gin_index.sql (12.37ms)15862026/09/23 13:01:47 OK 20251218171726_add_pins.sql (17.03ms)15872026/09/23 13:01:48 OK 20241026095416_initial_model.sql (110.78ms)15882026/09/23 13:01:48 OK 20260628120000_add_object_size_and_stats.sql (45.37ms)15892026/09/23 13:01:48 OK 20251210153512_drop_unused_gin_index.sql (2.96ms)15902026/09/23 13:01:48 OK 20260905000000_add_claims.sql (23.52ms)15912026/09/23 13:01:48 OK 20241026095416_initial_model.sql (106.78ms)15922026/09/23 13:01:48 OK 20251218171726_add_pins.sql (21.29ms)15932026/09/23 13:01:48 OK 20251210153512_drop_unused_gin_index.sql (7.77ms)15942026/09/23 13:01:48 OK 20260920000000_drop_claims.sql (16.19ms)15952026/09/23 13:01:48 OK 20260628120000_add_object_size_and_stats.sql (17.86ms)15962026/09/23 13:01:48 OK 20251218171726_add_pins.sql (12.38ms)15972026/09/23 13:01:48 OK 20260923120000_add_pushes.sql (11.31ms)15982026/09/23 13:01:48 goose: successfully migrated database to version: 2026092312000015992026/09/23 13:01:48 OK 1_commit_pending_closure.sql (3.52ms)16002026/09/23 13:01:48 OK 2_object_stats_trigger.sql (408.13µs)16012026/09/23 13:01:48 OK 3_commit_push.sql (331.38µs)16022026/09/23 13:01:48 goose: up to current file version: 316032026/09/23 13:01:48 OK 20260628120000_add_object_size_and_stats.sql (26.59ms)16042026/09/23 13:01:48 INFO lead: acquired remote=192.0.2.1:123416052026/09/23 13:01:48 INFO lead: released remote=192.0.2.1:12341606--- PASS: TestLeadEndsOnShutdown (2.80s)1607=== CONT TestReadProxyRootRedirectsToIndexHTML16082026/09/23 13:01:48 OK 20260905000000_add_claims.sql (50.87ms)16092026/09/23 13:01:48 OK 20260920000000_drop_claims.sql (52.25ms)16102026/09/23 13:01:48 OK 20260905000000_add_claims.sql (79.96ms)16112026/09/23 13:01:48 OK 20260923120000_add_pushes.sql (17.87ms)16122026/09/23 13:01:48 goose: successfully migrated database to version: 2026092312000016132026/09/23 13:01:48 OK 1_commit_pending_closure.sql (2.16ms)16142026/09/23 13:01:48 OK 2_object_stats_trigger.sql (416.13µs)16152026/09/23 13:01:48 OK 3_commit_push.sql (349.38µs)16162026/09/23 13:01:48 goose: up to current file version: 316172026/09/23 13:01:48 OK 20260920000000_drop_claims.sql (20.55ms)16182026/09/23 13:01:48 OK 20260923120000_add_pushes.sql (10.17ms)16192026/09/23 13:01:48 goose: successfully migrated database to version: 2026092312000016202026/09/23 13:01:48 OK 1_commit_pending_closure.sql (1.51ms)16212026/09/23 13:01:48 OK 2_object_stats_trigger.sql (421µs)16222026/09/23 13:01:48 OK 3_commit_push.sql (329.29µs)16232026/09/23 13:01:48 goose: up to current file version: 31624--- PASS: TestReadProxyRangeRequest (2.89s)1625=== CONT TestProxyHeadersOnlyTrustedOnSocket16262026/09/23 13:01:48 INFO lead: acquired remote=192.0.2.1:123416272026/09/23 13:01:48 INFO lead: released remote=192.0.2.1:123416282026/09/23 13:01:48 INFO lead: acquired remote=192.0.2.1:123416292026/09/23 13:01:48 INFO lead: released remote=192.0.2.1:12341630--- PASS: TestLeadElectsOneAndHandsOver (3.07s)1631=== CONT TestReadProxyInvalidPath1632--- PASS: TestReadRedirectKeepsNarinfoProxied (3.06s)1633=== CONT TestReadProxyConditionalGet16342026-09-23 13:01:49.226 UTC [51777] ERROR: relation "goose_db_version" does not exist at character 3616352026-09-23 13:01:49.226 UTC [51777] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16362026-09-23 13:01:49.227 UTC [51778] ERROR: relation "goose_db_version" does not exist at character 3616372026-09-23 13:01:49.227 UTC [51778] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1638--- PASS: TestReadProxyNarStreaming (3.05s)1639=== CONT TestParseSingleRange1640=== RUN TestParseSingleRange/none1641=== PAUSE TestParseSingleRange/none1642=== RUN TestParseSingleRange/unknown_unit1643=== PAUSE TestParseSingleRange/unknown_unit1644=== RUN TestParseSingleRange/multi-range_ignored1645=== PAUSE TestParseSingleRange/multi-range_ignored1646=== RUN TestParseSingleRange/malformed_no_dash1647=== PAUSE TestParseSingleRange/malformed_no_dash1648=== RUN TestParseSingleRange/malformed_both_empty1649=== PAUSE TestParseSingleRange/malformed_both_empty1650=== RUN TestParseSingleRange/malformed_end_before_start1651=== PAUSE TestParseSingleRange/malformed_end_before_start1652=== RUN TestParseSingleRange/closed1653=== PAUSE TestParseSingleRange/closed1654=== RUN TestParseSingleRange/open-ended1655=== PAUSE TestParseSingleRange/open-ended1656=== RUN TestParseSingleRange/end_clamped_to_size1657=== PAUSE TestParseSingleRange/end_clamped_to_size1658=== RUN TestParseSingleRange/suffix1659=== PAUSE TestParseSingleRange/suffix1660=== RUN TestParseSingleRange/suffix_exceeds_size1661=== PAUSE TestParseSingleRange/suffix_exceeds_size1662=== RUN TestParseSingleRange/single_byte1663=== PAUSE TestParseSingleRange/single_byte1664=== RUN TestParseSingleRange/start_past_EOF1665=== PAUSE TestParseSingleRange/start_past_EOF1666=== RUN TestParseSingleRange/start_far_past_EOF1667=== PAUSE TestParseSingleRange/start_far_past_EOF1668=== CONT TestReadProxy40416692026-09-23 13:01:49.317 UTC [51780] ERROR: relation "goose_db_version" does not exist at character 3616702026-09-23 13:01:49.317 UTC [51780] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16712026/09/23 13:01:49 OK 20241026095416_initial_model.sql (67.76ms)16722026/09/23 13:01:49 OK 20241026095416_initial_model.sql (68.07ms)16732026/09/23 13:01:49 OK 20251210153512_drop_unused_gin_index.sql (992.58µs)16742026/09/23 13:01:49 OK 20251210153512_drop_unused_gin_index.sql (867.08µs)16752026/09/23 13:01:49 OK 20251218171726_add_pins.sql (2ms)16762026/09/23 13:01:49 OK 20251218171726_add_pins.sql (1.86ms)16772026-09-23 13:01:49.358 UTC [51782] ERROR: relation "goose_db_version" does not exist at character 3616782026-09-23 13:01:49.358 UTC [51782] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16792026/09/23 13:01:49 OK 20260628120000_add_object_size_and_stats.sql (6.82ms)16802026/09/23 13:01:49 OK 20260628120000_add_object_size_and_stats.sql (6.98ms)16812026-09-23 13:01:49.363 UTC [51784] ERROR: relation "goose_db_version" does not exist at character 3616822026-09-23 13:01:49.363 UTC [51784] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16832026/09/23 13:01:49 OK 20260905000000_add_claims.sql (7.8ms)16842026/09/23 13:01:49 OK 20260905000000_add_claims.sql (8.07ms)16852026/09/23 13:01:49 OK 20241026095416_initial_model.sql (21.3ms)16862026/09/23 13:01:49 OK 20260920000000_drop_claims.sql (2.13ms)16872026/09/23 13:01:49 OK 20260920000000_drop_claims.sql (1.85ms)16882026/09/23 13:01:49 OK 20260923120000_add_pushes.sql (4.76ms)16892026/09/23 13:01:49 goose: successfully migrated database to version: 2026092312000016902026/09/23 13:01:49 OK 20260923120000_add_pushes.sql (4.84ms)16912026/09/23 13:01:49 goose: successfully migrated database to version: 2026092312000016922026/09/23 13:01:49 OK 20251210153512_drop_unused_gin_index.sql (5.44ms)16932026/09/23 13:01:49 OK 1_commit_pending_closure.sql (1.45ms)16942026/09/23 13:01:49 OK 1_commit_pending_closure.sql (1.52ms)16952026/09/23 13:01:49 OK 20251218171726_add_pins.sql (1.43ms)16962026/09/23 13:01:49 OK 2_object_stats_trigger.sql (362.96µs)16972026/09/23 13:01:49 OK 2_object_stats_trigger.sql (427.38µs)16982026/09/23 13:01:49 OK 3_commit_push.sql (357.71µs)16992026/09/23 13:01:49 goose: up to current file version: 317002026/09/23 13:01:49 OK 3_commit_push.sql (273.92µs)17012026/09/23 13:01:49 goose: up to current file version: 317022026/09/23 13:01:49 OK 20260628120000_add_object_size_and_stats.sql (14.5ms)17032026/09/23 13:01:49 OK 20241026095416_initial_model.sql (33.51ms)17042026/09/23 13:01:49 OK 20251210153512_drop_unused_gin_index.sql (6.96ms)17052026/09/23 13:01:49 OK 20260905000000_add_claims.sql (16.92ms)17062026/09/23 13:01:49 OK 20251218171726_add_pins.sql (8.85ms)17072026/09/23 13:01:49 OK 20260920000000_drop_claims.sql (7.05ms)17082026/09/23 13:01:49 OK 20241026095416_initial_model.sql (40.32ms)17092026/09/23 13:01:49 OK 20251210153512_drop_unused_gin_index.sql (1.73ms)17102026/09/23 13:01:49 OK 20260923120000_add_pushes.sql (8.73ms)17112026/09/23 13:01:49 goose: successfully migrated database to version: 2026092312000017122026/09/23 13:01:49 OK 1_commit_pending_closure.sql (1.94ms)17132026/09/23 13:01:49 OK 2_object_stats_trigger.sql (324.04µs)17142026/09/23 13:01:49 OK 3_commit_push.sql (274.79µs)17152026/09/23 13:01:49 goose: up to current file version: 317162026/09/23 13:01:49 OK 20260628120000_add_object_size_and_stats.sql (16.76ms)17172026/09/23 13:01:49 OK 20251218171726_add_pins.sql (15.14ms)17182026/09/23 13:01:49 OK 20260905000000_add_claims.sql (17.29ms)17192026/09/23 13:01:49 OK 20260628120000_add_object_size_and_stats.sql (23.58ms)17202026/09/23 13:01:49 OK 20260920000000_drop_claims.sql (13.73ms)17212026/09/23 13:01:49 OK 20260923120000_add_pushes.sql (7.02ms)17222026/09/23 13:01:49 goose: successfully migrated database to version: 2026092312000017232026/09/23 13:01:49 OK 1_commit_pending_closure.sql (2.02ms)17242026/09/23 13:01:49 OK 2_object_stats_trigger.sql (453µs)17252026/09/23 13:01:49 OK 3_commit_push.sql (420.33µs)17262026/09/23 13:01:49 goose: up to current file version: 317272026/09/23 13:01:49 OK 20260905000000_add_claims.sql (22.91ms)17282026/09/23 13:01:49 OK 20260920000000_drop_claims.sql (21.98ms)17292026/09/23 13:01:49 OK 20260923120000_add_pushes.sql (12.64ms)17302026/09/23 13:01:49 goose: successfully migrated database to version: 2026092312000017312026/09/23 13:01:49 OK 1_commit_pending_closure.sql (1.94ms)17322026/09/23 13:01:49 OK 2_object_stats_trigger.sql (395.75µs)17332026/09/23 13:01:49 OK 3_commit_push.sql (309.92µs)17342026/09/23 13:01:49 goose: up to current file version: 31735--- PASS: TestReadRedirectNar (2.37s)1736=== CONT TestResurrectedObjectNotDeleted1737--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.67s)1738=== CONT TestCreatePin_ReservedPins17392026-09-23 13:01:49.858 UTC [51789] ERROR: relation "goose_db_version" does not exist at character 3617402026-09-23 13:01:49.858 UTC [51789] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17412026/09/23 13:01:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57357/oidc17422026-09-23 13:01:49.921 UTC [51792] ERROR: relation "goose_db_version" does not exist at character 3617432026-09-23 13:01:49.921 UTC [51792] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17442026/09/23 13:01:49 OK 20241026095416_initial_model.sql (73.87ms)17452026/09/23 13:01:49 OK 20251210153512_drop_unused_gin_index.sql (12.55ms)1746--- PASS: TestReadProxyNarinfo (2.59s)1747=== CONT TestOrphanedObjectsGCStressTest17482026/09/23 13:01:49 OK 20251218171726_add_pins.sql (22.47ms)17492026/09/23 13:01:50 OK 20260628120000_add_object_size_and_stats.sql (19.41ms)17502026/09/23 13:01:50 OK 20260905000000_add_claims.sql (36.58ms)17512026/09/23 13:01:50 OK 20241026095416_initial_model.sql (103.87ms)17522026/09/23 13:01:50 OK 20260920000000_drop_claims.sql (6.1ms)17532026/09/23 13:01:50 OK 20251210153512_drop_unused_gin_index.sql (4.81ms)17542026/09/23 13:01:50 OK 20260923120000_add_pushes.sql (4.76ms)17552026/09/23 13:01:50 goose: successfully migrated database to version: 2026092312000017562026/09/23 13:01:50 OK 1_commit_pending_closure.sql (1.14ms)17572026/09/23 13:01:50 OK 2_object_stats_trigger.sql (1.02ms)17582026/09/23 13:01:50 OK 3_commit_push.sql (374.42µs)17592026/09/23 13:01:50 goose: up to current file version: 317602026/09/23 13:01:50 OK 20251218171726_add_pins.sql (12.37ms)17612026/09/23 13:01:50 OK 20260628120000_add_object_size_and_stats.sql (52.82ms)17622026/09/23 13:01:50 OK 20260905000000_add_claims.sql (38.24ms)17632026-09-23 13:01:50.171 UTC [51795] ERROR: relation "goose_db_version" does not exist at character 3617642026-09-23 13:01:50.171 UTC [51795] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17652026/09/23 13:01:50 OK 20260920000000_drop_claims.sql (26.29ms)17662026/09/23 13:01:50 OK 20260923120000_add_pushes.sql (7.56ms)17672026/09/23 13:01:50 goose: successfully migrated database to version: 2026092312000017682026/09/23 13:01:50 OK 1_commit_pending_closure.sql (2.89ms)17692026/09/23 13:01:50 OK 2_object_stats_trigger.sql (526.63µs)17702026/09/23 13:01:50 OK 3_commit_push.sql (459.17µs)17712026/09/23 13:01:50 goose: up to current file version: 31772--- PASS: TestReadProxyHead (2.56s)1773=== CONT TestClientWithDependencies17742026-09-23 13:01:50.248 UTC [51796] ERROR: relation "goose_db_version" does not exist at character 3617752026-09-23 13:01:50.248 UTC [51796] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17762026/09/23 13:01:50 OK 20241026095416_initial_model.sql (121.65ms)17772026/09/23 13:01:50 OK 20251210153512_drop_unused_gin_index.sql (4.86ms)17782026/09/23 13:01:50 OK 20251218171726_add_pins.sql (19.3ms)17792026/09/23 13:01:50 OK 20241026095416_initial_model.sql (72.7ms)17802026/09/23 13:01:50 OK 20260628120000_add_object_size_and_stats.sql (21.64ms)17812026/09/23 13:01:50 OK 20251210153512_drop_unused_gin_index.sql (8.51ms)17822026/09/23 13:01:50 OK 20251218171726_add_pins.sql (16.07ms)17832026/09/23 13:01:50 OK 20260905000000_add_claims.sql (40.55ms)1784--- PASS: TestReadProxyDisabled (2.73s)1785=== CONT TestClientSharedPathCommittedMidPush17862026/09/23 13:01:50 OK 20260628120000_add_object_size_and_stats.sql (27.15ms)17872026/09/23 13:01:50 OK 20260920000000_drop_claims.sql (36.96ms)17882026/09/23 13:01:50 OK 20260923120000_add_pushes.sql (16.05ms)17892026/09/23 13:01:50 goose: successfully migrated database to version: 2026092312000017902026/09/23 13:01:50 OK 20260905000000_add_claims.sql (48.64ms)17912026/09/23 13:01:50 OK 1_commit_pending_closure.sql (2.47ms)17922026/09/23 13:01:50 OK 2_object_stats_trigger.sql (549.83µs)17932026/09/23 13:01:50 OK 3_commit_push.sql (458.75µs)17942026/09/23 13:01:50 goose: up to current file version: 317952026-09-23 13:01:50.480 UTC [51802] ERROR: relation "goose_db_version" does not exist at character 3617962026-09-23 13:01:50.480 UTC [51802] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17972026/09/23 13:01:50 OK 20260920000000_drop_claims.sql (10.28ms)17982026/09/23 13:01:50 OK 20260923120000_add_pushes.sql (4.21ms)17992026/09/23 13:01:50 goose: successfully migrated database to version: 2026092312000018002026/09/23 13:01:50 OK 1_commit_pending_closure.sql (1.96ms)18012026/09/23 13:01:50 OK 2_object_stats_trigger.sql (456.04µs)18022026/09/23 13:01:50 OK 3_commit_push.sql (387.71µs)18032026/09/23 13:01:50 goose: up to current file version: 318042026/09/23 13:01:50 OK 20241026095416_initial_model.sql (154.94ms)18052026/09/23 13:01:50 OK 20251210153512_drop_unused_gin_index.sql (18.6ms)1806--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.61s)1807=== CONT TestClientMultipleUploads18082026/09/23 13:01:50 OK 20251218171726_add_pins.sql (51.91ms)18092026/09/23 13:01:50 OK 20260628120000_add_object_size_and_stats.sql (56.09ms)18102026/09/23 13:01:50 OK 20260905000000_add_claims.sql (57.85ms)18112026/09/23 13:01:50 OK 20260920000000_drop_claims.sql (25.7ms)18122026/09/23 13:01:50 OK 20260923120000_add_pushes.sql (5.32ms)18132026/09/23 13:01:50 goose: successfully migrated database to version: 2026092312000018142026/09/23 13:01:50 OK 1_commit_pending_closure.sql (4.78ms)18152026/09/23 13:01:50 OK 2_object_stats_trigger.sql (919.08µs)18162026/09/23 13:01:50 OK 3_commit_push.sql (578.79µs)18172026/09/23 13:01:50 goose: up to current file version: 318182026/09/23 13:01:50 INFO Starting HTTP server address=/nix/var/nix/builds/nix-51385-2205677552/TestProxyHeadersOnlyTrustedOnSocket2016902277/001/proxy.sock18192026/09/23 13:01:50 INFO Starting HTTP server address=127.0.0.1:5737218202026/09/23 13:01:50 WARN mTLS auth: subject not in bound subjects subject="CN=someone"18212026/09/23 13:01:50 INFO Shutdown signal received, draining in-flight requests timeout=10s1822--- PASS: TestProxyHeadersOnlyTrustedOnSocket (2.62s)1823=== CONT TestClientPushesUseOnePush18242026-09-23 13:01:51.043 UTC [51806] ERROR: relation "goose_db_version" does not exist at character 3618252026-09-23 13:01:51.043 UTC [51806] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18262026/09/23 13:01:51 OK 20241026095416_initial_model.sql (178.21ms)18272026/09/23 13:01:51 OK 20251210153512_drop_unused_gin_index.sql (9.48ms)1828--- PASS: TestReadProxyConditionalGet (2.37s)1829=== CONT TestClientCADerivations18302026/09/23 13:01:51 OK 20251218171726_add_pins.sql (39.24ms)18312026/09/23 13:01:51 OK 20260628120000_add_object_size_and_stats.sql (46.87ms)18322026/09/23 13:01:51 OK 20260905000000_add_claims.sql (41.32ms)18332026/09/23 13:01:51 OK 20260920000000_drop_claims.sql (19.96ms)18342026/09/23 13:01:51 OK 20260923120000_add_pushes.sql (10.52ms)18352026/09/23 13:01:51 goose: successfully migrated database to version: 2026092312000018362026/09/23 13:01:51 OK 1_commit_pending_closure.sql (2.54ms)18372026/09/23 13:01:51 OK 2_object_stats_trigger.sql (519.63µs)18382026/09/23 13:01:51 OK 3_commit_push.sql (366.29µs)18392026/09/23 13:01:51 goose: up to current file version: 318402026-09-23 13:01:51.549 UTC [51831] ERROR: relation "goose_db_version" does not exist at character 3618412026-09-23 13:01:51.549 UTC [51831] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18422026-09-23 13:01:51.592 UTC [51832] ERROR: relation "goose_db_version" does not exist at character 3618432026-09-23 13:01:51.592 UTC [51832] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1844--- PASS: TestReadProxyInvalidPath (2.76s)1845=== CONT TestPinProtectsFromGC18462026/09/23 13:01:51 OK 20241026095416_initial_model.sql (107.64ms)18472026/09/23 13:01:51 OK 20251210153512_drop_unused_gin_index.sql (17.4ms)18482026/09/23 13:01:51 OK 20251218171726_add_pins.sql (13.53ms)18492026/09/23 13:01:51 OK 20241026095416_initial_model.sql (91.98ms)18502026-09-23 13:01:51.754 UTC [51835] ERROR: relation "goose_db_version" does not exist at character 3618512026-09-23 13:01:51.754 UTC [51835] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18522026/09/23 13:01:51 OK 20251210153512_drop_unused_gin_index.sql (10.7ms)18532026/09/23 13:01:51 OK 20251218171726_add_pins.sql (16.97ms)18542026/09/23 13:01:51 OK 20260628120000_add_object_size_and_stats.sql (32.67ms)1855--- PASS: TestReadProxy404 (2.52s)1856=== CONT TestClientErrorHandling1857=== RUN TestClientErrorHandling/InvalidStorePath1858=== PAUSE TestClientErrorHandling/InvalidStorePath1859=== RUN TestClientErrorHandling/InvalidAuthToken1860=== PAUSE TestClientErrorHandling/InvalidAuthToken1861=== RUN TestClientErrorHandling/ServerNotAvailable1862=== PAUSE TestClientErrorHandling/ServerNotAvailable1863=== CONT TestCacheConfigHandler1864=== RUN TestCacheConfigHandler/full_config,_no_issuer1865=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1866=== RUN TestCacheConfigHandler/no_cache_url_configured1867=== PAUSE TestCacheConfigHandler/no_cache_url_configured1868=== RUN TestCacheConfigHandler/no_signing_keys1869=== PAUSE TestCacheConfigHandler/no_signing_keys1870=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1871=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1872=== CONT TestCacheStatsHandler18732026/09/23 13:01:51 OK 20260628120000_add_object_size_and_stats.sql (45.8ms)18742026/09/23 13:01:51 OK 20260905000000_add_claims.sql (41.3ms)18752026/09/23 13:01:51 OK 20260920000000_drop_claims.sql (47.47ms)18762026/09/23 13:01:51 OK 20260923120000_add_pushes.sql (9.33ms)18772026/09/23 13:01:51 goose: successfully migrated database to version: 2026092312000018782026/09/23 13:01:51 OK 20260905000000_add_claims.sql (57.67ms)18792026/09/23 13:01:51 OK 1_commit_pending_closure.sql (4.17ms)18802026/09/23 13:01:51 OK 2_object_stats_trigger.sql (556.21µs)18812026/09/23 13:01:51 OK 3_commit_push.sql (386.04µs)18822026/09/23 13:01:51 goose: up to current file version: 318832026/09/23 13:01:51 OK 20260920000000_drop_claims.sql (23.48ms)18842026/09/23 13:01:51 OK 20260923120000_add_pushes.sql (16.48ms)18852026/09/23 13:01:51 goose: successfully migrated database to version: 2026092312000018862026/09/23 13:01:51 OK 20241026095416_initial_model.sql (117.61ms)18872026/09/23 13:01:51 OK 1_commit_pending_closure.sql (1.83ms)18882026/09/23 13:01:51 OK 2_object_stats_trigger.sql (370.13µs)18892026/09/23 13:01:51 OK 3_commit_push.sql (324.08µs)18902026/09/23 13:01:51 goose: up to current file version: 318912026/09/23 13:01:51 OK 20251210153512_drop_unused_gin_index.sql (10.54ms)18922026/09/23 13:01:51 OK 20251218171726_add_pins.sql (17.35ms)18932026/09/23 13:01:51 OK 20260628120000_add_object_size_and_stats.sql (33.1ms)18942026/09/23 13:01:52 OK 20260905000000_add_claims.sql (67.78ms)18952026/09/23 13:01:52 OK 20260920000000_drop_claims.sql (22.02ms)18962026/09/23 13:01:52 OK 20260923120000_add_pushes.sql (18.98ms)18972026/09/23 13:01:52 goose: successfully migrated database to version: 2026092312000018982026/09/23 13:01:52 OK 1_commit_pending_closure.sql (3.07ms)18992026/09/23 13:01:52 OK 2_object_stats_trigger.sql (376.5µs)19002026/09/23 13:01:52 OK 3_commit_push.sql (333.08µs)19012026/09/23 13:01:52 goose: up to current file version: 31902--- PASS: TestResurrectedObjectNotDeleted (2.64s)1903=== CONT TestService_ReadScope_PublicByDefault19042026-09-23 13:01:52.352 UTC [51840] ERROR: relation "goose_db_version" does not exist at character 3619052026-09-23 13:01:52.352 UTC [51840] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19062026/09/23 13:01:52 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux19072026/09/23 13:01:52 WARN Refused reserved pin name=worker-x86_64-linux19082026/09/23 13:01:52 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux19092026/09/23 13:01:52 INFO Received create pin request method=POST path=/api/pins/my-app19102026/09/23 13:01:52 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1911--- PASS: TestCreatePin_ReservedPins (2.61s)1912=== CONT TestService_RequireScope_OIDC19132026/09/23 13:01:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57387/oidc19142026/09/23 13:01:52 OK 20241026095416_initial_model.sql (96.15ms)19152026/09/23 13:01:52 OK 20251210153512_drop_unused_gin_index.sql (9.28ms)19162026-09-23 13:01:52.545 UTC [51843] ERROR: relation "goose_db_version" does not exist at character 3619172026-09-23 13:01:52.545 UTC [51843] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19182026/09/23 13:01:52 OK 20251218171726_add_pins.sql (11.58ms)19192026/09/23 13:01:52 OK 20260628120000_add_object_size_and_stats.sql (33.09ms)19202026/09/23 13:01:52 OK 20260905000000_add_claims.sql (45.56ms)19212026/09/23 13:01:52 OK 20260920000000_drop_claims.sql (28ms)19222026/09/23 13:01:52 OK 20260923120000_add_pushes.sql (17.11ms)19232026/09/23 13:01:52 goose: successfully migrated database to version: 2026092312000019242026/09/23 13:01:52 OK 1_commit_pending_closure.sql (2.07ms)19252026/09/23 13:01:52 OK 2_object_stats_trigger.sql (462.42µs)19262026/09/23 13:01:52 OK 3_commit_push.sql (399.83µs)19272026/09/23 13:01:52 goose: up to current file version: 319282026/09/23 13:01:52 OK 20241026095416_initial_model.sql (152.96ms)19292026/09/23 13:01:52 OK 20251210153512_drop_unused_gin_index.sql (7.54ms)19302026/09/23 13:01:52 OK 20251218171726_add_pins.sql (33.14ms)19312026/09/23 13:01:52 OK 20260628120000_add_object_size_and_stats.sql (37.65ms)19322026/09/23 13:01:52 OK 20260905000000_add_claims.sql (91.46ms)19332026/09/23 13:01:52 OK 20260920000000_drop_claims.sql (41.5ms)19342026/09/23 13:01:52 OK 20260923120000_add_pushes.sql (23.29ms)19352026/09/23 13:01:52 goose: successfully migrated database to version: 2026092312000019362026/09/23 13:01:52 OK 1_commit_pending_closure.sql (4.54ms)19372026/09/23 13:01:52 OK 2_object_stats_trigger.sql (848.21µs)19382026/09/23 13:01:52 OK 3_commit_push.sql (594.63µs)19392026/09/23 13:01:52 goose: up to current file version: 319402026-09-23 13:01:53.322 UTC [51846] ERROR: relation "goose_db_version" does not exist at character 3619412026-09-23 13:01:53.322 UTC [51846] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19422026-09-23 13:01:53.478 UTC [51862] ERROR: relation "goose_db_version" does not exist at character 3619432026-09-23 13:01:53.478 UTC [51862] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19442026/09/23 13:01:53 OK 20241026095416_initial_model.sql (141.54ms)19452026/09/23 13:01:53 OK 20251210153512_drop_unused_gin_index.sql (9.02ms)1946=== NAME TestClientWithDependencies1947 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-51385-2205677552/TestClientWithDependencies3107970747/001/store/qb0g3bwy8zxd99yhj1cxzmgpdv801vha-test-script19482026/09/23 13:01:53 OK 20251218171726_add_pins.sql (32.24ms)1949 client_integration_test.go:615: Found 1 dependencies (including self)19502026/09/23 13:01:53 OK 20260628120000_add_object_size_and_stats.sql (40.86ms)19512026/09/23 13:01:53 OK 20260905000000_add_claims.sql (20.93ms)19522026/09/23 13:01:53 OK 20260920000000_drop_claims.sql (11.72ms)19532026/09/23 13:01:53 OK 20260923120000_add_pushes.sql (10.4ms)19542026/09/23 13:01:53 goose: successfully migrated database to version: 2026092312000019552026/09/23 13:01:53 OK 20241026095416_initial_model.sql (123.43ms)19562026/09/23 13:01:53 OK 1_commit_pending_closure.sql (1.66ms)19572026/09/23 13:01:53 OK 2_object_stats_trigger.sql (353µs)19582026/09/23 13:01:53 OK 3_commit_push.sql (267.04µs)19592026/09/23 13:01:53 goose: up to current file version: 319602026/09/23 13:01:53 OK 20251210153512_drop_unused_gin_index.sql (18.99ms)19612026/09/23 13:01:53 INFO Received uploads request method=POST path=/api/pending_closures19622026/09/23 13:01:53 INFO Received uploads request method=POST path=/api/pending_closures19632026/09/23 13:01:53 OK 20251218171726_add_pins.sql (45.08ms)19642026/09/23 13:01:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19652026/09/23 13:01:53 INFO Uploading qb0g3bwy8zxd99yhj1cxzmgpdv801vha-test-script (136B)19662026/09/23 13:01:53 OK 20260628120000_add_object_size_and_stats.sql (64.15ms)19672026/09/23 13:01:53 WARN Failed to register uploaded object key=qb0g3bwy8zxd99yhj1cxzmgpdv801vha.ls error="server returned 404: 404 page not found\n"19682026/09/23 13:01:53 WARN Failed to register uploaded object key=log/mmgb262zxxdlzm6hicljy6dsvdz94dx4-test-script.drv error="server returned 404: 404 page not found\n"19692026/09/23 13:01:53 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"19702026/09/23 13:01:53 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19712026/09/23 13:01:53 INFO Signed narinfos id=1 count=119722026/09/23 13:01:53 INFO Uploading 1 narinfos19732026/09/23 13:01:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19742026/09/23 13:01:53 WARN Failed to register uploaded object key=qb0g3bwy8zxd99yhj1cxzmgpdv801vha.narinfo error="server returned 404: 404 page not found\n"19752026/09/23 13:01:53 INFO Completed upload id=119762026/09/23 13:01:53 INFO Upload complete. (223ms)19772026/09/23 13:01:53 OK 20260905000000_add_claims.sql (75.4ms)19782026/09/23 13:01:53 INFO Received uploads request method=POST path=/api/pending_closures19792026/09/23 13:01:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19802026/09/23 13:01:53 INFO Uploading yngkg059s6fqa0icxsk4zjhrbdwjki06-shared-dep (136B)1981 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-51385-2205677552/TestClientWithDependencies3107970747/001/store) requires matching store prefix19822026/09/23 13:01:53 WARN Failed to register uploaded object key=yngkg059s6fqa0icxsk4zjhrbdwjki06.ls error="server returned 404: 404 page not found\n"1983=== NAME TestClientMultipleUploads1984 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-51385-2205677552/TestClientMultipleUploads3188170906/001/store/kp781g15qj9kz539cmapa3l6acm4gyw3-test-file-0.txt19852026/09/23 13:01:53 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign19862026/09/23 13:01:53 INFO Signed narinfos id=2 count=119872026/09/23 13:01:53 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19882026/09/23 13:01:53 INFO Uploading 1 narinfos19892026/09/23 13:01:53 OK 20260920000000_drop_claims.sql (38.99ms)19902026-09-23 13:01:53.897 UTC [51881] ERROR: relation "goose_db_version" does not exist at character 3619912026-09-23 13:01:53.897 UTC [51881] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19922026/09/23 13:01:53 OK 20260923120000_add_pushes.sql (13.26ms)19932026/09/23 13:01:53 goose: successfully migrated database to version: 2026092312000019942026/09/23 13:01:53 OK 1_commit_pending_closure.sql (1.13ms)19952026/09/23 13:01:53 OK 2_object_stats_trigger.sql (253.42µs)19962026/09/23 13:01:53 OK 3_commit_push.sql (216.92µs)19972026/09/23 13:01:53 goose: up to current file version: 319982026/09/23 13:01:53 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete19992026/09/23 13:01:53 WARN Failed to register uploaded object key=yngkg059s6fqa0icxsk4zjhrbdwjki06.narinfo error="server returned 404: 404 page not found\n"2000--- PASS: TestClientWithDependencies (3.71s)2001=== CONT TestService_AuthMiddleware_MTLSProxyHeader20022026/09/23 13:01:53 INFO Completed upload id=220032026/09/23 13:01:53 INFO Upload complete. (172ms)20042026/09/23 13:01:53 INFO Received uploads request method=POST path=/api/pending_closures20052026/09/23 13:01:53 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)20062026/09/23 13:01:53 INFO Uploading z3hq9bfs7b951njarbnmv87g51xr99sv-top (256B)20072026/09/23 13:01:53 INFO Uploading yngkg059s6fqa0icxsk4zjhrbdwjki06-shared-dep (136B)20082026/09/23 13:01:53 WARN Failed to register uploaded object key=z3hq9bfs7b951njarbnmv87g51xr99sv.ls error="server returned 404: 404 page not found\n"20092026/09/23 13:01:53 WARN Failed to register uploaded object key=nar/072097il7b1w4izm03may83d58krmpbazhjj0vg80k2q9vlrizqv.nar.zst error="server returned 404: 404 page not found\n"20102026/09/23 13:01:54 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"20112026/09/23 13:01:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20122026/09/23 13:01:54 INFO Signed narinfos id=1 count=120132026/09/23 13:01:54 WARN Failed to register uploaded object key=yngkg059s6fqa0icxsk4zjhrbdwjki06.ls error="server returned 404: 404 page not found\n"20142026/09/23 13:01:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign20152026/09/23 13:01:54 INFO Signed narinfos id=3 count=120162026/09/23 13:01:54 INFO Uploading 2 narinfos20172026/09/23 13:01:54 WARN Failed to register uploaded object key=z3hq9bfs7b951njarbnmv87g51xr99sv.narinfo error="server returned 404: 404 page not found\n"2018=== NAME TestClientMultipleUploads2019 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-51385-2205677552/TestClientMultipleUploads3188170906/001/store/3npxddcj26jr7bjxr78ar55yppc8bjqk-test-file-1.txt20202026/09/23 13:01:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20212026/09/23 13:01:54 WARN Failed to register uploaded object key=yngkg059s6fqa0icxsk4zjhrbdwjki06.narinfo error="server returned 404: 404 page not found\n"20222026/09/23 13:01:54 INFO Completed upload id=120232026/09/23 13:01:54 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete20242026/09/23 13:01:54 INFO Completed upload id=320252026/09/23 13:01:54 INFO Upload complete. (441ms)2026=== NAME TestClientSharedPathCommittedMidPush2027 client_integration_test.go:680: Retrieved narinfo from S3:2028 StorePath: /nix/var/nix/builds/nix-51385-2205677552/TestClientSharedPathCommittedMidPush3437937793/001/store/yngkg059s6fqa0icxsk4zjhrbdwjki06-shared-dep2029 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2030 Compression: zstd2031 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822032 NarSize: 1362033 References: 2034 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2035 client_integration_test.go:680: Retrieved narinfo from S3:2036 StorePath: /nix/var/nix/builds/nix-51385-2205677552/TestClientSharedPathCommittedMidPush3437937793/001/store/z3hq9bfs7b951njarbnmv87g51xr99sv-top2037 URL: nar/072097il7b1w4izm03may83d58krmpbazhjj0vg80k2q9vlrizqv.nar.zst2038 Compression: zstd2039 NarHash: sha256:072097il7b1w4izm03may83d58krmpbazhjj0vg80k2q9vlrizqv2040 NarSize: 2562041 References: /nix/var/nix/builds/nix-51385-2205677552/TestClientSharedPathCommittedMidPush3437937793/001/store/yngkg059s6fqa0icxsk4zjhrbdwjki06-shared-dep2042 CA: text:sha256:03q0dxdq3sxxih6q17109n584vq6z35ixlxas2zks1yba32zcr0k20432026-09-23 13:01:54.095 UTC [51884] ERROR: relation "goose_db_version" does not exist at character 3620442026-09-23 13:01:54.095 UTC [51884] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2045--- PASS: TestClientSharedPathCommittedMidPush (3.78s)2046=== CONT TestService_AuthMiddleware_OIDC2047=== NAME TestClientMultipleUploads2048 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-51385-2205677552/TestClientMultipleUploads3188170906/001/store/0z893d3ysdyb1jah6ng2q4lrmza98bxf-test-file-2.txt20492026/09/23 13:01:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57416/oidc20502026/09/23 13:01:54 OK 20241026095416_initial_model.sql (313.96ms)20512026/09/23 13:01:54 OK 20251210153512_drop_unused_gin_index.sql (21.34ms)20522026/09/23 13:01:54 INFO Received uploads request method=POST path=/api/pending_closures20532026/09/23 13:01:54 INFO Received uploads request method=POST path=/api/pending_closures20542026/09/23 13:01:54 OK 20251218171726_add_pins.sql (59.69ms)20552026/09/23 13:01:54 INFO Received uploads request method=POST path=/api/pending_closures20562026/09/23 13:01:54 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)20572026/09/23 13:01:54 INFO Uploading 0z893d3ysdyb1jah6ng2q4lrmza98bxf-test-file-2.txt (160B)20582026/09/23 13:01:54 INFO Uploading kp781g15qj9kz539cmapa3l6acm4gyw3-test-file-0.txt (160B)20592026/09/23 13:01:54 INFO Uploading 3npxddcj26jr7bjxr78ar55yppc8bjqk-test-file-1.txt (160B)20602026/09/23 13:01:54 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"20612026/09/23 13:01:54 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"20622026/09/23 13:01:54 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"20632026/09/23 13:01:54 WARN Failed to register uploaded object key=kp781g15qj9kz539cmapa3l6acm4gyw3.ls error="server returned 404: 404 page not found\n"20642026/09/23 13:01:54 WARN Failed to register uploaded object key=0z893d3ysdyb1jah6ng2q4lrmza98bxf.ls error="server returned 404: 404 page not found\n"20652026/09/23 13:01:54 OK 20260628120000_add_object_size_and_stats.sql (59.92ms)20662026/09/23 13:01:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20672026/09/23 13:01:54 WARN Failed to register uploaded object key=3npxddcj26jr7bjxr78ar55yppc8bjqk.ls error="server returned 404: 404 page not found\n"20682026/09/23 13:01:54 INFO Signed narinfos id=1 count=120692026/09/23 13:01:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign20702026/09/23 13:01:54 INFO Signed narinfos id=2 count=120712026/09/23 13:01:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign20722026/09/23 13:01:54 INFO Signed narinfos id=3 count=120732026/09/23 13:01:54 INFO Uploading 3 narinfos20742026/09/23 13:01:54 WARN Failed to register uploaded object key=0z893d3ysdyb1jah6ng2q4lrmza98bxf.narinfo error="server returned 404: 404 page not found\n"20752026/09/23 13:01:54 OK 20241026095416_initial_model.sql (290.62ms)20762026/09/23 13:01:54 OK 20251210153512_drop_unused_gin_index.sql (5.06ms)20772026/09/23 13:01:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20782026/09/23 13:01:54 WARN Failed to register uploaded object key=kp781g15qj9kz539cmapa3l6acm4gyw3.narinfo error="server returned 404: 404 page not found\n"20792026/09/23 13:01:54 WARN Failed to register uploaded object key=3npxddcj26jr7bjxr78ar55yppc8bjqk.narinfo error="server returned 404: 404 page not found\n"20802026/09/23 13:01:54 INFO Completed upload id=120812026/09/23 13:01:54 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete20822026/09/23 13:01:54 INFO Completed upload id=220832026/09/23 13:01:54 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete20842026/09/23 13:01:54 INFO Completed upload id=320852026/09/23 13:01:54 INFO Upload complete. (272ms)2086 client_integration_test.go:369: Uploaded 3 paths in 305.478084ms20872026/09/23 13:01:54 OK 20251218171726_add_pins.sql (47.14ms)20882026/09/23 13:01:54 OK 20260905000000_add_claims.sql (93.14ms)20892026/09/23 13:01:54 OK 20260628120000_add_object_size_and_stats.sql (33.92ms)20902026/09/23 13:01:54 OK 20260920000000_drop_claims.sql (89.91ms)2091--- PASS: TestClientMultipleUploads (3.95s)2092=== CONT TestService_ReadAuthMiddleware20932026/09/23 13:01:54 OK 20260923120000_add_pushes.sql (22.74ms)20942026/09/23 13:01:54 goose: successfully migrated database to version: 2026092312000020952026/09/23 13:01:54 OK 1_commit_pending_closure.sql (1.47ms)20962026/09/23 13:01:54 OK 2_object_stats_trigger.sql (394.38µs)20972026/09/23 13:01:54 OK 3_commit_push.sql (217.38µs)20982026/09/23 13:01:54 goose: up to current file version: 320992026/09/23 13:01:54 OK 20260905000000_add_claims.sql (112.59ms)21002026/09/23 13:01:54 OK 20260920000000_drop_claims.sql (69.47ms)21012026/09/23 13:01:54 OK 20260923120000_add_pushes.sql (27.61ms)21022026/09/23 13:01:54 goose: successfully migrated database to version: 2026092312000021032026/09/23 13:01:54 OK 1_commit_pending_closure.sql (1.12ms)21042026/09/23 13:01:54 OK 2_object_stats_trigger.sql (254.63µs)21052026/09/23 13:01:54 OK 3_commit_push.sql (198.04µs)21062026/09/23 13:01:54 goose: up to current file version: 321072026/09/23 13:01:54 INFO Received uploads request method=POST path=/api/pending_closures21082026/09/23 13:01:54 INFO Received uploads request method=POST path=/api/pending_closures21092026/09/23 13:01:54 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)21102026/09/23 13:01:54 INFO Uploading 7g0vip6gwxx520w4fvla1xvf1z0chgxp-b (248B)21112026/09/23 13:01:54 INFO Uploading lzviqlda7n194ch5yxbzkfn74xq4yf4r-shared-dep (136B)21122026/09/23 13:01:54 WARN Failed to register uploaded object key=7g0vip6gwxx520w4fvla1xvf1z0chgxp.ls error="server returned 404: 404 page not found\n"21132026/09/23 13:01:55 WARN Failed to register uploaded object key=nar/1ac1j7iw03fycs6pq9mqwmxdhsibzbp9ngpjcq8c9fdrg64058cr.nar.zst error="server returned 404: 404 page not found\n"21142026/09/23 13:01:55 WARN Failed to register uploaded object key=4n5mxaqdfjszn4103h0q9dknr7j7bpvn.ls error="server returned 404: 404 page not found\n"21152026/09/23 13:01:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21162026/09/23 13:01:55 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"21172026/09/23 13:01:55 WARN Failed to register uploaded object key=lzviqlda7n194ch5yxbzkfn74xq4yf4r.ls error="server returned 404: 404 page not found\n"21182026/09/23 13:01:55 INFO Signed narinfos id=1 count=221192026/09/23 13:01:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign21202026/09/23 13:01:55 INFO Signed narinfos id=2 count=221212026/09/23 13:01:55 INFO Uploading 4 narinfos21222026/09/23 13:01:55 WARN Failed to register uploaded object key=4n5mxaqdfjszn4103h0q9dknr7j7bpvn.narinfo error="server returned 404: 404 page not found\n"21232026/09/23 13:01:55 WARN Failed to register uploaded object key=lzviqlda7n194ch5yxbzkfn74xq4yf4r.narinfo error="server returned 404: 404 page not found\n"21242026/09/23 13:01:55 WARN Failed to register uploaded object key=7g0vip6gwxx520w4fvla1xvf1z0chgxp.narinfo error="server returned 404: 404 page not found\n"2125--- PASS: TestCacheStatsHandler (3.24s)2126=== CONT TestService_AuthMiddleware_MTLSBoundSubjects21272026/09/23 13:01:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21282026/09/23 13:01:55 WARN Failed to register uploaded object key=lzviqlda7n194ch5yxbzkfn74xq4yf4r.narinfo error="server returned 404: 404 page not found\n"21292026/09/23 13:01:55 INFO Completed upload id=121302026/09/23 13:01:55 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21312026/09/23 13:01:55 INFO Completed upload id=221322026/09/23 13:01:55 INFO Upload complete. (231ms)2133=== NAME TestClientPushesUseOnePush2134 client_pushes_test.go:97: Retrieved narinfo from S3:2135 StorePath: /nix/var/nix/builds/nix-51385-2205677552/TestClientPushesUseOnePush2189549595/001/store/lzviqlda7n194ch5yxbzkfn74xq4yf4r-shared-dep2136 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2137 Compression: zstd2138 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822139 NarSize: 1362140 References: 2141 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2142 client_pushes_test.go:97: Retrieved narinfo from S3:2143 StorePath: /nix/var/nix/builds/nix-51385-2205677552/TestClientPushesUseOnePush2189549595/001/store/4n5mxaqdfjszn4103h0q9dknr7j7bpvn-a2144 URL: nar/1ac1j7iw03fycs6pq9mqwmxdhsibzbp9ngpjcq8c9fdrg64058cr.nar.zst2145 Compression: zstd2146 NarHash: sha256:1ac1j7iw03fycs6pq9mqwmxdhsibzbp9ngpjcq8c9fdrg64058cr2147 NarSize: 2482148 References: /nix/var/nix/builds/nix-51385-2205677552/TestClientPushesUseOnePush2189549595/001/store/lzviqlda7n194ch5yxbzkfn74xq4yf4r-shared-dep2149 CA: text:sha256:0dvag7h2q3sff2qm9hhn3flihgkhymvpbbk13j652lrpkkqiq5s02150 client_pushes_test.go:97: Retrieved narinfo from S3:2151 StorePath: /nix/var/nix/builds/nix-51385-2205677552/TestClientPushesUseOnePush2189549595/001/store/7g0vip6gwxx520w4fvla1xvf1z0chgxp-b2152 URL: nar/1ac1j7iw03fycs6pq9mqwmxdhsibzbp9ngpjcq8c9fdrg64058cr.nar.zst2153 Compression: zstd2154 NarHash: sha256:1ac1j7iw03fycs6pq9mqwmxdhsibzbp9ngpjcq8c9fdrg64058cr2155 NarSize: 2482156 References: /nix/var/nix/builds/nix-51385-2205677552/TestClientPushesUseOnePush2189549595/001/store/lzviqlda7n194ch5yxbzkfn74xq4yf4r-shared-dep2157 CA: text:sha256:0dvag7h2q3sff2qm9hhn3flihgkhymvpbbk13j652lrpkkqiq5s02158 client_pushes_test.go:100: POST /api/pushes calls = 0, want 12159 client_pushes_test.go:104: POST /api/pending_closures calls = 2, want 021602026-09-23 13:01:55.112 UTC [51921] ERROR: relation "goose_db_version" does not exist at character 3621612026-09-23 13:01:55.112 UTC [51921] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2162=== NAME TestClientCADerivations2163 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-51385-2205677552/TestClientCADerivations133067076/001/store/i26fdcp6rp27gv817c53r8pwkswn2a0a-ca-test2164--- FAIL: TestClientPushesUseOnePush (4.21s)2165=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure21662026/09/23 13:01:55 INFO Received uploads request method=POST path=/2167=== NAME TestClientCADerivations2168 client_ca_test.go:139: Found 1 dependencies (including self)21692026-09-23 13:01:55.233 UTC [51924] ERROR: relation "goose_db_version" does not exist at character 3621702026-09-23 13:01:55.233 UTC [51924] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21712026/09/23 13:01:55 INFO Received uploads request method=POST path=/api/pending_closures21722026/09/23 13:01:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21732026/09/23 13:01:55 INFO Uploading i26fdcp6rp27gv817c53r8pwkswn2a0a-ca-test (144B)21742026/09/23 13:01:55 OK 20241026095416_initial_model.sql (210.05ms)21752026/09/23 13:01:55 OK 20251210153512_drop_unused_gin_index.sql (4.43ms)21762026/09/23 13:01:55 WARN Failed to register uploaded object key=i26fdcp6rp27gv817c53r8pwkswn2a0a.ls error="server returned 404: 404 page not found\n"21772026/09/23 13:01:55 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"21782026/09/23 13:01:55 OK 20241026095416_initial_model.sql (139.03ms)21792026/09/23 13:01:55 OK 20251210153512_drop_unused_gin_index.sql (21.32ms)21802026/09/23 13:01:55 WARN Failed to register uploaded object key=log/q5gzsmynsd5lzy7vmaj26k6537a51rd8-ca-test.drv error="server returned 404: 404 page not found\n"21812026/09/23 13:01:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21822026/09/23 13:01:55 INFO Signed narinfos id=1 count=121832026/09/23 13:01:55 INFO Uploading 1 narinfos21842026/09/23 13:01:55 OK 20251218171726_add_pins.sql (45.98ms)21852026/09/23 13:01:55 OK 20251218171726_add_pins.sql (24.87ms)21862026/09/23 13:01:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21872026/09/23 13:01:55 WARN Failed to register uploaded object key=i26fdcp6rp27gv817c53r8pwkswn2a0a.narinfo error="server returned 404: 404 page not found\n"21882026/09/23 13:01:55 OK 20260628120000_add_object_size_and_stats.sql (26.07ms)2189=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart21902026/09/23 13:01:55 INFO Received complete multipart upload request method=POST path=/21912026/09/23 13:01:55 INFO Completed upload id=121922026/09/23 13:01:55 INFO Upload complete. (250ms)21932026/09/23 13:01:55 OK 20260628120000_add_object_size_and_stats.sql (32.59ms)2194=== NAME TestClientCADerivations2195 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-51385-2205677552/TestClientCADerivations133067076/001/store/i26fdcp6rp27gv817c53r8pwkswn2a0a-ca-test2196 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2197 Compression: zstd2198 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2199 NarSize: 1442200 References: 2201 Deriver: /nix/var/nix/builds/nix-51385-2205677552/TestClientCADerivations133067076/001/store/q5gzsmynsd5lzy7vmaj26k6537a51rd8-ca-test.drv2202 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2203 client_ca_test.go:185: Checking for realisation files in S3...2204 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2205 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache2206=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts22072026/09/23 13:01:55 INFO Received request for more parts method=POST path=/22082026/09/23 13:01:55 OK 20260905000000_add_claims.sql (25.86ms)2209=== CONT TestServerTLSConfig/no_client_CA2210--- PASS: TestUploadHandlersRejectOversizedBody (0.04s)2211 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.29s)2212 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)2213 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)2214=== CONT TestServerTLSConfig/not_a_PEM_file22152026/09/23 13:01:55 OK 20260905000000_add_claims.sql (34.5ms)2216=== CONT TestServerTLSConfig/missing_CA_file2217--- PASS: TestServerTLSConfig (0.00s)2218 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2219 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)2220 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2221=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info22222026/09/23 13:01:55 INFO Received uploads request method=POST path=/2223=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key22242026/09/23 13:01:55 INFO Received complete multipart upload request method=POST path=/2225=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key22262026/09/23 13:01:55 INFO Received request for more parts method=POST path=/2227=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal22282026/09/23 13:01:55 INFO Received uploads request method=POST path=/2229--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2230 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2231 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2232 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2233 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2234=== CONT TestIsValidUploadKey/narinfo2235=== CONT TestIsValidUploadKey/realisation_plus_in_output2236=== CONT TestIsValidUploadKey/unknown_type2237=== CONT TestIsValidUploadKey/empty_key2238=== CONT TestIsValidUploadKey/absolute2239=== CONT TestIsValidUploadKey/traversal_nar2240=== CONT TestIsValidUploadKey/traversal2241=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2242=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2243=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2244=== CONT TestIsValidUploadKey/index.html2245=== CONT TestIsValidUploadKey/nix-cache-info2246=== CONT TestIsValidUploadKey/build_log_home-manager_file2247=== CONT TestIsValidUploadKey/realisation2248=== CONT TestIsValidUploadKey/build_log_equals2249=== CONT TestIsValidUploadKey/build_log_question_mark2250=== CONT TestIsValidUploadKey/build_log_plus_in_name2251=== CONT TestIsValidUploadKey/nar_plain2252=== CONT TestIsValidUploadKey/build_log2253=== CONT TestIsValidUploadKey/listing2254=== CONT TestIsValidUploadKey/nar_xz2255=== CONT TestIsValidUploadKey/nar_zst2256--- PASS: TestIsValidUploadKey (0.00s)2257 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2258 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2259 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2260 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2261 --- PASS: TestIsValidUploadKey/absolute (0.00s)2262 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2263 --- PASS: TestIsValidUploadKey/traversal (0.00s)2264 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2265 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2266 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2267 --- PASS: TestIsValidUploadKey/index.html (0.00s)2268 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2269 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2270 --- PASS: TestIsValidUploadKey/realisation (0.00s)2271 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2272 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2273 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2274 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2275 --- PASS: TestIsValidUploadKey/build_log (0.00s)2276 --- PASS: TestIsValidUploadKey/listing (0.00s)2277 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2278 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2279=== CONT TestProxyWriteTimeout/narinfo2280=== CONT TestProxyWriteTimeout/10_GiB_nar2281=== CONT TestProxyWriteTimeout/unknown_size2282=== CONT TestProxyWriteTimeout/1_GiB_nar2283--- PASS: TestProxyWriteTimeout (0.00s)2284 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2285 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2286 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2287 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2288=== CONT TestPush_RejectsBadRequests/no_objects22892026/09/23 13:01:55 INFO Received push request method=POST path=/api/pushes2290=== CONT TestPush_RejectsBadRequests/root_not_in_objects22912026/09/23 13:01:55 INFO Received push request method=POST path=/api/pushes2292=== CONT TestPush_RejectsBadRequests/no_roots22932026/09/23 13:01:55 INFO Received push request method=POST path=/api/pushes2294=== CONT TestPush_RejectsBadRequests/bad_root22952026/09/23 13:01:55 INFO Received push request method=POST path=/api/pushes2296=== CONT TestResolveDBConnectionString/flag_wins2297=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2298=== CONT TestResolveDBConnectionString/nothing_configured2299=== CONT TestResolveDBConnectionString/missing_file_is_an_error2300--- PASS: TestPush_RejectsBadRequests (2.16s)2301 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2302 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2303 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2304 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2305=== CONT TestResolveDBConnectionString/file_when_flag_empty2306=== CONT TestIsValidCachePath/narinfo2307=== CONT TestIsValidCachePath/index.html2308=== CONT TestIsValidCachePath/short_hash2309=== CONT TestIsValidCachePath/wrong_extension2310=== CONT TestIsValidCachePath/leading_slash2311=== CONT TestIsValidCachePath/empty2312=== CONT TestIsValidCachePath/nar_uncompressed2313=== CONT TestIsValidCachePath/random_path2314=== CONT TestIsValidCachePath/nix-cache-info2315=== CONT TestIsValidCachePath/invalid_char_u2316=== CONT TestIsValidCachePath/realisation2317=== CONT TestIsValidCachePath/invalid_char_e2318=== CONT TestIsValidCachePath/log2319=== CONT TestIsValidCachePath/traversal_in_middle2320=== CONT TestIsValidCachePath/nar_xz2321=== CONT TestIsValidCachePath/traversal_parent2322=== CONT TestIsValidCachePath/nar_bz22323=== CONT TestIsValidCachePath/nar_zst2324=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2325=== CONT TestIsValidCachePath/ls2326--- PASS: TestIsValidCachePath (0.00s)2327 --- PASS: TestIsValidCachePath/narinfo (0.00s)2328 --- PASS: TestIsValidCachePath/index.html (0.00s)2329 --- PASS: TestIsValidCachePath/short_hash (0.00s)2330 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2331 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2332 --- PASS: TestIsValidCachePath/empty (0.00s)2333 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2334 --- PASS: TestIsValidCachePath/random_path (0.00s)2335 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2336 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2337 --- PASS: TestIsValidCachePath/realisation (0.00s)2338 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2339 --- PASS: TestIsValidCachePath/log (0.00s)2340 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2341 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2342 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2343 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2344 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2345 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2346 --- PASS: TestIsValidCachePath/ls (0.00s)2347=== CONT TestParseSingleRange/none2348=== CONT TestParseSingleRange/open-ended2349=== CONT TestParseSingleRange/start_far_past_EOF2350=== CONT TestParseSingleRange/start_past_EOF2351=== CONT TestParseSingleRange/single_byte2352=== CONT TestParseSingleRange/suffix_exceeds_size2353=== CONT TestParseSingleRange/suffix2354=== CONT TestParseSingleRange/end_clamped_to_size2355=== CONT TestParseSingleRange/malformed_both_empty2356=== CONT TestParseSingleRange/closed2357=== CONT TestParseSingleRange/malformed_end_before_start2358=== CONT TestParseSingleRange/multi-range_ignored2359=== CONT TestParseSingleRange/malformed_no_dash2360=== CONT TestParseSingleRange/unknown_unit2361--- PASS: TestParseSingleRange (0.00s)2362 --- PASS: TestParseSingleRange/none (0.00s)2363 --- PASS: TestParseSingleRange/open-ended (0.00s)2364 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2365 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2366 --- PASS: TestParseSingleRange/single_byte (0.00s)2367 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2368 --- PASS: TestParseSingleRange/suffix (0.00s)2369 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2370 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2371 --- PASS: TestParseSingleRange/closed (0.00s)2372 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2373 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2374 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2375 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2376=== CONT TestClientErrorHandling/InvalidStorePath2377--- PASS: TestResolveDBConnectionString (0.04s)2378 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2379 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2380 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2381 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2382 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)23832026/09/23 13:01:55 OK 20260920000000_drop_claims.sql (62.42ms)23842026/09/23 13:01:55 OK 20260920000000_drop_claims.sql (38.77ms)23852026/09/23 13:01:55 OK 20260923120000_add_pushes.sql (13.77ms)23862026/09/23 13:01:55 goose: successfully migrated database to version: 2026092312000023872026/09/23 13:01:55 OK 20260923120000_add_pushes.sql (14.07ms)23882026/09/23 13:01:55 goose: successfully migrated database to version: 2026092312000023892026/09/23 13:01:55 OK 1_commit_pending_closure.sql (811.67µs)23902026/09/23 13:01:55 OK 1_commit_pending_closure.sql (1.09ms)23912026/09/23 13:01:55 OK 2_object_stats_trigger.sql (254.63µs)23922026/09/23 13:01:55 OK 2_object_stats_trigger.sql (238.38µs)23932026/09/23 13:01:55 OK 3_commit_push.sql (182.25µs)23942026/09/23 13:01:55 goose: up to current file version: 323952026/09/23 13:01:55 OK 3_commit_push.sql (226.21µs)23962026/09/23 13:01:55 goose: up to current file version: 32397=== NAME TestClientCADerivations2398 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket55?endpoint=http://localhost:57145®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-51385-2205677552/TestClientCADerivations133067076/001/store'2399 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12400=== NAME TestPinProtectsFromGC2401 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-51385-2205677552/TestPinProtectsFromGC2138680006/001/store/23y1cbv3j064k042niknpxqh8f4284j7-pinned-file.txt2402 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-51385-2205677552/TestPinProtectsFromGC2138680006/001/store/4vs5r3ys8xf0pml6jpv13hkpph3lz9kw-unpinned-file.txt2403--- PASS: TestClientCADerivations (4.40s)2404=== CONT TestClientErrorHandling/ServerNotAvailable24052026/09/23 13:01:55 INFO Received uploads request method=POST path=/api/pending_closures24062026/09/23 13:01:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)24072026/09/23 13:01:55 INFO Uploading 23y1cbv3j064k042niknpxqh8f4284j7-pinned-file.txt (128B)24082026/09/23 13:01:55 WARN Failed to register uploaded object key=23y1cbv3j064k042niknpxqh8f4284j7.ls error="server returned 404: 404 page not found\n"24092026/09/23 13:01:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign24102026/09/23 13:01:55 INFO Signed narinfos id=1 count=124112026/09/23 13:01:55 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"24122026/09/23 13:01:55 INFO Uploading 1 narinfos24132026/09/23 13:01:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete24142026/09/23 13:01:55 WARN Failed to register uploaded object key=23y1cbv3j064k042niknpxqh8f4284j7.narinfo error="server returned 404: 404 page not found\n"2415=== RUN TestService_RequireScope_OIDC/builder_may_write2416=== PAUSE TestService_RequireScope_OIDC/builder_may_write2417=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2418=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2419=== RUN TestService_RequireScope_OIDC/ops_may_admin2420=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2421=== RUN TestService_RequireScope_OIDC/ops_may_not_write2422=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2423=== RUN TestService_RequireScope_OIDC/reader_may_not_write2424=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2425=== RUN TestService_RequireScope_OIDC/static_token_may_admin2426=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2427=== RUN TestService_RequireScope_OIDC/static_token_may_write2428=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2429=== RUN TestService_RequireScope_OIDC/reader_may_read2430=== PAUSE TestService_RequireScope_OIDC/reader_may_read2431=== RUN TestService_RequireScope_OIDC/writer_implies_read2432=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2433=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2434=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2435=== CONT TestClientErrorHandling/InvalidAuthToken24362026/09/23 13:01:55 INFO Completed upload id=124372026/09/23 13:01:55 INFO Upload complete. (189ms)24382026/09/23 13:01:56 INFO Received uploads request method=POST path=/api/pending_closures24392026/09/23 13:01:56 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)24402026/09/23 13:01:56 INFO Uploading 4vs5r3ys8xf0pml6jpv13hkpph3lz9kw-unpinned-file.txt (128B)24412026/09/23 13:01:56 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"24422026/09/23 13:01:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign24432026/09/23 13:01:56 INFO Signed narinfos id=2 count=124442026/09/23 13:01:56 WARN Failed to register uploaded object key=4vs5r3ys8xf0pml6jpv13hkpph3lz9kw.ls error="server returned 404: 404 page not found\n"24452026/09/23 13:01:56 INFO Uploading 1 narinfos24462026/09/23 13:01:56 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete24472026/09/23 13:01:56 WARN Failed to register uploaded object key=4vs5r3ys8xf0pml6jpv13hkpph3lz9kw.narinfo error="server returned 404: 404 page not found\n"24482026/09/23 13:01:56 INFO Completed upload id=224492026/09/23 13:01:56 INFO Upload complete. (137ms)24502026/09/23 13:01:56 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/present24512026/09/23 13:01:56 INFO Received create pin request method=POST path=/api/pins/myapp24522026/09/23 13:01:56 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-51385-2205677552/TestPinProtectsFromGC2138680006/001/store/23y1cbv3j064k042niknpxqh8f4284j7-pinned-file.txt narinfo_key=23y1cbv3j064k042niknpxqh8f4284j7.narinfo24532026/09/23 13:01:56 INFO Starting cleanup of old closures method=DELETE path=/api/closures24542026/09/23 13:01:56 INFO Garbage collection started24552026/09/23 13:01:56 INFO Aborted multipart uploads count=024562026/09/23 13:01:56 WARN Force mode enabled - objects will be deleted immediately without grace period24572026/09/23 13:01:56 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=214.571171ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2458--- PASS: TestService_ReadScope_PublicByDefault (4.09s)2459=== CONT TestCacheConfigHandler/full_config,_no_issuer2460=== CONT TestCacheConfigHandler/no_signing_keys2461=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2462=== CONT TestCacheConfigHandler/no_cache_url_configured2463--- PASS: TestCacheConfigHandler (0.00s)2464 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2465 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2466 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2467 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2468=== CONT TestService_RequireScope_OIDC/builder_may_write2469=== CONT TestService_RequireScope_OIDC/static_token_may_admin2470=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2471=== CONT TestService_RequireScope_OIDC/writer_implies_read2472=== CONT TestService_RequireScope_OIDC/reader_may_read2473=== CONT TestService_RequireScope_OIDC/static_token_may_write2474=== CONT TestService_RequireScope_OIDC/ops_may_not_write2475=== CONT TestService_RequireScope_OIDC/reader_may_not_write2476=== CONT TestService_RequireScope_OIDC/ops_may_admin2477=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2478--- PASS: TestService_RequireScope_OIDC (3.54s)2479 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2480 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2481 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2482 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2483 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2484 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2485 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2486 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2487 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2488 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)24892026/09/23 13:01:56 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=393.436526ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present24902026/09/23 13:01:56 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=024912026/09/23 13:01:56 INFO Vacuumed table table=pending_closures24922026/09/23 13:01:56 INFO Vacuumed table table=pending_objects24932026/09/23 13:01:56 INFO Vacuumed table table=multipart_uploads24942026/09/23 13:01:56 INFO Vacuumed table table=closures24952026/09/23 13:01:56 INFO Vacuumed table table=objects24962026/09/23 13:01:56 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=766.210124ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present24972026-09-23 13:01:56.920 UTC [51969] ERROR: relation "goose_db_version" does not exist at character 3624982026-09-23 13:01:56.920 UTC [51969] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24992026-09-23 13:01:57.116 UTC [51972] ERROR: relation "goose_db_version" does not exist at character 3625002026-09-23 13:01:57.116 UTC [51972] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25012026/09/23 13:01:57 OK 20241026095416_initial_model.sql (256.84ms)25022026/09/23 13:01:57 OK 20251210153512_drop_unused_gin_index.sql (11.76ms)25032026/09/23 13:01:57 OK 20251218171726_add_pins.sql (72.73ms)25042026/09/23 13:01:57 OK 20260628120000_add_object_size_and_stats.sql (37.91ms)25052026/09/23 13:01:57 OK 20241026095416_initial_model.sql (218.04ms)25062026/09/23 13:01:57 OK 20251210153512_drop_unused_gin_index.sql (16.16ms)25072026/09/23 13:01:57 OK 20260905000000_add_claims.sql (74.73ms)25082026/09/23 13:01:57 OK 20251218171726_add_pins.sql (48.6ms)25092026/09/23 13:01:57 OK 20260920000000_drop_claims.sql (39.13ms)25102026/09/23 13:01:57 OK 20260923120000_add_pushes.sql (8.8ms)25112026/09/23 13:01:57 goose: successfully migrated database to version: 2026092312000025122026/09/23 13:01:57 OK 1_commit_pending_closure.sql (1.37ms)25132026/09/23 13:01:57 OK 2_object_stats_trigger.sql (309.58µs)25142026/09/23 13:01:57 OK 3_commit_push.sql (259.13µs)25152026/09/23 13:01:57 goose: up to current file version: 325162026/09/23 13:01:57 OK 20260628120000_add_object_size_and_stats.sql (47.09ms)25172026/09/23 13:01:57 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.513355303s error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present25182026/09/23 13:01:57 OK 20260905000000_add_claims.sql (111.98ms)25192026-09-23 13:01:57.679 UTC [51979] ERROR: relation "goose_db_version" does not exist at character 3625202026-09-23 13:01:57.679 UTC [51979] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25212026/09/23 13:01:57 OK 20260920000000_drop_claims.sql (47.6ms)25222026/09/23 13:01:57 OK 20260923120000_add_pushes.sql (16.82ms)25232026/09/23 13:01:57 goose: successfully migrated database to version: 2026092312000025242026/09/23 13:01:57 OK 1_commit_pending_closure.sql (939.29µs)25252026/09/23 13:01:57 OK 2_object_stats_trigger.sql (255.67µs)25262026/09/23 13:01:57 OK 3_commit_push.sql (181.08µs)25272026/09/23 13:01:57 goose: up to current file version: 32528--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (3.93s)25292026-09-23 13:01:58.005 UTC [51987] ERROR: relation "goose_db_version" does not exist at character 3625302026-09-23 13:01:58.005 UTC [51987] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25312026/09/23 13:01:58 OK 20241026095416_initial_model.sql (242.43ms)25322026/09/23 13:01:58 OK 20251210153512_drop_unused_gin_index.sql (2.17ms)25332026/09/23 13:01:58 OK 20251218171726_add_pins.sql (31.19ms)25342026/09/23 13:01:58 OK 20260628120000_add_object_size_and_stats.sql (36.52ms)25352026/09/23 13:01:58 OK 20260905000000_add_claims.sql (113.56ms)2536=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2537=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2538=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2539=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2540=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2541=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2542=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2543=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2544=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2545=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected2546=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected25472026/09/23 13:01:58 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]2548=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured25492026/09/23 13:01:58 WARN Authentication failed token_preview=eyJhbGciOi...5ugOXhfgmw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2550--- PASS: TestService_AuthMiddleware_OIDC (4.01s)2551 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2552 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2553 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2554 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)25552026/09/23 13:01:58 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02556=== NAME TestPinProtectsFromGC2557 client_integration_test.go:794: Pin successfully protected closure from garbage collection25582026/09/23 13:01:58 OK 20260920000000_drop_claims.sql (61.41ms)25592026/09/23 13:01:58 OK 20260923120000_add_pushes.sql (33.29ms)25602026/09/23 13:01:58 goose: successfully migrated database to version: 2026092312000025612026/09/23 13:01:58 OK 1_commit_pending_closure.sql (1.33ms)25622026/09/23 13:01:58 OK 2_object_stats_trigger.sql (307.63µs)25632026/09/23 13:01:58 OK 3_commit_push.sql (264.38µs)25642026/09/23 13:01:58 goose: up to current file version: 325652026/09/23 13:01:58 OK 20241026095416_initial_model.sql (334.32ms)2566--- PASS: TestPinProtectsFromGC (6.84s)25672026/09/23 13:01:58 OK 20251210153512_drop_unused_gin_index.sql (18.87ms)25682026/09/23 13:01:58 OK 20251218171726_add_pins.sql (48.99ms)25692026/09/23 13:01:58 OK 20260628120000_add_object_size_and_stats.sql (62.49ms)25702026/09/23 13:01:58 OK 20260905000000_add_claims.sql (146.99ms)2571--- PASS: TestService_ReadAuthMiddleware (4.09s)25722026/09/23 13:01:58 OK 20260920000000_drop_claims.sql (67.75ms)25732026/09/23 13:01:58 OK 20260923120000_add_pushes.sql (24.99ms)25742026/09/23 13:01:58 goose: successfully migrated database to version: 2026092312000025752026/09/23 13:01:58 OK 1_commit_pending_closure.sql (3.7ms)25762026/09/23 13:01:58 OK 2_object_stats_trigger.sql (739.21µs)25772026/09/23 13:01:58 OK 3_commit_push.sql (542.13µs)25782026/09/23 13:01:58 goose: up to current file version: 325792026-09-23 13:01:58.955 UTC [51999] ERROR: relation "goose_db_version" does not exist at character 3625802026-09-23 13:01:58.955 UTC [51999] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25812026/09/23 13:01:59 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"25822026/09/23 13:01:59 WARN mTLS auth: bound subjects configured but subject DN unavailable25832026/09/23 13:01:59 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2584--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (4.18s)25852026/09/23 13:01:59 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-config25862026/09/23 13:01:59 OK 20241026095416_initial_model.sql (274.59ms)25872026/09/23 13:01:59 OK 20251210153512_drop_unused_gin_index.sql (17.18ms)25882026/09/23 13:01:59 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=190.980499ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25892026/09/23 13:01:59 OK 20251218171726_add_pins.sql (53.77ms)25902026/09/23 13:01:59 OK 20260628120000_add_object_size_and_stats.sql (37.76ms)25912026-09-23 13:01:59.471 UTC [52006] ERROR: relation "goose_db_version" does not exist at character 3625922026-09-23 13:01:59.471 UTC [52006] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25932026/09/23 13:01:59 OK 20260905000000_add_claims.sql (53.87ms)25942026/09/23 13:01:59 OK 20260920000000_drop_claims.sql (28.47ms)25952026/09/23 13:01:59 OK 20260923120000_add_pushes.sql (18.59ms)25962026/09/23 13:01:59 goose: successfully migrated database to version: 2026092312000025972026/09/23 13:01:59 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=395.37171ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25982026/09/23 13:01:59 OK 1_commit_pending_closure.sql (4.08ms)25992026/09/23 13:01:59 OK 2_object_stats_trigger.sql (721.67µs)26002026/09/23 13:01:59 OK 3_commit_push.sql (551.33µs)26012026/09/23 13:01:59 goose: up to current file version: 326022026/09/23 13:01:59 OK 20241026095416_initial_model.sql (321.16ms)26032026/09/23 13:01:59 OK 20251210153512_drop_unused_gin_index.sql (22.24ms)26042026/09/23 13:01:59 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=877.431365ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26052026/09/23 13:01:59 OK 20251218171726_add_pins.sql (59.81ms)26062026/09/23 13:02:00 OK 20260628120000_add_object_size_and_stats.sql (43.34ms)26072026/09/23 13:02:00 OK 20260905000000_add_claims.sql (121.86ms)26082026/09/23 13:02:00 OK 20260920000000_drop_claims.sql (83.78ms)26092026/09/23 13:02:00 OK 20260923120000_add_pushes.sql (36.73ms)26102026/09/23 13:02:00 goose: successfully migrated database to version: 2026092312000026112026/09/23 13:02:00 OK 1_commit_pending_closure.sql (1.65ms)26122026/09/23 13:02:00 OK 2_object_stats_trigger.sql (433.71µs)26132026/09/23 13:02:00 OK 3_commit_push.sql (392µs)26142026/09/23 13:02:00 goose: up to current file version: 32615=== NAME TestOrphanedObjectsGCStressTest2616 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2617 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion26182026/09/23 13:02:00 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.733381997s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26192026/09/23 13:02:01 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"26202026/09/23 13:02:01 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"26212026/09/23 13:02:02 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"26222026/09/23 13:02:02 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_closures26232026/09/23 13:02:02 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=212.181756ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26242026/09/23 13:02:02 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=413.894044ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26252026/09/23 13:02:03 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=802.446018ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26262026/09/23 13:02:04 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.515668524s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2627 orphaned_objects_gc_test.go:509: Stress test completed successfully:2628 orphaned_objects_gc_test.go:510: - Active objects preserved: 202629 orphaned_objects_gc_test.go:511: - Objects deleted: 2102630 orphaned_objects_gc_test.go:512: - Total GC'd: 2102631--- PASS: TestOrphanedObjectsGCStressTest (14.57s)2632--- PASS: TestClientErrorHandling (0.00s)2633 --- PASS: TestClientErrorHandling/InvalidStorePath (4.52s)2634 --- PASS: TestClientErrorHandling/InvalidAuthToken (5.33s)2635 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.91s)2636FAIL26372026-09-23 13:02:08.566 UTC [51480] LOG: received smart shutdown request26382026-09-23 13:02:08.570 UTC [51480] LOG: background worker "logical replication launcher" (PID 51490) exited with exit code 126392026-09-23 13:02:08.736 UTC [51485] LOG: shutting down26402026-09-23 13:02:08.736 UTC [51485] LOG: checkpoint starting: shutdown immediate26412026/09/23 13:02:15 ERROR failed to kill rustfs error="no such process"26422026-09-23 13:02:17.175 UTC [51485] LOG: checkpoint complete: wrote 12962 buffers (79.1%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 18 recycled; write=4.718 s, sync=3.376 s, total=8.439 s; sync files=21874, longest=0.017 s, average=0.001 s; distance=302640 kB, estimate=302640 kB; lsn=0/13F190D8, redo lsn=0/13F190D826432026-09-23 13:02:17.295 UTC [51480] LOG: database system is shut down26442026/09/23 13:02:18 ERROR failed to kill rustfs error="no such process"