niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #264
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestCaseHackSuffix8=== PAUSE TestCaseHackSuffix9=== RUN TestFilterOversizedClosures10=== PAUSE TestFilterOversizedClosures11=== RUN TestUploadMultipart_PartsInParallel12=== PAUSE TestUploadMultipart_PartsInParallel13=== RUN TestPartSizeForNAR14=== PAUSE TestPartSizeForNAR15=== RUN TestUploadMultipart_SupersededByPeer16=== PAUSE TestUploadMultipart_SupersededByPeer17=== RUN TestDumpPathCaseHackMatchesNix18--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)19=== RUN TestDumpPathCaseHackCollision20--- PASS: TestDumpPathCaseHackCollision (0.00s)21=== RUN TestDumpPathMatchesNix22=== PAUSE TestDumpPathMatchesNix23=== RUN TestDumpPathSingleFile24=== PAUSE TestDumpPathSingleFile25=== RUN TestDumpPathWriterError26=== PAUSE TestDumpPathWriterError27=== RUN TestEncodeNixBase3228=== PAUSE TestEncodeNixBase3229=== RUN TestEncodeNixBase32WithRealHash30=== PAUSE TestEncodeNixBase32WithRealHash31=== RUN TestConvertHashToNix3232=== PAUSE TestConvertHashToNix3233=== RUN TestGetStorePathHash34=== PAUSE TestGetStorePathHash35=== RUN TestPathInfoHashCompatibility36=== PAUSE TestPathInfoHashCompatibility37=== RUN TestParsePathInfoJSON38=== PAUSE TestParsePathInfoJSON39=== RUN TestParsePathInfoJSONMultiplePaths40=== PAUSE TestParsePathInfoJSONMultiplePaths41=== RUN TestPathInfoCACompatibility42=== PAUSE TestPathInfoCACompatibility43=== RUN TestRateLimiterFeedback44=== PAUSE TestRateLimiterFeedback45=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess47=== RUN TestResolveStorePath48=== PAUSE TestResolveStorePath49=== RUN TestDoWithRetry_BodyReplayedViaGetBody50=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody51=== RUN TestShellSplit52=== PAUSE TestShellSplit53=== RUN TestShellSplitErrors54=== PAUSE TestShellSplitErrors55=== RUN TestStreamPushReportsEveryPath56=== PAUSE TestStreamPushReportsEveryPath57=== RUN TestStreamPushBatchesUnderLoad58=== PAUSE TestStreamPushBatchesUnderLoad59=== RUN TestStreamPushIsolatesFailures60=== PAUSE TestStreamPushIsolatesFailures61=== RUN TestStreamPushGivesUpOnDeadServer62=== PAUSE TestStreamPushGivesUpOnDeadServer63=== RUN TestStreamPushRequestLine64=== PAUSE TestStreamPushRequestLine65=== RUN TestStreamPushReportsSignatures66=== PAUSE TestStreamPushReportsSignatures67=== RUN TestClientSignaturesByStorePath68=== PAUSE TestClientSignaturesByStorePath69=== RUN TestSetClientTLS70=== PAUSE TestSetClientTLS71=== RUN TestSetClientTLSDoesNotMutateDefaultTransport72=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport73=== RUN TestSetClientTLSErrors74=== PAUSE TestSetClientTLSErrors75=== RUN TestStaticToken76=== PAUSE TestStaticToken77=== RUN TestFileTokenReadsAndCaches78=== PAUSE TestFileTokenReadsAndCaches79=== RUN TestFileTokenMissing80=== PAUSE TestFileTokenMissing81=== RUN TestFileTokenEmpty82=== PAUSE TestFileTokenEmpty83=== RUN TestScriptTokenNoExpiryRerunsEveryCall84=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall85=== RUN TestScriptTokenCachesUntilRefresh86=== PAUSE TestScriptTokenCachesUntilRefresh87=== RUN TestScriptTokenEmptyToken88=== PAUSE TestScriptTokenEmptyToken89=== RUN TestScriptTokenBadJSON90=== PAUSE TestScriptTokenBadJSON91=== RUN TestScriptTokenScriptFails92=== PAUSE TestScriptTokenScriptFails93=== RUN TestScriptTokenEmptyCommand94=== PAUSE TestScriptTokenEmptyCommand95=== CONT TestDoServerRequestAttachesToken96=== CONT TestShellSplit97=== CONT TestEncodeNixBase32WithRealHash98=== CONT TestStaticToken99=== CONT TestFilterOversizedClosures100=== CONT TestParsePathInfoJSONMultiplePaths101=== CONT TestParsePathInfoJSON102=== RUN TestParsePathInfoJSON/Nix_format103=== CONT TestPathInfoHashCompatibility104=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)105=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)106=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths107=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths108=== CONT TestGetStorePathHash109=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths110=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths111=== RUN TestGetStorePathHash/valid_store_path112=== CONT TestPartSizeForNAR113=== RUN TestPartSizeForNAR/zero_stays_at_minimum114=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum115=== RUN TestPartSizeForNAR/small_stays_at_minimum116=== CONT TestDoWithRetry_BodyReplayedViaGetBody117=== CONT TestConvertHashToNix32118=== RUN TestConvertHashToNix32/SRI_format_to_Nix32119=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32120=== RUN TestConvertHashToNix32/already_Nix32_format121=== PAUSE TestConvertHashToNix32/already_Nix32_format122=== CONT TestResolveStorePath123=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess124=== CONT TestUploadMultipart_SupersededByPeer125=== CONT TestEncodeNixBase321262026/09/23 13:17:49 WARN Rate limiter enabled after throttle name=server-test rate=5127=== RUN TestEncodeNixBase32/test_string_hash128=== RUN TestUploadMultipart_SupersededByPeer/exists129=== CONT TestRateLimiterFeedback130=== PAUSE TestUploadMultipart_SupersededByPeer/exists131=== CONT TestSetClientTLSErrors132=== CONT TestDumpPathMatchesNix133=== CONT TestScriptTokenNoExpiryRerunsEveryCall134=== CONT TestFileTokenEmpty135=== CONT TestScriptTokenScriptFails136=== CONT TestFileTokenMissing137=== CONT TestScriptTokenEmptyCommand138=== CONT TestStreamPushRequestLine139--- PASS: TestShellSplit (0.00s)140--- PASS: TestEncodeNixBase32WithRealHash (0.00s)141=== CONT TestFileTokenReadsAndCaches142=== RUN TestFilterOversizedClosures/no_limit_keeps_everything143=== PAUSE TestParsePathInfoJSON/Nix_format144=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon145=== CONT TestPathInfoCACompatibility146=== PAUSE TestGetStorePathHash/valid_store_path147=== PAUSE TestPartSizeForNAR/small_stays_at_minimum148=== RUN TestConvertHashToNix32/invalid_format149=== CONT TestDumpPathWriterError150=== CONT TestDumpPathSingleFile151=== RUN TestRateLimiterFeedback/429_enables_limiter152=== RUN TestUploadMultipart_SupersededByPeer/missing153=== PAUSE TestEncodeNixBase32/test_string_hash154=== CONT TestUploadMultipart_PartsInParallel155--- PASS: TestStaticToken (0.00s)156=== CONT TestCaseHackSuffix157=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything158=== RUN TestParsePathInfoJSON/Lix_format159=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon160=== CONT TestSetClientTLSDoesNotMutateDefaultTransport161=== RUN TestGetStorePathHash/basename_without_hyphen_should_error162=== RUN TestPathInfoCACompatibility/null_ca_field163=== CONT TestSetClientTLS1642026/09/23 13:17:49 ERROR Upload failed error=boom count=1165=== PAUSE TestConvertHashToNix32/invalid_format166--- PASS: TestResolveStorePath (0.00s)167=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum168=== RUN TestEncodeNixBase32/empty_input169=== CONT TestStreamPushBatchesUnderLoad170=== CONT TestClientSignaturesByStorePath171--- PASS: TestScriptTokenEmptyCommand (0.00s)172--- PASS: TestFileTokenEmpty (0.00s)1732026/09/23 13:17:49 WARN Rate limiter enabled after throttle name=server-test rate=5174--- PASS: TestClientSignaturesByStorePath (0.00s)1752026/09/23 13:17:49 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:33039176=== PAUSE TestUploadMultipart_SupersededByPeer/missing177=== CONT TestStreamPushGivesUpOnDeadServer178=== CONT TestStreamPushReportsEveryPath179=== PAUSE TestRateLimiterFeedback/429_enables_limiter180=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped181=== PAUSE TestParsePathInfoJSON/Lix_format182=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI183=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error184=== PAUSE TestPathInfoCACompatibility/null_ca_field1852026/09/23 13:17:49 ERROR Upload failed error="connection refused" count=20186=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum1872026/09/23 13:17:49 ERROR Server seems unavailable, giving up on batch untried=17188=== PAUSE TestEncodeNixBase32/empty_input189=== RUN TestPathInfoCACompatibility/old_string_format_-_text190=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text191--- PASS: TestFileTokenMissing (0.00s)192=== RUN TestSetClientTLS/rejects_connection_without_client_cert193=== RUN TestRateLimiterFeedback/503_enables_limiter194=== PAUSE TestRateLimiterFeedback/503_enables_limiter195=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive196=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert197=== CONT TestScriptTokenBadJSON198=== RUN TestSetClientTLSErrors/missing_cert_file199=== PAUSE TestSetClientTLSErrors/missing_cert_file200=== RUN TestSetClientTLSErrors/missing_key_file201=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter202=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter203=== CONT TestStreamPushIsolatesFailures204=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter205=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter206=== RUN TestParsePathInfoJSON/empty_input207=== PAUSE TestParsePathInfoJSON/empty_input2082026/09/23 13:17:49 ERROR Upload failed error="bad path" count=3209=== RUN TestParsePathInfoJSON/whitespace_only210=== PAUSE TestParsePathInfoJSON/whitespace_only211=== RUN TestParsePathInfoJSON/invalid_JSON212=== PAUSE TestParsePathInfoJSON/invalid_JSON213=== CONT TestScriptTokenEmptyToken214=== CONT TestScriptTokenCachesUntilRefresh215=== CONT TestStreamPushReportsSignatures2162026/09/23 13:17:49 WARN Rate limiter backed off name=server-test rate=5217=== CONT TestShellSplitErrors2182026/09/23 13:17:49 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:33039219=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths220=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts221=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts222=== CONT TestConvertHashToNix32/invalid_format223=== CONT TestConvertHashToNix32/already_Nix32_format224=== RUN TestPartSizeForNAR/1_TiB225=== PAUSE TestPartSizeForNAR/1_TiB226=== CONT TestConvertHashToNix32/SRI_format_to_Nix32227=== CONT TestUploadMultipart_SupersededByPeer/exists2282026/09/23 13:17:49 ERROR Upload failed error=boom count=1229=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI230=== CONT TestRegisterUploadedObjectReusesConnections231=== CONT TestEncodeNixBase32/test_string_hash232=== CONT TestEncodeNixBase32/empty_input233=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512234=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512235=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA236=== PAUSE TestSetClientTLSErrors/missing_key_file237=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped238=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error239=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths240=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA241=== RUN TestSetClientTLS/preserves_debug_logging_transport242=== PAUSE TestSetClientTLS/preserves_debug_logging_transport243=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter244=== CONT TestRateLimiterFeedback/503_enables_limiter245=== RUN TestPartSizeForNAR/5_TiB_S3_max_object246=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object247=== RUN TestPartSizeForNAR/capped_at_5_GiB248=== PAUSE TestPartSizeForNAR/capped_at_5_GiB249=== CONT TestUploadMultipart_SupersededByPeer/missing2502026/09/23 13:17:49 WARN Rate limiter enabled after throttle name=server-test rate=52512026/09/23 13:17:49 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:33149252=== CONT TestParsePathInfoJSON/Nix_format253=== CONT TestParsePathInfoJSON/empty_input254=== CONT TestParsePathInfoJSON/whitespace_only255=== CONT TestParsePathInfoJSON/Lix_format256=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha5122572026/09/23 13:17:49 WARN Rate limiter backed off name=server-test rate=5258=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI259=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon260=== CONT TestSetClientTLS/rejects_connection_without_client_cert261=== CONT TestSetClientTLS/preserves_debug_logging_transport262=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA263=== CONT TestParsePathInfoJSON/invalid_JSON264=== CONT TestPartSizeForNAR/zero_stays_at_minimum265=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts266=== CONT TestPartSizeForNAR/capped_at_5_GiB267=== CONT TestPartSizeForNAR/5_TiB_S3_max_object268=== CONT TestPartSizeForNAR/1_TiB269=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum270=== CONT TestPartSizeForNAR/small_stays_at_minimum271=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)272=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter273=== CONT TestRateLimiterFeedback/429_enables_limiter274=== RUN TestSetClientTLSErrors/missing_ca_file275=== PAUSE TestSetClientTLSErrors/missing_ca_file276=== RUN TestSetClientTLSErrors/invalid_ca_file277=== PAUSE TestSetClientTLSErrors/invalid_ca_file278=== CONT TestSetClientTLSErrors/missing_cert_file279=== RUN TestFilterOversizedClosures/all_closures_skipped280=== PAUSE TestFilterOversizedClosures/all_closures_skipped281=== CONT TestFilterOversizedClosures/no_limit_keeps_everything282=== CONT TestSetClientTLSErrors/missing_ca_file283=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error284=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error285=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error286=== CONT TestGetStorePathHash/valid_store_path287=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive288=== RUN TestPathInfoCACompatibility/new_structured_format_-_text289=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text290=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method291=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method292=== CONT TestPathInfoCACompatibility/null_ca_field293=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error294=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error295=== CONT TestGetStorePathHash/basename_without_hyphen_should_error296=== CONT TestSetClientTLSErrors/invalid_ca_file297=== CONT TestSetClientTLSErrors/missing_key_file2982026/09/23 13:17:49 WARN Rate limiter enabled after throttle name=server-test rate=5299=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method300--- PASS: TestScriptTokenScriptFails (0.00s)3012026/09/23 13:17:49 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:35851302=== CONT TestFilterOversizedClosures/all_closures_skipped3032026/09/23 13:17:49 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50304=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3052026/09/23 13:17:50 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=2000306=== CONT TestPathInfoCACompatibility/old_string_format_-_text307=== CONT TestPathInfoCACompatibility/new_structured_format_-_text3082026/09/23 13:17:50 WARN Rate limiter backed off name=server-test rate=5309=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive310--- PASS: TestFileTokenReadsAndCaches (0.00s)311--- PASS: TestDoServerRequestAttachesToken (0.01s)312--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)313--- PASS: TestStreamPushReportsEveryPath (0.00s)314--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)315--- PASS: TestStreamPushIsolatesFailures (0.00s)316--- PASS: TestShellSplitErrors (0.00s)317--- PASS: TestConvertHashToNix32 (0.01s)318 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)319 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)320 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)321--- PASS: TestStreamPushReportsSignatures (0.00s)322--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)323--- PASS: TestEncodeNixBase32 (0.03s)324 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)325 --- PASS: TestEncodeNixBase32/empty_input (0.00s)326--- PASS: TestScriptTokenBadJSON (0.00s)327--- PASS: TestPartSizeForNAR (0.04s)328 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)329 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)330 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)331 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)332 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)333 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)334 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)335--- PASS: TestPathInfoHashCompatibility (0.03s)336 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)337 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)338 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)339 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)340--- PASS: TestScriptTokenEmptyToken (0.00s)341--- PASS: TestGetStorePathHash (0.04s)342 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)343 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (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: TestUploadMultipart_SupersededByPeer (0.03s)347 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)348 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)349--- PASS: TestFilterOversizedClosures (0.04s)350 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)351 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)352 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)353--- PASS: TestPathInfoCACompatibility (0.03s)354 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)355 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)356 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)357 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)358 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)359--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)360 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)361 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)362--- PASS: TestParsePathInfoJSON (0.03s)363 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)364 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)365 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)366 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)367 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)368--- PASS: TestRateLimiterFeedback (0.03s)369 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)370 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)371 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)372 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)373--- PASS: TestSetClientTLSErrors (0.04s)374 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)375 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)376 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)377 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)378--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)379--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)380--- PASS: TestStreamPushRequestLine (0.05s)3812026/09/23 13:17:50 http: TLS handshake error from 127.0.0.1:46046: remote error: tls: bad certificate382--- PASS: TestSetClientTLS (0.03s)383 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.02s)384 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.02s)385 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)386--- PASS: TestDumpPathSingleFile (0.06s)387--- PASS: TestCaseHackSuffix (0.06s)388--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)389--- PASS: TestDumpPathWriterError (0.07s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestDumpPathMatchesNix (0.12s)392--- PASS: TestUploadMultipart_PartsInParallel (0.65s)393--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)394PASS395Running server tests...396The files belonging to this database system will be owned by user "nixbld".397This user must also own the server process.398399The database cluster will be initialized with locale "C".400The default database encoding has accordingly been set to "SQL_ASCII".401The default text search configuration will be set to "english".402403Data page checksums are enabled.404405creating directory /build/postgres3201942654/data ... ok406creating subdirectories ... ok407selecting dynamic shared memory implementation ... posix408selecting default "max_connections" ... 100409selecting default "shared_buffers" ... 128MB410selecting default time zone ... UTC411creating configuration files ... ok412running bootstrap script ... ok413performing post-bootstrap initialization ... ok414syncing data to disk ... ok415416initdb: warning: enabling "trust" authentication for local connections417initdb: 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.418419Success. You can now start the database server using:420421 pg_ctl -D /build/postgres3201942654/data -l logfile start422423/build/postgres3201942654:5432 - no response4242026-09-23 13:17:51.770 UTC [130] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-09-23 13:17:51.771 UTC [130] LOG: listening on Unix socket "/build/postgres3201942654/.s.PGSQL.5432"4262026-09-23 13:17:51.777 UTC [137] LOG: database system was shut down at 2026-09-23 13:17:51 UTC4272026-09-23 13:17:51.780 UTC [130] LOG: database system is ready to accept connections428/build/postgres3201942654:5432 - accepting connections429{"timestamp":"2026-09-23T13:17:52.077112295Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"df005961-5176-4960-8142-f213cfd5aa91","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(399)"}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:17:52.271 UTC [564] ERROR: relation "goose_db_version" does not exist at character 364722026-09-23 13:17:52.271 UTC [564] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4732026/09/23 13:17:52 OK 20241026095416_initial_model.sql (6.81ms)4742026/09/23 13:17:52 OK 20251210153512_drop_unused_gin_index.sql (988.41µs)4752026/09/23 13:17:52 OK 20251218171726_add_pins.sql (2.09ms)4762026/09/23 13:17:52 OK 20260628120000_add_object_size_and_stats.sql (1.84ms)4772026/09/23 13:17:52 OK 20260905000000_add_claims.sql (3.38ms)4782026/09/23 13:17:52 OK 20260920000000_drop_claims.sql (1.6ms)4792026/09/23 13:17:52 OK 20260923120000_add_pushes.sql (998.75µs)4802026/09/23 13:17:52 goose: successfully migrated database to version: 202609231200004812026/09/23 13:17:52 OK 1_commit_pending_closure.sql (1.49ms)4822026/09/23 13:17:52 OK 2_object_stats_trigger.sql (804.07µs)4832026/09/23 13:17:52 OK 3_commit_push.sql (703.43µs)4842026/09/23 13:17:52 goose: up to current file version: 34852026/09/23 13:17:52 INFO lead: acquired remote=192.0.2.1:12344862026/09/23 13:17:52 INFO lead: released remote=192.0.2.1:12344872026/09/23 13:17:52 INFO lead: acquired remote=192.0.2.1:12344882026/09/23 13:17:52 INFO lead: released remote=192.0.2.1:1234489--- PASS: TestLeadIncumbentWinsAfterRestart (0.80s)490=== RUN TestLeadEndsOnShutdown491=== PAUSE TestLeadEndsOnShutdown492=== RUN TestGCAdvisoryLockBlocksConcurrentRun4932026-09-23 13:17:53.045 UTC [574] ERROR: relation "goose_db_version" does not exist at character 364942026-09-23 13:17:53.045 UTC [574] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4952026/09/23 13:17:53 OK 20241026095416_initial_model.sql (6.54ms)4962026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (2.05ms)4972026/09/23 13:17:53 OK 20251218171726_add_pins.sql (2.4ms)4982026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (2.65ms)4992026/09/23 13:17:53 OK 20260905000000_add_claims.sql (2.16ms)5002026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (1.34ms)5012026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (938.06µs)5022026/09/23 13:17:53 goose: successfully migrated database to version: 202609231200005032026/09/23 13:17:53 OK 1_commit_pending_closure.sql (1.31ms)5042026/09/23 13:17:53 OK 2_object_stats_trigger.sql (642.69µs)5052026/09/23 13:17:53 OK 3_commit_push.sql (629.41µs)5062026/09/23 13:17:53 goose: up to current file version: 3507--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.12s)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:17:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6222026/09/23 13:17:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6232026/09/23 13:17:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6242026/09/23 13:17:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6252026/09/23 13:17:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6262026/09/23 13:17:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6272026/09/23 13:17:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6282026/09/23 13:17:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6292026/09/23 13:17:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"630--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)631=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle632=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle633=== RUN TestProxyWriteTimeout634=== PAUSE TestProxyWriteTimeout635=== RUN TestIsValidUploadKey636=== PAUSE TestIsValidUploadKey637=== RUN TestUploadHandlersRejectInvalidKeys638=== PAUSE TestUploadHandlersRejectInvalidKeys639=== RUN TestUploadHandlersRejectOversizedBody640=== PAUSE TestUploadHandlersRejectOversizedBody641=== RUN TestService_cleanupPendingClosuresHandler642=== PAUSE TestService_cleanupPendingClosuresHandler643=== RUN TestService_createPendingClosureHandler644=== PAUSE TestService_createPendingClosureHandler645=== RUN TestService_verifyS3Integrity646=== PAUSE TestService_verifyS3Integrity647=== RUN TestCompleteMultipartUnregistered648=== PAUSE TestCompleteMultipartUnregistered649=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT650=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT651=== CONT TestService_AuthMiddleware652=== CONT TestProxyWriteTimeout653=== RUN TestProxyWriteTimeout/narinfo654=== PAUSE TestProxyWriteTimeout/narinfo655=== RUN TestProxyWriteTimeout/1_GiB_nar656=== PAUSE TestProxyWriteTimeout/1_GiB_nar657=== RUN TestProxyWriteTimeout/10_GiB_nar658=== PAUSE TestProxyWriteTimeout/10_GiB_nar659=== CONT TestCompleteMultipartUnregistered660=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT661=== CONT TestObjectStatsTrigger662=== CONT TestService_verifyS3Integrity663=== CONT TestService_createPendingClosureHandler664=== CONT TestService_cleanupPendingClosuresHandler665=== CONT TestUploadHandlersRejectOversizedBody666=== CONT TestUploadHandlersRejectInvalidKeys667=== CONT TestIsValidUploadKey668=== RUN TestIsValidUploadKey/narinfo669=== PAUSE TestIsValidUploadKey/narinfo670=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info671=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info672=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal673=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal674=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key675=== CONT TestMultipartCleanup676=== CONT TestServerTLSConfig677=== CONT TestService_NativeMTLS678=== CONT TestMetricsInventory679=== CONT TestNARDeduplicationMetadataUploadBug680=== CONT TestCreatePendingClosureRejectsOversizedNAR681=== CONT TestCacheConfigHandlerMaxNarSize682=== CONT TestGenerateLandingPage683=== CONT TestService_readinessHandler684=== CONT TestService_healthCheckHandler685=== CONT TestGracefulShutdownDrainsInflight686=== CONT TestGCTaskStore_Fail687=== RUN TestProxyWriteTimeout/unknown_size688=== RUN TestIsValidUploadKey/nar_zst689=== CONT TestGCBugBareHashReferences690=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key691=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key692=== RUN TestServerTLSConfig/no_client_CA6932026/09/23 13:17:53 INFO Received uploads request method=POST path=/api/pending_closures694--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)695--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)696=== PAUSE TestServerTLSConfig/no_client_CA697=== PAUSE TestIsValidUploadKey/nar_zst698=== CONT TestGCTaskStore_CompletedAllowsNewTask699=== CONT TestGCTaskStore_PhaseUpdates700=== PAUSE TestProxyWriteTimeout/unknown_size701=== RUN TestIsValidUploadKey/nar_xz702=== CONT TestGCTaskStore_GetReturnsLatest703=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key704--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)705--- PASS: TestGCTaskStore_Fail (0.00s)706=== CONT TestGCTaskStore_GetEmpty707--- PASS: TestGCTaskStore_GetEmpty (0.00s)708=== CONT TestGCTaskStore_ConflictDifferentParams709--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)710=== CONT TestGCMetrics711=== RUN TestServerTLSConfig/missing_CA_file712=== CONT TestGCTaskStore_StartNew713--- PASS: TestGenerateLandingPage (0.00s)714--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)715=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle716=== CONT TestGCTaskStore_DeduplicateSameParams717=== PAUSE TestServerTLSConfig/missing_CA_file718=== RUN TestServerTLSConfig/not_a_PEM_file719=== PAUSE TestServerTLSConfig/not_a_PEM_file720=== CONT TestSkippedUploadsHandler721=== CONT TestPresignedUploadRegisteredBeforeCommit722=== PAUSE TestIsValidUploadKey/nar_xz7232026/09/23 13:17:53 INFO Starting HTTP server address=127.0.0.1:43891724=== RUN TestIsValidUploadKey/nar_plain7252026/09/23 13:17:53 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000726--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)727--- PASS: TestGCTaskStore_StartNew (0.00s)728--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)729=== CONT TestParseSize730=== CONT TestService_Rustfstest7312026/09/23 13:17:53 INFO Shutdown signal received, draining in-flight requests timeout=10s732=== CONT TestReadRedirectNar733=== PAUSE TestIsValidUploadKey/nar_plain734--- PASS: TestParseSize (0.00s)735=== CONT TestCompletedNarNotReofferedAcrossClosures736=== RUN TestIsValidUploadKey/listing737=== PAUSE TestIsValidUploadKey/listing738=== RUN TestIsValidUploadKey/build_log739=== PAUSE TestIsValidUploadKey/build_log740=== RUN TestIsValidUploadKey/build_log_home-manager_file741=== PAUSE TestIsValidUploadKey/build_log_home-manager_file742=== RUN TestIsValidUploadKey/build_log_plus_in_name743=== PAUSE TestIsValidUploadKey/build_log_plus_in_name744=== RUN TestIsValidUploadKey/build_log_question_mark745=== PAUSE TestIsValidUploadKey/build_log_question_mark746=== RUN TestIsValidUploadKey/build_log_equals747=== PAUSE TestIsValidUploadKey/build_log_equals748=== RUN TestIsValidUploadKey/realisation749=== PAUSE TestIsValidUploadKey/realisation750=== RUN TestIsValidUploadKey/realisation_plus_in_output751=== PAUSE TestIsValidUploadKey/realisation_plus_in_output752=== RUN TestIsValidUploadKey/nix-cache-info753=== PAUSE TestIsValidUploadKey/nix-cache-info754=== RUN TestIsValidUploadKey/index.html755=== PAUSE TestIsValidUploadKey/index.html756=== RUN TestIsValidUploadKey/narinfo_key,_nar_type757=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type758=== RUN TestIsValidUploadKey/nar_key,_narinfo_type759=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type760=== RUN TestIsValidUploadKey/listing_key,_narinfo_type761=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type762=== RUN TestIsValidUploadKey/traversal763=== PAUSE TestIsValidUploadKey/traversal764=== RUN TestIsValidUploadKey/traversal_nar765=== PAUSE TestIsValidUploadKey/traversal_nar766=== RUN TestIsValidUploadKey/absolute767=== PAUSE TestIsValidUploadKey/absolute768=== RUN TestIsValidUploadKey/empty_key769=== PAUSE TestIsValidUploadKey/empty_key770=== RUN TestIsValidUploadKey/unknown_type771=== PAUSE TestIsValidUploadKey/unknown_type772=== CONT TestCompleteMultipartUpload_ErrorButObjectExists773--- PASS: TestSkippedUploadsHandler (0.01s)774=== CONT TestRedundantMultipartUpload7752026-09-23 13:17:53.510 UTC [636] ERROR: relation "goose_db_version" does not exist at character 367762026-09-23 13:17:53.510 UTC [636] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC777--- PASS: TestGracefulShutdownDrainsInflight (0.07s)778=== CONT TestPush_SignsNarinfosOfItsPendingObjects779=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure780=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure781=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart782=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart783=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts784=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts785=== CONT TestPush_RejectsBadRequests7862026-09-23 13:17:53.582 UTC [641] ERROR: relation "goose_db_version" does not exist at character 367872026-09-23 13:17:53.582 UTC [641] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7882026-09-23 13:17:53.583 UTC [642] ERROR: relation "goose_db_version" does not exist at character 367892026-09-23 13:17:53.583 UTC [642] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7902026-09-23 13:17:53.631 UTC [643] ERROR: relation "goose_db_version" does not exist at character 367912026-09-23 13:17:53.631 UTC [643] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7922026-09-23 13:17:53.633 UTC [644] ERROR: relation "goose_db_version" does not exist at character 367932026-09-23 13:17:53.633 UTC [644] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7942026/09/23 13:17:53 OK 20241026095416_initial_model.sql (26.5ms)7952026/09/23 13:17:53 OK 20241026095416_initial_model.sql (29.76ms)7962026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (5.88ms)7972026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (5.46ms)7982026/09/23 13:17:53 OK 20241026095416_initial_model.sql (84.97ms)7992026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (3.66ms)8002026/09/23 13:17:53 OK 20251218171726_add_pins.sql (6.63ms)8012026-09-23 13:17:53.661 UTC [647] ERROR: relation "goose_db_version" does not exist at character 368022026-09-23 13:17:53.661 UTC [647] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8032026/09/23 13:17:53 OK 20251218171726_add_pins.sql (8.24ms)8042026/09/23 13:17:53 OK 20241026095416_initial_model.sql (15.34ms)8052026/09/23 13:17:53 OK 20251218171726_add_pins.sql (11.91ms)8062026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (10.58ms)8072026-09-23 13:17:53.671 UTC [649] ERROR: relation "goose_db_version" does not exist at character 368082026-09-23 13:17:53.671 UTC [649] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8092026-09-23 13:17:53.672 UTC [650] ERROR: relation "goose_db_version" does not exist at character 368102026-09-23 13:17:53.672 UTC [650] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8112026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (12.23ms)8122026/09/23 13:17:53 OK 20241026095416_initial_model.sql (22.08ms)8132026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (5.27ms)8142026/09/23 13:17:53 OK 20260905000000_add_claims.sql (5.91ms)8152026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (2.86ms)8162026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (4.12ms)8172026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (10.88ms)8182026/09/23 13:17:53 OK 20251218171726_add_pins.sql (8.59ms)8192026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (4.61ms)8202026/09/23 13:17:53 goose: successfully migrated database to version: 202609231200008212026/09/23 13:17:53 OK 20260905000000_add_claims.sql (13.12ms)8222026/09/23 13:17:53 OK 20251218171726_add_pins.sql (8.2ms)8232026/09/23 13:17:53 OK 1_commit_pending_closure.sql (3.39ms)8242026-09-23 13:17:53.695 UTC [651] ERROR: relation "goose_db_version" does not exist at character 368252026-09-23 13:17:53.695 UTC [651] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8262026-09-23 13:17:53.699 UTC [652] ERROR: relation "goose_db_version" does not exist at character 368272026-09-23 13:17:53.699 UTC [652] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8282026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (15.69ms)8292026/09/23 13:17:53 OK 20260905000000_add_claims.sql (18.51ms)8302026/09/23 13:17:53 OK 2_object_stats_trigger.sql (15.05ms)8312026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (17.41ms)8322026/09/23 13:17:53 OK 20241026095416_initial_model.sql (22.66ms)8332026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (18.82ms)8342026/09/23 13:17:53 OK 20241026095416_initial_model.sql (24.11ms)8352026/09/23 13:17:53 OK 3_commit_push.sql (2.65ms)8362026/09/23 13:17:53 goose: up to current file version: 38372026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (2.56ms)8382026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (2.36ms)8392026/09/23 13:17:53 OK 20260905000000_add_claims.sql (9.51ms)8402026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (9.61ms)8412026/09/23 13:17:53 OK 20260905000000_add_claims.sql (6.23ms)8422026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (7.14ms)8432026/09/23 13:17:53 goose: successfully migrated database to version: 202609231200008442026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (5.8ms)8452026/09/23 13:17:53 OK 20251218171726_add_pins.sql (7.87ms)8462026/09/23 13:17:53 OK 20251218171726_add_pins.sql (9.19ms)8472026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (6.71ms)8482026/09/23 13:17:53 goose: successfully migrated database to version: 202609231200008492026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (6.95ms)8502026/09/23 13:17:53 OK 1_commit_pending_closure.sql (6.28ms)8512026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (6.27ms)8522026/09/23 13:17:53 goose: successfully migrated database to version: 202609231200008532026/09/23 13:17:53 OK 20241026095416_initial_model.sql (45.84ms)8542026-09-23 13:17:53.723 UTC [653] ERROR: relation "goose_db_version" does not exist at character 368552026-09-23 13:17:53.723 UTC [653] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8562026-09-23 13:17:53.723 UTC [654] ERROR: relation "goose_db_version" does not exist at character 368572026-09-23 13:17:53.723 UTC [654] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8582026/09/23 13:17:53 OK 2_object_stats_trigger.sql (3.39ms)8592026/09/23 13:17:53 OK 1_commit_pending_closure.sql (6.7ms)8602026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (6.99ms)8612026/09/23 13:17:53 goose: successfully migrated database to version: 202609231200008622026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (8.4ms)8632026/09/23 13:17:53 OK 2_object_stats_trigger.sql (2.73ms)8642026/09/23 13:17:53 OK 3_commit_push.sql (2.87ms)8652026/09/23 13:17:53 goose: up to current file version: 38662026/09/23 13:17:53 OK 1_commit_pending_closure.sql (4.37ms)8672026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (9.51ms)8682026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (6.13ms)8692026/09/23 13:17:53 OK 2_object_stats_trigger.sql (2.82ms)8702026/09/23 13:17:53 OK 1_commit_pending_closure.sql (4.77ms)8712026/09/23 13:17:53 OK 3_commit_push.sql (3.19ms)8722026/09/23 13:17:53 goose: up to current file version: 38732026/09/23 13:17:53 OK 20260905000000_add_claims.sql (6.04ms)8742026/09/23 13:17:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8752026/09/23 13:17:53 OK 2_object_stats_trigger.sql (2.33ms)8762026/09/23 13:17:53 OK 3_commit_push.sql (2.51ms)8772026/09/23 13:17:53 goose: up to current file version: 38782026/09/23 13:17:53 OK 20260905000000_add_claims.sql (6.55ms)8792026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (3.15ms)8802026/09/23 13:17:53 OK 3_commit_push.sql (2.26ms)8812026/09/23 13:17:53 goose: up to current file version: 38822026/09/23 13:17:53 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst883--- PASS: TestCompleteMultipartUnregistered (0.40s)884=== CONT TestPush_CommitFailsWhenSkippedKeyWasCollected8852026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (2.87ms)8862026-09-23 13:17:53.737 UTC [655] ERROR: relation "goose_db_version" does not exist at character 368872026-09-23 13:17:53.737 UTC [655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8882026/09/23 13:17:53 OK 20241026095416_initial_model.sql (28.66ms)8892026/09/23 13:17:53 OK 20241026095416_initial_model.sql (28.8ms)8902026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (16.52ms)8912026/09/23 13:17:53 goose: successfully migrated database to version: 202609231200008922026/09/23 13:17:53 INFO Received uploads request method=POST path=/api/pending_closures8932026/09/23 13:17:53 OK 20251218171726_add_pins.sql (22.32ms)8942026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (14.32ms)8952026/09/23 13:17:53 goose: successfully migrated database to version: 202609231200008962026/09/23 13:17:53 OK 20241026095416_initial_model.sql (18.85ms)8972026/09/23 13:17:53 OK 20241026095416_initial_model.sql (20.32ms)8982026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (8.41ms)8992026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (8.38ms)9002026/09/23 13:17:53 OK 1_commit_pending_closure.sql (4.56ms)9012026/09/23 13:17:53 OK 1_commit_pending_closure.sql (5.14ms)9022026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (2.96ms)9032026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (2.93ms)9042026-09-23 13:17:53.760 UTC [659] ERROR: relation "goose_db_version" does not exist at character 369052026-09-23 13:17:53.760 UTC [659] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9062026/09/23 13:17:53 OK 2_object_stats_trigger.sql (3.27ms)9072026/09/23 13:17:53 OK 2_object_stats_trigger.sql (3.25ms)9082026/09/23 13:17:53 OK 20251218171726_add_pins.sql (5.66ms)9092026/09/23 13:17:53 OK 3_commit_push.sql (2.53ms)9102026/09/23 13:17:53 goose: up to current file version: 39112026/09/23 13:17:53 OK 3_commit_push.sql (2.45ms)9122026/09/23 13:17:53 goose: up to current file version: 39132026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (10.76ms)9142026/09/23 13:17:53 OK 20251218171726_add_pins.sql (5.67ms)9152026/09/23 13:17:53 OK 20251218171726_add_pins.sql (8.62ms)9162026/09/23 13:17:53 OK 20251218171726_add_pins.sql (5.71ms)9172026-09-23 13:17:53.765 UTC [660] ERROR: relation "goose_db_version" does not exist at character 369182026-09-23 13:17:53.765 UTC [660] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9192026/09/23 13:17:53 OK 20241026095416_initial_model.sql (13.21ms)9202026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (5.3ms)9212026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (1.76ms)9222026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (4.14ms)9232026/09/23 13:17:53 OK 20260905000000_add_claims.sql (5.32ms)9242026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (4.77ms)9252026/09/23 13:17:53 OK 20260905000000_add_claims.sql (3.42ms)9262026/09/23 13:17:53 OK 20251218171726_add_pins.sql (2.93ms)9272026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (6.5ms)928--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.44s)929=== CONT TestPush_CompleteCommitsEveryRoot9302026/09/23 13:17:53 OK 20260905000000_add_claims.sql (3.25ms)9312026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (3.88ms)9322026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (2.26ms)9332026/09/23 13:17:53 OK 20260905000000_add_claims.sql (3.42ms)9342026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (2.77ms)9352026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (2.42ms)9362026/09/23 13:17:53 goose: successfully migrated database to version: 202609231200009372026/09/23 13:17:53 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"938--- PASS: TestService_AuthMiddleware (0.44s)939=== CONT TestPush_OverlappingRootsStoreOneRowPerKey9402026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (2.85ms)9412026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (3.83ms)9422026-09-23 13:17:53.777 UTC [662] ERROR: relation "goose_db_version" does not exist at character 369432026-09-23 13:17:53.777 UTC [662] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9442026/09/23 13:17:53 OK 20260905000000_add_claims.sql (5.36ms)9452026/09/23 13:17:53 goose: successfully migrated database to version: 202609231200009462026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (5.42ms)9472026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (2.35ms)9482026/09/23 13:17:53 goose: successfully migrated database to version: 202609231200009492026-09-23 13:17:53.777 UTC [663] ERROR: relation "goose_db_version" does not exist at character 369502026-09-23 13:17:53.777 UTC [663] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9512026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (2.27ms)9522026/09/23 13:17:53 goose: successfully migrated database to version: 202609231200009532026-09-23 13:17:53.779 UTC [665] ERROR: relation "goose_db_version" does not exist at character 369542026-09-23 13:17:53.779 UTC [665] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9552026/09/23 13:17:53 OK 1_commit_pending_closure.sql (3.9ms)9562026-09-23 13:17:53.780 UTC [667] ERROR: relation "goose_db_version" does not exist at character 369572026-09-23 13:17:53.780 UTC [667] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9582026-09-23 13:17:53.780 UTC [666] ERROR: relation "goose_db_version" does not exist at character 369592026-09-23 13:17:53.780 UTC [666] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9602026/09/23 13:17:53 OK 20260905000000_add_claims.sql (3.16ms)9612026/09/23 13:17:53 OK 1_commit_pending_closure.sql (2.76ms)9622026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (3.72ms)9632026/09/23 13:17:53 OK 2_object_stats_trigger.sql (1.44ms)9642026/09/23 13:17:53 OK 20241026095416_initial_model.sql (10.01ms)9652026/09/23 13:17:53 OK 1_commit_pending_closure.sql (4ms)9662026/09/23 13:17:53 OK 1_commit_pending_closure.sql (3.01ms)9672026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (2.1ms)9682026/09/23 13:17:53 OK 3_commit_push.sql (1.51ms)9692026/09/23 13:17:53 goose: up to current file version: 39702026/09/23 13:17:53 OK 2_object_stats_trigger.sql (2.06ms)9712026/09/23 13:17:53 OK 2_object_stats_trigger.sql (1.57ms)9722026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (2.74ms)9732026/09/23 13:17:53 goose: successfully migrated database to version: 202609231200009742026/09/23 13:17:53 OK 2_object_stats_trigger.sql (2.16ms)9752026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (2.25ms)9762026/09/23 13:17:53 OK 3_commit_push.sql (1.47ms)9772026-09-23 13:17:53.784 UTC [670] ERROR: relation "goose_db_version" does not exist at character 369782026-09-23 13:17:53.784 UTC [670] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9792026/09/23 13:17:53 goose: up to current file version: 39802026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (2.98ms)9812026/09/23 13:17:53 goose: successfully migrated database to version: 202609231200009822026-09-23 13:17:53.785 UTC [672] ERROR: relation "goose_db_version" does not exist at character 369832026-09-23 13:17:53.785 UTC [672] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9842026/09/23 13:17:53 OK 20241026095416_initial_model.sql (10.9ms)9852026-09-23 13:17:53.786 UTC [671] ERROR: relation "goose_db_version" does not exist at character 369862026-09-23 13:17:53.786 UTC [671] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9872026/09/23 13:17:53 OK 3_commit_push.sql (2.13ms)9882026/09/23 13:17:53 goose: up to current file version: 39892026/09/23 13:17:53 OK 3_commit_push.sql (2.97ms)9902026/09/23 13:17:53 goose: up to current file version: 39912026/09/23 13:17:53 OK 1_commit_pending_closure.sql (4.39ms)9922026/09/23 13:17:53 OK 20251218171726_add_pins.sql (4.1ms)9932026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (2.22ms)9942026/09/23 13:17:53 OK 1_commit_pending_closure.sql (3.57ms)9952026/09/23 13:17:53 OK 2_object_stats_trigger.sql (2.08ms)9962026-09-23 13:17:53.791 UTC [673] ERROR: relation "goose_db_version" does not exist at character 369972026-09-23 13:17:53.791 UTC [673] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9982026/09/23 13:17:53 OK 2_object_stats_trigger.sql (2.08ms)9992026/09/23 13:17:53 OK 3_commit_push.sql (1.8ms)10002026/09/23 13:17:53 goose: up to current file version: 310012026/09/23 13:17:53 OK 20251218171726_add_pins.sql (3.91ms)10022026/09/23 13:17:53 OK 3_commit_push.sql (1.65ms)10032026/09/23 13:17:53 goose: up to current file version: 310042026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (5.07ms)10052026/09/23 13:17:53 OK 20241026095416_initial_model.sql (11.36ms)10062026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (2.46ms)10072026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (5.57ms)10082026/09/23 13:17:53 OK 20241026095416_initial_model.sql (13.14ms)10092026/09/23 13:17:53 OK 20260905000000_add_claims.sql (5.31ms)10102026/09/23 13:17:53 OK 20241026095416_initial_model.sql (12.63ms)10112026/09/23 13:17:53 OK 20241026095416_initial_model.sql (11.43ms)10122026/09/23 13:17:53 OK 20251218171726_add_pins.sql (3.65ms)10132026/09/23 13:17:53 OK 20241026095416_initial_model.sql (12.39ms)10142026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (2.66ms)10152026/09/23 13:17:53 OK 20260905000000_add_claims.sql (3.68ms)10162026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (2.74ms)10172026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (1.97ms)10182026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (3.49ms)10192026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (2.24ms)10202026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (3.73ms)10212026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (3.2ms)10222026/09/23 13:17:53 goose: successfully migrated database to version: 2026092312000010232026/09/23 13:17:53 OK 20251218171726_add_pins.sql (3.8ms)10242026/09/23 13:17:53 OK 20251218171726_add_pins.sql (4.85ms)10252026/09/23 13:17:53 OK 20241026095416_initial_model.sql (14.08ms)10262026/09/23 13:17:53 OK 20241026095416_initial_model.sql (13.26ms)10272026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (5.81ms)10282026/09/23 13:17:53 OK 20241026095416_initial_model.sql (12.69ms)10292026/09/23 13:17:53 OK 20251218171726_add_pins.sql (4.43ms)10302026/09/23 13:17:53 OK 20251218171726_add_pins.sql (4.5ms)10312026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (2.74ms)10322026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (2.14ms)10332026/09/23 13:17:53 goose: successfully migrated database to version: 2026092312000010342026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (2.18ms)10352026/09/23 13:17:53 OK 1_commit_pending_closure.sql (2.5ms)10362026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (1.9ms)10372026/09/23 13:17:53 OK 20241026095416_initial_model.sql (10.84ms)10382026/09/23 13:17:53 INFO Received uploads request method=POST path=/api/pending_closures10392026/09/23 13:17:53 OK 2_object_stats_trigger.sql (1.86ms)10402026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (4.54ms)10412026/09/23 13:17:53 OK 20260905000000_add_claims.sql (4.09ms)10422026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (3.97ms)10432026/09/23 13:17:53 OK 1_commit_pending_closure.sql (2.95ms)10442026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (2.04ms)10452026/09/23 13:17:53 OK 20251218171726_add_pins.sql (3.04ms)10462026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (5.42ms)10472026/09/23 13:17:53 OK 3_commit_push.sql (2.01ms)10482026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (5.07ms)10492026/09/23 13:17:53 OK 20251218171726_add_pins.sql (4.03ms)10502026/09/23 13:17:53 OK 20251218171726_add_pins.sql (3.97ms)10512026/09/23 13:17:53 goose: up to current file version: 310522026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (2.64ms)10532026/09/23 13:17:53 OK 20260905000000_add_claims.sql (3.01ms)10542026/09/23 13:17:53 OK 2_object_stats_trigger.sql (2.05ms)10552026/09/23 13:17:53 OK 20251218171726_add_pins.sql (3.19ms)10562026/09/23 13:17:53 OK 20260905000000_add_claims.sql (4.36ms)10572026/09/23 13:17:53 OK 3_commit_push.sql (10.06ms)10582026/09/23 13:17:53 goose: up to current file version: 310592026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (12.06ms)10602026/09/23 13:17:53 OK 20260905000000_add_claims.sql (11.97ms)10612026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (10.59ms)10622026/09/23 13:17:53 goose: successfully migrated database to version: 2026092312000010632026/09/23 13:17:53 OK 20260905000000_add_claims.sql (11.28ms)10642026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (10.93ms)10652026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (13.51ms)10662026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (13.43ms)10672026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (11.34ms)10682026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (11.95ms)10692026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (2.75ms)10702026/09/23 13:17:53 goose: successfully migrated database to version: 2026092312000010712026/09/23 13:17:53 OK 1_commit_pending_closure.sql (3ms)10722026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (3.62ms)10732026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (4.03ms)10742026/09/23 13:17:53 OK 20260905000000_add_claims.sql (4.36ms)10752026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (2.27ms)10762026/09/23 13:17:53 goose: successfully migrated database to version: 2026092312000010772026/09/23 13:17:53 OK 20260905000000_add_claims.sql (3.99ms)10782026/09/23 13:17:53 OK 1_commit_pending_closure.sql (2.79ms)10792026/09/23 13:17:53 OK 20260905000000_add_claims.sql (4.12ms)10802026/09/23 13:17:53 OK 20260905000000_add_claims.sql (4.07ms)10812026/09/23 13:17:53 OK 2_object_stats_trigger.sql (2.7ms)10822026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (2.49ms)10832026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (3.19ms)10842026/09/23 13:17:53 goose: successfully migrated database to version: 2026092312000010852026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (3.12ms)10862026/09/23 13:17:53 goose: successfully migrated database to version: 2026092312000010872026/09/23 13:17:53 OK 3_commit_push.sql (2ms)10882026/09/23 13:17:53 goose: up to current file version: 310892026/09/23 13:17:53 OK 1_commit_pending_closure.sql (3.28ms)10902026/09/23 13:17:53 OK 2_object_stats_trigger.sql (2.24ms)10912026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (2.84ms)10922026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (3.15ms)10932026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (2.63ms)10942026/09/23 13:17:53 goose: successfully migrated database to version: 2026092312000010952026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (3.02ms)10962026/09/23 13:17:53 OK 3_commit_push.sql (1.47ms)10972026/09/23 13:17:53 goose: up to current file version: 310982026/09/23 13:17:53 OK 1_commit_pending_closure.sql (2.76ms)10992026/09/23 13:17:53 OK 1_commit_pending_closure.sql (2.88ms)11002026/09/23 13:17:53 OK 2_object_stats_trigger.sql (1.58ms)11012026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (1.79ms)11022026/09/23 13:17:53 goose: successfully migrated database to version: 2026092312000011032026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (2.31ms)11042026/09/23 13:17:53 goose: successfully migrated database to version: 2026092312000011052026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (2.65ms)11062026/09/23 13:17:53 goose: successfully migrated database to version: 2026092312000011072026/09/23 13:17:53 OK 1_commit_pending_closure.sql (2.5ms)11082026/09/23 13:17:53 OK 2_object_stats_trigger.sql (2.72ms)11092026/09/23 13:17:53 OK 3_commit_push.sql (2.54ms)11102026/09/23 13:17:53 goose: up to current file version: 311112026/09/23 13:17:53 OK 2_object_stats_trigger.sql (2.62ms)11122026/09/23 13:17:53 OK 1_commit_pending_closure.sql (2.88ms)11132026/09/23 13:17:53 OK 1_commit_pending_closure.sql (2.75ms)11142026/09/23 13:17:53 OK 3_commit_push.sql (1.92ms)11152026/09/23 13:17:53 goose: up to current file version: 311162026/09/23 13:17:53 OK 1_commit_pending_closure.sql (2.97ms)11172026/09/23 13:17:53 OK 3_commit_push.sql (1.69ms)11182026/09/23 13:17:53 goose: up to current file version: 311192026/09/23 13:17:53 OK 2_object_stats_trigger.sql (2.55ms)11202026/09/23 13:17:53 OK 2_object_stats_trigger.sql (1.77ms)11212026/09/23 13:17:53 OK 2_object_stats_trigger.sql (1.72ms)11222026/09/23 13:17:53 OK 2_object_stats_trigger.sql (2.29ms)11232026/09/23 13:17:53 OK 3_commit_push.sql (2.06ms)11242026/09/23 13:17:53 goose: up to current file version: 311252026/09/23 13:17:53 OK 3_commit_push.sql (1.77ms)11262026/09/23 13:17:53 goose: up to current file version: 311272026/09/23 13:17:53 OK 3_commit_push.sql (1.72ms)11282026/09/23 13:17:53 goose: up to current file version: 311292026/09/23 13:17:53 OK 3_commit_push.sql (1.6ms)11302026/09/23 13:17:53 goose: up to current file version: 311312026-09-23 13:17:53.856 UTC [676] ERROR: relation "goose_db_version" does not exist at character 3611322026-09-23 13:17:53.856 UTC [676] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11332026/09/23 13:17:53 OK 20241026095416_initial_model.sql (6.96ms)11342026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (993.15µs)11352026-09-23 13:17:53.873 UTC [677] ERROR: relation "goose_db_version" does not exist at character 3611362026-09-23 13:17:53.873 UTC [677] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11372026/09/23 13:17:53 OK 20251218171726_add_pins.sql (2.2ms)11382026-09-23 13:17:53.876 UTC [679] ERROR: relation "goose_db_version" does not exist at character 3611392026-09-23 13:17:53.876 UTC [679] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11402026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (3.09ms)11412026/09/23 13:17:53 OK 20260905000000_add_claims.sql (2.99ms)11422026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (1.86ms)11432026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (1.92ms)11442026/09/23 13:17:53 goose: successfully migrated database to version: 2026092312000011452026/09/23 13:17:53 OK 20241026095416_initial_model.sql (8.32ms)1146=== NAME TestNARDeduplicationMetadataUploadBug1147 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3757079813/001/store/4v6sq8yp8h7cvcx51f7qr0sldjaappbm-file1.txt11482026/09/23 13:17:53 OK 1_commit_pending_closure.sql (1.82ms)11492026/09/23 13:17:53 OK 2_object_stats_trigger.sql (1.25ms)11502026/09/23 13:17:53 OK 20241026095416_initial_model.sql (6.98ms)11512026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (2ms)11522026/09/23 13:17:53 OK 3_commit_push.sql (699.38µs)11532026/09/23 13:17:53 goose: up to current file version: 31154--- PASS: TestMetricsInventory (0.55s)1155=== CONT TestReadRedirectUsesPublicS3URL11562026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (970.58µs)11572026/09/23 13:17:53 OK 20251218171726_add_pins.sql (2.16ms)11582026/09/23 13:17:53 OK 20251218171726_add_pins.sql (2.07ms)11592026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (2.39ms)11602026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (2.21ms)11612026/09/23 13:17:53 OK 20260905000000_add_claims.sql (2.27ms)11622026/09/23 13:17:53 OK 20260905000000_add_claims.sql (2.16ms)11632026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (1.56ms)11642026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (1.59ms)11652026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (2.03ms)11662026/09/23 13:17:53 goose: successfully migrated database to version: 2026092312000011672026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (2.39ms)11682026/09/23 13:17:53 goose: successfully migrated database to version: 2026092312000011692026/09/23 13:17:53 OK 1_commit_pending_closure.sql (1.47ms)11702026/09/23 13:17:53 OK 1_commit_pending_closure.sql (1.83ms)11712026/09/23 13:17:53 OK 2_object_stats_trigger.sql (1.6ms)11722026/09/23 13:17:53 OK 2_object_stats_trigger.sql (1.8ms)11732026/09/23 13:17:53 OK 3_commit_push.sql (1.2ms)11742026/09/23 13:17:53 goose: up to current file version: 311752026/09/23 13:17:53 OK 3_commit_push.sql (635.18µs)11762026/09/23 13:17:53 goose: up to current file version: 31177--- PASS: TestObjectStatsTrigger (0.58s)1178=== CONT TestReadProxyRangeRequest11792026/09/23 13:17:53 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11802026/09/23 13:17:53 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1181--- PASS: TestService_NativeMTLS (0.58s)1182=== CONT TestReadRedirectKeepsNarinfoProxied11832026/09/23 13:17:53 INFO Received uploads request method=POST path=/api/pending_closures11842026/09/23 13:17:53 INFO Received uploads request method=POST path=/api/pending_closures11852026/09/23 13:17:53 INFO Received uploads request method=POST path=/api/pending_closures11862026/09/23 13:17:53 INFO Received uploads request method=POST path=/api/pending_closures11872026/09/23 13:17:53 INFO Received uploads request method=POST path=/api/pending_closures11882026/09/23 13:17:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11892026/09/23 13:17:53 INFO Uploading 4v6sq8yp8h7cvcx51f7qr0sldjaappbm-file1.txt (160B)11902026/09/23 13:17:53 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11912026/09/23 13:17:53 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11922026/09/23 13:17:53 WARN Failed to register uploaded object key=4v6sq8yp8h7cvcx51f7qr0sldjaappbm.ls error="server returned 404: 404 page not found\n"11932026/09/23 13:17:53 INFO Signed narinfos id=1 count=111942026/09/23 13:17:53 INFO Uploading 1 narinfos11952026-09-23 13:17:53.990 UTC [737] ERROR: relation "goose_db_version" does not exist at character 3611962026-09-23 13:17:53.990 UTC [737] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11972026/09/23 13:17:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11982026/09/23 13:17:53 WARN Failed to register uploaded object key=4v6sq8yp8h7cvcx51f7qr0sldjaappbm.narinfo error="server returned 404: 404 page not found\n"11992026/09/23 13:17:53 INFO Completed upload id=112002026/09/23 13:17:53 INFO Upload complete. (72ms)12012026/09/23 13:17:53 INFO Received cleanup request method=DELETE path=/api/pending_closures1202=== NAME TestNARDeduplicationMetadataUploadBug1203 metadata_upload_test.go:54: Retrieved narinfo from S3:1204 StorePath: /build/TestNARDeduplicationMetadataUploadBug3757079813/001/store/4v6sq8yp8h7cvcx51f7qr0sldjaappbm-file1.txt1205 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1206 Compression: zstd1207 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1208 NarSize: 1601209 References: 1210 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf12112026-09-23 13:17:54.000 UTC [738] ERROR: relation "goose_db_version" does not exist at character 3612122026-09-23 13:17:54.000 UTC [738] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1213 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1214 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1215 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12162026/09/23 13:17:54 OK 20241026095416_initial_model.sql (9.72ms)12172026/09/23 13:17:54 INFO Aborted multipart uploads count=012182026/09/23 13:17:54 OK 20251210153512_drop_unused_gin_index.sql (1.38ms)12192026/09/23 13:17:54 INFO Received uploads request method=POST path=/api/pending_closures12202026/09/23 13:17:54 OK 20251218171726_add_pins.sql (2.57ms)12212026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (2.97ms)12222026/09/23 13:17:54 OK 20241026095416_initial_model.sql (6.97ms)12232026/09/23 13:17:54 OK 20251210153512_drop_unused_gin_index.sql (1ms)12242026/09/23 13:17:54 OK 20260905000000_add_claims.sql (2.13ms)12252026/09/23 13:17:54 OK 20251218171726_add_pins.sql (1.99ms)12262026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (1.82ms)12272026/09/23 13:17:54 INFO Received cleanup request method=DELETE path=/api/pending_closures12282026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (1.85ms)12292026/09/23 13:17:54 goose: successfully migrated database to version: 2026092312000012302026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (2.69ms)12312026-09-23 13:17:54.019 UTC [740] ERROR: relation "goose_db_version" does not exist at character 3612322026-09-23 13:17:54.019 UTC [740] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12332026/09/23 13:17:54 INFO Aborted multipart uploads count=112342026/09/23 13:17:54 OK 1_commit_pending_closure.sql (2.05ms)12352026/09/23 13:17:54 OK 20260905000000_add_claims.sql (2.5ms)12362026/09/23 13:17:54 OK 2_object_stats_trigger.sql (1.24ms)12372026/09/23 13:17:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12382026/09/23 13:17:54 OK 3_commit_push.sql (677.37µs)12392026/09/23 13:17:54 goose: up to current file version: 312402026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (1.62ms)12412026-09-23 13:17:54.023 UTC [647] ERROR: Closure does not exist: id=112422026-09-23 13:17:54.023 UTC [647] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE12432026-09-23 13:17:54.023 UTC [647] STATEMENT: -- name: CommitPendingClosure :exec1244 SELECT commit_pending_closure($1::bigint)1245 1246--- PASS: TestService_cleanupPendingClosuresHandler (0.68s)1247=== CONT TestClientIntegration12482026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (1.25ms)12492026/09/23 13:17:54 goose: successfully migrated database to version: 202609231200001250--- PASS: TestService_healthCheckHandler (0.67s)1251=== CONT TestLeadEndsOnShutdown12522026/09/23 13:17:54 OK 1_commit_pending_closure.sql (2.1ms)12532026/09/23 13:17:54 OK 2_object_stats_trigger.sql (1.48ms)12542026/09/23 13:17:54 OK 3_commit_push.sql (988.68µs)12552026/09/23 13:17:54 goose: up to current file version: 312562026/09/23 13:17:54 OK 20241026095416_initial_model.sql (7.05ms)12572026/09/23 13:17:54 OK 20251210153512_drop_unused_gin_index.sql (1.03ms)12582026/09/23 13:17:54 OK 20251218171726_add_pins.sql (1.99ms)12592026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (2.53ms)12602026/09/23 13:17:54 OK 20260905000000_add_claims.sql (4.16ms)1261=== NAME TestNARDeduplicationMetadataUploadBug1262 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3757079813/001/store/mhric4fjwk6dfkqx9p4n7jadlyrwp1pj-file2.txt12632026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (2.42ms)12642026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (2.84ms)12652026/09/23 13:17:54 goose: successfully migrated database to version: 2026092312000012662026/09/23 13:17:54 OK 1_commit_pending_closure.sql (2.69ms)12672026/09/23 13:17:54 OK 2_object_stats_trigger.sql (1.64ms)12682026/09/23 13:17:54 OK 3_commit_push.sql (1.74ms)12692026/09/23 13:17:54 goose: up to current file version: 312702026/09/23 13:17:54 INFO Aborted multipart uploads count=012712026/09/23 13:17:54 WARN Force mode enabled - objects will be deleted immediately without grace period12722026/09/23 13:17:54 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012732026/09/23 13:17:54 INFO Vacuumed table table=pending_closures12742026/09/23 13:17:54 INFO Received cleanup request method=DELETE path=/api/pending_closures12752026/09/23 13:17:54 INFO Vacuumed table table=pending_objects12762026/09/23 13:17:54 INFO Vacuumed table table=multipart_uploads12772026/09/23 13:17:54 INFO Vacuumed table table=closures12782026/09/23 13:17:54 INFO Vacuumed table table=objects12792026/09/23 13:17:54 INFO Aborted multipart uploads count=112802026/09/23 13:17:54 INFO Received uploads request method=POST path=/api/pending_closures1281--- PASS: TestGCMetrics (0.71s)1282=== CONT TestLeadElectsOneAndHandsOver1283--- PASS: TestMultipartCleanup (0.74s)1284=== CONT TestResolveDBConnectionString1285=== RUN TestResolveDBConnectionString/flag_wins1286=== PAUSE TestResolveDBConnectionString/flag_wins1287=== RUN TestResolveDBConnectionString/file_when_flag_empty1288=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1289=== RUN TestResolveDBConnectionString/missing_file_is_an_error1290=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1291=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1292=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1293=== RUN TestResolveDBConnectionString/nothing_configured1294=== PAUSE TestResolveDBConnectionString/nothing_configured1295=== CONT TestClientFallsBackToClosures12962026/09/23 13:17:54 WARN readiness check failed error="closed pool"1297--- PASS: TestService_readinessHandler (0.65s)1298=== CONT TestClientPushesUseOnePush12992026/09/23 13:17:54 INFO Received uploads request method=POST path=/api/pending_closures13002026-09-23 13:17:54.111 UTC [804] ERROR: relation "goose_db_version" does not exist at character 3613012026-09-23 13:17:54.111 UTC [804] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13022026/09/23 13:17:54 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13032026-09-23 13:17:54.122 UTC [806] ERROR: relation "goose_db_version" does not exist at character 3613042026-09-23 13:17:54.122 UTC [806] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13052026/09/23 13:17:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13062026/09/23 13:17:54 WARN Failed to register uploaded object key=mhric4fjwk6dfkqx9p4n7jadlyrwp1pj.ls error="server returned 404: 404 page not found\n"13072026/09/23 13:17:54 INFO Signed narinfos id=2 count=113082026/09/23 13:17:54 INFO Uploading 1 narinfos13092026/09/23 13:17:54 OK 20241026095416_initial_model.sql (9.81ms)13102026/09/23 13:17:54 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13112026/09/23 13:17:54 WARN Failed to register uploaded object key=mhric4fjwk6dfkqx9p4n7jadlyrwp1pj.narinfo error="server returned 404: 404 page not found\n"13122026/09/23 13:17:54 OK 20251210153512_drop_unused_gin_index.sql (2.03ms)13132026/09/23 13:17:54 INFO Completed upload id=213142026/09/23 13:17:54 INFO Upload complete. (53ms)1315=== NAME TestNARDeduplicationMetadataUploadBug1316 metadata_upload_test.go:76: Retrieved narinfo from S3:1317 StorePath: /build/TestNARDeduplicationMetadataUploadBug3757079813/001/store/mhric4fjwk6dfkqx9p4n7jadlyrwp1pj-file2.txt1318 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1319 Compression: zstd1320 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf13212026/09/23 13:17:54 INFO Received uploads request method=POST path=/api/pending_closures1322 NarSize: 1601323 References: 1324 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf13252026/09/23 13:17:54 OK 20251218171726_add_pins.sql (3.52ms)1326 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1327 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1328 {"version":1,"root":{"type":"regular","size":44}}13292026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (4.62ms)13302026/09/23 13:17:54 OK 20241026095416_initial_model.sql (10.03ms)13312026/09/23 13:17:54 OK 20251210153512_drop_unused_gin_index.sql (2.63ms)13322026/09/23 13:17:54 OK 20260905000000_add_claims.sql (3.85ms)1333--- PASS: TestNARDeduplicationMetadataUploadBug (0.80s)1334=== CONT TestPinProtectsFromGC13352026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (2.7ms)13362026/09/23 13:17:54 OK 20251218171726_add_pins.sql (3.01ms)13372026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (1.95ms)13382026/09/23 13:17:54 goose: successfully migrated database to version: 2026092312000013392026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (3.61ms)13402026/09/23 13:17:54 OK 1_commit_pending_closure.sql (2.73ms)13412026/09/23 13:17:54 OK 2_object_stats_trigger.sql (1.56ms)13422026/09/23 13:17:54 OK 20260905000000_add_claims.sql (3.99ms)13432026/09/23 13:17:54 OK 3_commit_push.sql (2.12ms)13442026/09/23 13:17:54 goose: up to current file version: 313452026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (3.66ms)13462026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (3.13ms)13472026/09/23 13:17:54 goose: successfully migrated database to version: 2026092312000013482026/09/23 13:17:54 OK 1_commit_pending_closure.sql (3.27ms)13492026/09/23 13:17:54 OK 2_object_stats_trigger.sql (2.15ms)13502026/09/23 13:17:54 OK 3_commit_push.sql (1.8ms)13512026/09/23 13:17:54 goose: up to current file version: 313522026-09-23 13:17:54.174 UTC [809] ERROR: relation "goose_db_version" does not exist at character 3613532026-09-23 13:17:54.174 UTC [809] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13542026-09-23 13:17:54.179 UTC [810] ERROR: relation "goose_db_version" does not exist at character 3613552026-09-23 13:17:54.179 UTC [810] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13562026/09/23 13:17:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13572026/09/23 13:17:54 OK 20241026095416_initial_model.sql (8.51ms)13582026/09/23 13:17:54 OK 20251210153512_drop_unused_gin_index.sql (1.72ms)13592026/09/23 13:17:54 OK 20241026095416_initial_model.sql (7.74ms)13602026/09/23 13:17:54 OK 20251218171726_add_pins.sql (2.25ms)1361--- PASS: TestService_Rustfstest (0.74s)1362=== CONT TestClientSharedPathCommittedMidPush13632026/09/23 13:17:54 OK 20251210153512_drop_unused_gin_index.sql (1.82ms)13642026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (3.13ms)13652026/09/23 13:17:54 OK 20251218171726_add_pins.sql (2.9ms)13662026-09-23 13:17:54.198 UTC [811] ERROR: relation "goose_db_version" does not exist at character 3613672026-09-23 13:17:54.198 UTC [811] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13682026/09/23 13:17:54 OK 20260905000000_add_claims.sql (3.05ms)13692026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (3.25ms)13702026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (2.41ms)13712026/09/23 13:17:54 OK 20260905000000_add_claims.sql (3.29ms)13722026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (2.47ms)13732026/09/23 13:17:54 goose: successfully migrated database to version: 2026092312000013742026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (1.98ms)13752026/09/23 13:17:54 OK 1_commit_pending_closure.sql (1.79ms)13762026/09/23 13:17:54 OK 2_object_stats_trigger.sql (1.54ms)13772026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (3.03ms)13782026/09/23 13:17:54 goose: successfully migrated database to version: 2026092312000013792026/09/23 13:17:54 OK 3_commit_push.sql (1.59ms)13802026/09/23 13:17:54 goose: up to current file version: 313812026/09/23 13:17:54 OK 1_commit_pending_closure.sql (2.04ms)13822026/09/23 13:17:54 OK 20241026095416_initial_model.sql (15.54ms)13832026/09/23 13:17:54 OK 2_object_stats_trigger.sql (10.26ms)13842026/09/23 13:17:54 OK 20251210153512_drop_unused_gin_index.sql (3.95ms)13852026/09/23 13:17:54 OK 3_commit_push.sql (2.29ms)13862026/09/23 13:17:54 goose: up to current file version: 313872026/09/23 13:17:54 OK 20251218171726_add_pins.sql (2.38ms)13882026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (3.36ms)1389--- PASS: TestReadRedirectNar (0.78s)1390=== CONT TestClientWithDependencies13912026/09/23 13:17:54 OK 20260905000000_add_claims.sql (2.74ms)13922026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (2.46ms)13932026-09-23 13:17:54.235 UTC [814] ERROR: relation "goose_db_version" does not exist at character 3613942026-09-23 13:17:54.235 UTC [814] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13952026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (2.05ms)13962026/09/23 13:17:54 goose: successfully migrated database to version: 2026092312000013972026/09/23 13:17:54 OK 1_commit_pending_closure.sql (2.07ms)13982026/09/23 13:17:54 OK 2_object_stats_trigger.sql (3.23ms)13992026/09/23 13:17:54 OK 3_commit_push.sql (1.61ms)14002026/09/23 13:17:54 goose: up to current file version: 314012026/09/23 13:17:54 INFO Received uploads request method=POST path=/api/pending_closures14022026/09/23 13:17:54 OK 20241026095416_initial_model.sql (10ms)14032026/09/23 13:17:54 OK 20251210153512_drop_unused_gin_index.sql (2.12ms)14042026/09/23 13:17:54 OK 20251218171726_add_pins.sql (2.84ms)14052026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (3.74ms)14062026/09/23 13:17:54 OK 20260905000000_add_claims.sql (3.53ms)14072026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (2.31ms)14082026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (3.62ms)14092026/09/23 13:17:54 goose: successfully migrated database to version: 2026092312000014102026/09/23 13:17:54 OK 1_commit_pending_closure.sql (2.33ms)14112026/09/23 13:17:54 OK 2_object_stats_trigger.sql (815.6µs)14122026/09/23 13:17:54 OK 3_commit_push.sql (721.61µs)14132026/09/23 13:17:54 goose: up to current file version: 31414=== RUN TestPush_RejectsBadRequests/bad_root1415=== PAUSE TestPush_RejectsBadRequests/bad_root1416=== RUN TestPush_RejectsBadRequests/root_not_in_objects1417=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1418=== RUN TestPush_RejectsBadRequests/no_roots1419=== PAUSE TestPush_RejectsBadRequests/no_roots1420=== RUN TestPush_RejectsBadRequests/no_objects1421=== PAUSE TestPush_RejectsBadRequests/no_objects1422=== CONT TestClientMultipleUploads14232026-09-23 13:17:54.282 UTC [817] ERROR: relation "goose_db_version" does not exist at character 3614242026-09-23 13:17:54.282 UTC [817] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14252026/09/23 13:17:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14262026/09/23 13:17:54 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Nzk0MTIyNzctOGU0MC00MTUzLWI4MmYtNTU3ZmE3ODI1NTc3LjA4MWFhNGZiLTYwOWUtNGRkYS1hOGQwLTY2Yjc3YmE3OGQ5NHgxNzkwMTY5NDc0MjYwMDUxNDQ314272026/09/23 13:17:54 OK 20241026095416_initial_model.sql (8.18ms)14282026/09/23 13:17:54 OK 20251210153512_drop_unused_gin_index.sql (2.45ms)14292026/09/23 13:17:54 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Nzk0MTIyNzctOGU0MC00MTUzLWI4MmYtNTU3ZmE3ODI1NTc3LjA4MWFhNGZiLTYwOWUtNGRkYS1hOGQwLTY2Yjc3YmE3OGQ5NHgxNzkwMTY5NDc0MjYwMDUxNDQ3 parts=11430--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.85s)1431=== CONT TestReadProxyNarinfoAlreadyDecompressed14322026/09/23 13:17:54 OK 20251218171726_add_pins.sql (2.46ms)14332026/09/23 13:17:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14342026/09/23 13:17:54 INFO Received uploads request method=POST path=/api/pending_closures14352026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (3.51ms)14362026/09/23 13:17:54 OK 20260905000000_add_claims.sql (2.88ms)14372026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (2.19ms)14382026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (1.82ms)14392026/09/23 13:17:54 goose: successfully migrated database to version: 2026092312000014402026-09-23 13:17:54.315 UTC [822] ERROR: relation "goose_db_version" does not exist at character 3614412026-09-23 13:17:54.315 UTC [822] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14422026/09/23 13:17:54 OK 1_commit_pending_closure.sql (2.92ms)14432026/09/23 13:17:54 OK 2_object_stats_trigger.sql (1.33ms)14442026/09/23 13:17:54 OK 3_commit_push.sql (1.28ms)14452026/09/23 13:17:54 goose: up to current file version: 314462026/09/23 13:17:54 INFO Received uploads request method=POST path=/api/pending_closures14472026/09/23 13:17:54 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=Nzk0MTIyNzctOGU0MC00MTUzLWI4MmYtNTU3ZmE3ODI1NTc3LmU4NzgwMWZiLWQyZTktNDU1OS1hOGEyLWY2MzUxNGY4MWRjNHgxNzkwMTY5NDczODI4ODcyMjAw parts=1014482026/09/23 13:17:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14492026/09/23 13:17:54 OK 20241026095416_initial_model.sql (8.57ms)14502026/09/23 13:17:54 OK 20251210153512_drop_unused_gin_index.sql (1.84ms)14512026/09/23 13:17:54 INFO Completed upload id=114522026/09/23 13:17:54 INFO Received uploads request method=POST path=/api/pending_closures14532026/09/23 13:17:54 OK 20251218171726_add_pins.sql (3.11ms)14542026/09/23 13:17:54 INFO Received uploads request method=POST path=/api/pending_closures14552026/09/23 13:17:54 INFO Received uploads request method=POST path=/api/pending_closures14562026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (3.28ms)14572026/09/23 13:17:54 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo14582026/09/23 13:17:54 WARN Found objects in DB but missing from S3, will re-upload count=114592026/09/23 13:17:54 OK 20260905000000_add_claims.sql (3.16ms)1460--- PASS: TestService_verifyS3Integrity (1.01s)1461=== CONT TestReadProxyDisabled14622026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (2.1ms)14632026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (2.11ms)14642026/09/23 13:17:54 goose: successfully migrated database to version: 2026092312000014652026/09/23 13:17:54 OK 1_commit_pending_closure.sql (1.96ms)14662026/09/23 13:17:54 OK 2_object_stats_trigger.sql (1.22ms)14672026/09/23 13:17:54 OK 3_commit_push.sql (1.3ms)14682026/09/23 13:17:54 goose: up to current file version: 314692026/09/23 13:17:54 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst14702026/09/23 13:17:54 INFO Received uploads request method=POST path=/api/pending_closures14712026/09/23 13:17:54 INFO Received push request method=POST path=/api/pushes1472--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.91s)1473=== CONT TestReadProxyRootRedirectsToIndexHTML14742026-09-23 13:17:54.371 UTC [841] ERROR: relation "goose_db_version" does not exist at character 3614752026-09-23 13:17:54.371 UTC [841] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14762026/09/23 13:17:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14772026/09/23 13:17:54 INFO Signed narinfos id=1 count=11478--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.86s)1479=== CONT TestReadProxy40414802026-09-23 13:17:54.384 UTC [843] ERROR: relation "goose_db_version" does not exist at character 3614812026-09-23 13:17:54.384 UTC [843] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14822026/09/23 13:17:54 OK 20241026095416_initial_model.sql (9.36ms)14832026/09/23 13:17:54 OK 20251210153512_drop_unused_gin_index.sql (2.07ms)14842026/09/23 13:17:54 OK 20251218171726_add_pins.sql (2.97ms)14852026/09/23 13:17:54 INFO Received push request method=POST path=/api/pushes14862026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (4.16ms)14872026/09/23 13:17:54 OK 20241026095416_initial_model.sql (9.13ms)1488--- PASS: TestGCBugBareHashReferences (0.95s)14892026/09/23 13:17:54 OK 20260905000000_add_claims.sql (3.61ms)1490=== CONT TestReadProxyNarStreaming14912026/09/23 13:17:54 OK 20251210153512_drop_unused_gin_index.sql (1.45ms)14922026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (2.56ms)14932026/09/23 13:17:54 OK 20251218171726_add_pins.sql (3.66ms)14942026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (2.62ms)14952026/09/23 13:17:54 goose: successfully migrated database to version: 2026092312000014962026/09/23 13:17:54 OK 1_commit_pending_closure.sql (2.29ms)14972026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (4.43ms)14982026/09/23 13:17:54 OK 2_object_stats_trigger.sql (2.07ms)14992026/09/23 13:17:54 OK 3_commit_push.sql (1.55ms)15002026/09/23 13:17:54 goose: up to current file version: 315012026/09/23 13:17:54 OK 20260905000000_add_claims.sql (4.04ms)15022026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (2.6ms)15032026/09/23 13:17:54 INFO Received complete push request method=POST path=/api/pushes/1/complete15042026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (2.12ms)15052026/09/23 13:17:54 goose: successfully migrated database to version: 2026092312000015062026/09/23 13:17:54 OK 1_commit_pending_closure.sql (2.42ms)15072026/09/23 13:17:54 INFO Received push request method=POST path=/api/pushes15082026/09/23 13:17:54 OK 2_object_stats_trigger.sql (1.63ms)15092026/09/23 13:17:54 OK 3_commit_push.sql (1.76ms)15102026/09/23 13:17:54 goose: up to current file version: 315112026/09/23 13:17:54 INFO Received push request method=POST path=/api/pushes15122026/09/23 13:17:54 INFO Received complete push request method=POST path=/api/pushes/2/complete15132026-09-23 13:17:54.436 UTC [848] ERROR: Push object missing: aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo15142026-09-23 13:17:54.436 UTC [848] CONTEXT: PL/pgSQL function commit_push(bigint) line 37 at RAISE15152026-09-23 13:17:54.436 UTC [848] STATEMENT: -- name: CommitPush :exec1516 SELECT commit_push($1::bigint)1517 1518--- PASS: TestPush_CommitFailsWhenSkippedKeyWasCollected (0.70s)1519=== CONT TestReadProxyConditionalGet15202026-09-23 13:17:54.446 UTC [852] ERROR: relation "goose_db_version" does not exist at character 3615212026-09-23 13:17:54.446 UTC [852] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1522--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.67s)1523=== CONT TestReadProxyHead15242026/09/23 13:17:54 INFO Received push request method=POST path=/api/pushes15252026/09/23 13:17:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15262026/09/23 13:17:54 OK 20241026095416_initial_model.sql (9.49ms)15272026/09/23 13:17:54 OK 20251210153512_drop_unused_gin_index.sql (1.61ms)15282026-09-23 13:17:54.472 UTC [856] ERROR: relation "goose_db_version" does not exist at character 3615292026-09-23 13:17:54.472 UTC [856] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15302026/09/23 13:17:54 OK 20251218171726_add_pins.sql (3.58ms)15312026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (3.47ms)15322026-09-23 13:17:54.479 UTC [866] ERROR: relation "goose_db_version" does not exist at character 3615332026-09-23 13:17:54.479 UTC [866] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15342026/09/23 13:17:54 INFO Received complete push request method=POST path=/api/pushes/1/complete15352026/09/23 13:17:54 OK 20260905000000_add_claims.sql (3.17ms)15362026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (2.65ms)15372026/09/23 13:17:54 OK 20241026095416_initial_model.sql (9.23ms)15382026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (3.08ms)15392026/09/23 13:17:54 goose: successfully migrated database to version: 2026092312000015402026/09/23 13:17:54 OK 20251210153512_drop_unused_gin_index.sql (2.39ms)15412026/09/23 13:17:54 OK 1_commit_pending_closure.sql (3.01ms)1542--- PASS: TestPush_CompleteCommitsEveryRoot (0.72s)1543=== CONT TestService_ReadScope_PublicByDefault15442026/09/23 13:17:54 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=Nzk0MTIyNzctOGU0MC00MTUzLWI4MmYtNTU3ZmE3ODI1NTc3LjU3ZGY5Yzc1LTZhMzEtNDZjZi05MjUxLWU4MDYwN2EwMmVlOXgxNzkwMTY5NDczOTg0MDIwMTIz parts=1015452026/09/23 13:17:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15462026/09/23 13:17:54 OK 20251218171726_add_pins.sql (3.04ms)15472026/09/23 13:17:54 OK 2_object_stats_trigger.sql (2.38ms)15482026/09/23 13:17:54 OK 20241026095416_initial_model.sql (8.87ms)15492026/09/23 13:17:54 OK 3_commit_push.sql (1.32ms)15502026/09/23 13:17:54 goose: up to current file version: 315512026/09/23 13:17:54 OK 20251210153512_drop_unused_gin_index.sql (2.25ms)15522026-09-23 13:17:54.498 UTC [867] ERROR: relation "goose_db_version" does not exist at character 3615532026-09-23 13:17:54.498 UTC [867] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15542026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (5.44ms)15552026/09/23 13:17:54 INFO Completed upload id=115562026/09/23 13:17:54 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000015572026/09/23 13:17:54 OK 20251218171726_add_pins.sql (3.56ms)15582026/09/23 13:17:54 INFO Received uploads request method=POST path=/api/pending_closures15592026/09/23 13:17:54 OK 20260905000000_add_claims.sql (3.59ms)1560--- PASS: TestReadRedirectUsesPublicS3URL (0.61s)1561=== CONT TestClientErrorHandling1562=== RUN TestClientErrorHandling/InvalidStorePath1563=== PAUSE TestClientErrorHandling/InvalidStorePath1564=== RUN TestClientErrorHandling/InvalidAuthToken1565=== PAUSE TestClientErrorHandling/InvalidAuthToken1566=== RUN TestClientErrorHandling/ServerNotAvailable1567=== PAUSE TestClientErrorHandling/ServerNotAvailable1568=== CONT TestClientCADerivations15692026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (3.8ms)15702026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (5.5ms)15712026/09/23 13:17:54 INFO Starting cleanup of old closures method=DELETE path=/api/closures15722026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (2.11ms)15732026/09/23 13:17:54 goose: successfully migrated database to version: 2026092312000015742026/09/23 13:17:54 OK 20260905000000_add_claims.sql (3.69ms)15752026/09/23 13:17:54 OK 1_commit_pending_closure.sql (2.62ms)15762026/09/23 13:17:54 OK 2_object_stats_trigger.sql (1.52ms)15772026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (2.62ms)15782026/09/23 13:17:54 OK 20241026095416_initial_model.sql (8.88ms)15792026/09/23 13:17:54 OK 3_commit_push.sql (1.81ms)15802026/09/23 13:17:54 goose: up to current file version: 315812026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (3.09ms)15822026/09/23 13:17:54 goose: successfully migrated database to version: 2026092312000015832026/09/23 13:17:54 OK 20251210153512_drop_unused_gin_index.sql (3.04ms)15842026/09/23 13:17:54 INFO Aborted multipart uploads count=015852026/09/23 13:17:54 OK 1_commit_pending_closure.sql (3.2ms)15862026/09/23 13:17:54 OK 20251218171726_add_pins.sql (4.65ms)15872026/09/23 13:17:54 OK 2_object_stats_trigger.sql (2.65ms)15882026/09/23 13:17:54 OK 3_commit_push.sql (2.07ms)15892026/09/23 13:17:54 goose: up to current file version: 315902026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (3.84ms)1591--- PASS: TestReadProxyRangeRequest (0.62s)1592=== CONT TestCacheStatsHandler15932026/09/23 13:17:54 OK 20260905000000_add_claims.sql (4.08ms)15942026/09/23 13:17:54 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=015952026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (3.68ms)15962026/09/23 13:17:54 INFO Vacuumed table table=pending_closures15972026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (7.65ms)15982026/09/23 13:17:54 goose: successfully migrated database to version: 2026092312000015992026-09-23 13:17:54.542 UTC [875] ERROR: relation "goose_db_version" does not exist at character 3616002026-09-23 13:17:54.542 UTC [875] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16012026/09/23 13:17:54 INFO Vacuumed table table=pending_objects16022026/09/23 13:17:54 OK 1_commit_pending_closure.sql (2.44ms)16032026/09/23 13:17:54 OK 2_object_stats_trigger.sql (10.61ms)16042026/09/23 13:17:54 INFO Vacuumed table table=multipart_uploads16052026/09/23 13:17:54 OK 3_commit_push.sql (3.35ms)16062026/09/23 13:17:54 goose: up to current file version: 316072026/09/23 13:17:54 INFO Vacuumed table table=closures1608--- PASS: TestReadRedirectKeepsNarinfoProxied (0.64s)1609=== CONT TestCacheConfigHandler1610=== RUN TestCacheConfigHandler/full_config,_no_issuer1611=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1612=== RUN TestCacheConfigHandler/no_cache_url_configured1613=== PAUSE TestCacheConfigHandler/no_cache_url_configured1614=== RUN TestCacheConfigHandler/no_signing_keys1615=== PAUSE TestCacheConfigHandler/no_signing_keys1616=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1617=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1618=== CONT TestService_ReadAuthMiddleware16192026/09/23 13:17:54 INFO Vacuumed table table=objects16202026-09-23 13:17:54.567 UTC [876] ERROR: relation "goose_db_version" does not exist at character 3616212026-09-23 13:17:54.567 UTC [876] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16222026/09/23 13:17:54 OK 20241026095416_initial_model.sql (9.67ms)16232026/09/23 13:17:54 OK 20251210153512_drop_unused_gin_index.sql (2.06ms)16242026/09/23 13:17:54 OK 20251218171726_add_pins.sql (4.01ms)16252026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (4.5ms)16262026/09/23 13:17:54 OK 20260905000000_add_claims.sql (3.65ms)16272026/09/23 13:17:54 OK 20241026095416_initial_model.sql (10.29ms)16282026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (3.34ms)16292026/09/23 13:17:54 OK 20251210153512_drop_unused_gin_index.sql (2.54ms)16302026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (2.18ms)16312026/09/23 13:17:54 goose: successfully migrated database to version: 2026092312000016322026/09/23 13:17:54 OK 20251218171726_add_pins.sql (3.39ms)16332026/09/23 13:17:54 OK 1_commit_pending_closure.sql (2.45ms)16342026/09/23 13:17:54 OK 2_object_stats_trigger.sql (1.58ms)16352026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (3.9ms)16362026/09/23 13:17:54 OK 3_commit_push.sql (1.97ms)16372026/09/23 13:17:54 goose: up to current file version: 316382026/09/23 13:17:54 OK 20260905000000_add_claims.sql (2.93ms)16392026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (2.74ms)16402026-09-23 13:17:54.600 UTC [880] ERROR: relation "goose_db_version" does not exist at character 3616412026-09-23 13:17:54.600 UTC [880] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16422026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (2.14ms)16432026/09/23 13:17:54 goose: successfully migrated database to version: 2026092312000016442026/09/23 13:17:54 OK 1_commit_pending_closure.sql (2.49ms)16452026/09/23 13:17:54 OK 2_object_stats_trigger.sql (1.61ms)16462026-09-23 13:17:54.607 UTC [881] ERROR: relation "goose_db_version" does not exist at character 3616472026-09-23 13:17:54.607 UTC [881] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16482026/09/23 13:17:54 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000016492026/09/23 13:17:54 OK 3_commit_push.sql (1.7ms)16502026/09/23 13:17:54 goose: up to current file version: 31651--- PASS: TestService_createPendingClosureHandler (1.27s)1652=== CONT TestService_RequireScope_OIDC16532026/09/23 13:17:54 INFO lead: acquired remote=192.0.2.1:123416542026/09/23 13:17:54 INFO lead: released remote=192.0.2.1:12341655--- PASS: TestLeadEndsOnShutdown (0.59s)1656=== CONT TestService_AuthMiddleware_OIDC16572026/09/23 13:17:54 OK 20241026095416_initial_model.sql (8.54ms)16582026/09/23 13:17:54 OK 20251210153512_drop_unused_gin_index.sql (1.75ms)16592026/09/23 13:17:54 OK 20251218171726_add_pins.sql (2.9ms)16602026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (3.57ms)16612026/09/23 13:17:54 OK 20241026095416_initial_model.sql (9.62ms)16622026/09/23 13:17:54 OK 20251210153512_drop_unused_gin_index.sql (1.68ms)1663=== NAME TestClientIntegration1664 client_integration_test.go:286: Created store path: /build/TestClientIntegration2034846548/002/store/42as533n04ylrifwznxl3yxb8c4a4ych-test-file.txt16652026/09/23 13:17:54 OK 20260905000000_add_claims.sql (3.38ms)16662026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (2.21ms)16672026/09/23 13:17:54 OK 20251218171726_add_pins.sql (3.2ms)16682026-09-23 13:17:54.631 UTC [898] ERROR: relation "goose_db_version" does not exist at character 3616692026-09-23 13:17:54.631 UTC [898] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16702026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (2.3ms)16712026/09/23 13:17:54 goose: successfully migrated database to version: 2026092312000016722026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (3.6ms)16732026/09/23 13:17:54 OK 1_commit_pending_closure.sql (2.4ms)16742026/09/23 13:17:54 OK 2_object_stats_trigger.sql (1.42ms)16752026/09/23 13:17:54 OK 20260905000000_add_claims.sql (3.3ms)16762026/09/23 13:17:54 OK 3_commit_push.sql (1.65ms)16772026/09/23 13:17:54 goose: up to current file version: 316782026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (2.27ms)16792026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (1.94ms)16802026/09/23 13:17:54 goose: successfully migrated database to version: 2026092312000016812026/09/23 13:17:54 OK 1_commit_pending_closure.sql (1.9ms)16822026/09/23 13:17:54 OK 2_object_stats_trigger.sql (744.56µs)16832026/09/23 13:17:54 INFO lead: acquired remote=192.0.2.1:123416842026/09/23 13:17:54 OK 20241026095416_initial_model.sql (7.2ms)16852026/09/23 13:17:54 OK 3_commit_push.sql (712.82µs)16862026/09/23 13:17:54 goose: up to current file version: 316872026/09/23 13:17:54 OK 20251210153512_drop_unused_gin_index.sql (1.21ms)16882026/09/23 13:17:54 OK 20251218171726_add_pins.sql (2.36ms)16892026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (2.81ms)16902026-09-23 13:17:54.651 UTC [901] ERROR: relation "goose_db_version" does not exist at character 3616912026-09-23 13:17:54.651 UTC [901] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16922026/09/23 13:17:54 OK 20260905000000_add_claims.sql (2.48ms)16932026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (1.45ms)16942026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (1.14ms)16952026/09/23 13:17:54 goose: successfully migrated database to version: 2026092312000016962026/09/23 13:17:54 OK 1_commit_pending_closure.sql (2.03ms)16972026/09/23 13:17:54 OK 2_object_stats_trigger.sql (713.13µs)16982026/09/23 13:17:54 OK 3_commit_push.sql (1.43ms)16992026/09/23 13:17:54 goose: up to current file version: 317002026/09/23 13:17:54 OK 20241026095416_initial_model.sql (6.92ms)17012026/09/23 13:17:54 OK 20251210153512_drop_unused_gin_index.sql (906.98µs)17022026/09/23 13:17:54 OK 20251218171726_add_pins.sql (2.38ms)17032026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (2.3ms)17042026/09/23 13:17:54 OK 20260905000000_add_claims.sql (3.12ms)17052026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (4.9ms)17062026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (1.08ms)17072026/09/23 13:17:54 goose: successfully migrated database to version: 2026092312000017082026/09/23 13:17:54 OK 1_commit_pending_closure.sql (1.28ms)17092026/09/23 13:17:54 OK 2_object_stats_trigger.sql (499.89µs)17102026/09/23 13:17:54 OK 3_commit_push.sql (543.44µs)17112026/09/23 13:17:54 goose: up to current file version: 317122026/09/23 13:17:54 INFO Received uploads request method=POST path=/api/pending_closures17132026/09/23 13:17:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17142026/09/23 13:17:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38589/oidc17152026/09/23 13:17:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17162026/09/23 13:17:54 INFO Uploading 42as533n04ylrifwznxl3yxb8c4a4ych-test-file.txt (152B)17172026/09/23 13:17:54 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17182026/09/23 13:17:54 WARN Failed to register uploaded object key=42as533n04ylrifwznxl3yxb8c4a4ych.ls error="server returned 404: 404 page not found\n"17192026/09/23 13:17:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17202026/09/23 13:17:54 INFO Signed narinfos id=1 count=117212026/09/23 13:17:54 INFO Uploading 1 narinfos17222026/09/23 13:17:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17232026/09/23 13:17:54 WARN Failed to register uploaded object key=42as533n04ylrifwznxl3yxb8c4a4ych.narinfo error="server returned 404: 404 page not found\n"17242026/09/23 13:17:54 INFO Completed upload id=117252026/09/23 13:17:54 INFO Upload complete. (68ms)17262026/09/23 13:17:54 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=Nzk0MTIyNzctOGU0MC00MTUzLWI4MmYtNTU3ZmE3ODI1NTc3LmU5MDlkZGRjLWE4MjItNDI1MS05YTZmLTgxYjllOTQ4NDQxNXgxNzkwMTY5NDc0MTQxNzg4MzQz parts=1217272026/09/23 13:17:54 INFO Received uploads request method=POST path=/api/pending_closures1728--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.28s)1729=== CONT TestService_AuthMiddleware_MTLSBoundSubjects17302026/09/23 13:17:54 INFO All 1 paths already cached1731=== NAME TestClientIntegration1732 client_integration_test.go:312: Retrieved narinfo from S3:1733 StorePath: /build/TestClientIntegration2034846548/002/store/42as533n04ylrifwznxl3yxb8c4a4ych-test-file.txt1734 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1735 Compression: zstd1736 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11737 NarSize: 1521738 References: 1739 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11740 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1741 client_integration_test.go:313: Decompressed .ls content (64 bytes):1742 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1743 client_integration_test.go:316: Testing garbage collection...17442026/09/23 13:17:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36413/oidc17452026-09-23 13:17:54.792 UTC [1081] ERROR: relation "goose_db_version" does not exist at character 3617462026-09-23 13:17:54.792 UTC [1081] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17472026/09/23 13:17:54 INFO lead: released remote=192.0.2.1:123417482026/09/23 13:17:54 INFO Starting cleanup of old closures method=DELETE path=/api/closures17492026/09/23 13:17:54 INFO Garbage collection started1750=== NAME TestPinProtectsFromGC1751 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC2301825947/001/store/4pfpnjk14lkjqif28q75l652wsy6qjf6-pinned-file.txt17522026/09/23 13:17:54 OK 20241026095416_initial_model.sql (10.47ms)1753 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC2301825947/001/store/242mp1izdbs9wz0x7wbidcwr2x7xa2cw-unpinned-file.txt17542026/09/23 13:17:54 INFO Aborted multipart uploads count=017552026/09/23 13:17:54 OK 20251210153512_drop_unused_gin_index.sql (4.3ms)17562026/09/23 13:17:54 WARN Force mode enabled - objects will be deleted immediately without grace period17572026/09/23 13:17:54 OK 20251218171726_add_pins.sql (3.31ms)17582026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (3.56ms)17592026/09/23 13:17:54 OK 20260905000000_add_claims.sql (2.55ms)17602026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (1.97ms)17612026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (1.52ms)17622026/09/23 13:17:54 goose: successfully migrated database to version: 2026092312000017632026-09-23 13:17:54.827 UTC [1163] ERROR: relation "goose_db_version" does not exist at character 3617642026-09-23 13:17:54.827 UTC [1163] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17652026/09/23 13:17:54 OK 1_commit_pending_closure.sql (1.99ms)17662026/09/23 13:17:54 OK 2_object_stats_trigger.sql (1.52ms)17672026/09/23 13:17:54 OK 3_commit_push.sql (1.28ms)17682026/09/23 13:17:54 goose: up to current file version: 317692026/09/23 13:17:54 INFO lead: acquired remote=192.0.2.1:123417702026/09/23 13:17:54 INFO lead: released remote=192.0.2.1:12341771--- PASS: TestLeadElectsOneAndHandsOver (0.77s)1772=== CONT TestParseSingleRange1773=== RUN TestParseSingleRange/none1774=== PAUSE TestParseSingleRange/none1775=== RUN TestParseSingleRange/unknown_unit1776=== PAUSE TestParseSingleRange/unknown_unit1777=== RUN TestParseSingleRange/multi-range_ignored1778=== PAUSE TestParseSingleRange/multi-range_ignored1779=== RUN TestParseSingleRange/malformed_no_dash1780=== PAUSE TestParseSingleRange/malformed_no_dash1781=== RUN TestParseSingleRange/malformed_both_empty1782=== PAUSE TestParseSingleRange/malformed_both_empty1783=== RUN TestParseSingleRange/malformed_end_before_start1784=== PAUSE TestParseSingleRange/malformed_end_before_start1785=== RUN TestParseSingleRange/closed1786=== PAUSE TestParseSingleRange/closed1787=== RUN TestParseSingleRange/open-ended1788=== PAUSE TestParseSingleRange/open-ended1789=== RUN TestParseSingleRange/end_clamped_to_size1790=== PAUSE TestParseSingleRange/end_clamped_to_size1791=== RUN TestParseSingleRange/suffix1792=== PAUSE TestParseSingleRange/suffix1793=== RUN TestParseSingleRange/suffix_exceeds_size1794=== PAUSE TestParseSingleRange/suffix_exceeds_size1795=== RUN TestParseSingleRange/single_byte1796=== PAUSE TestParseSingleRange/single_byte1797=== RUN TestParseSingleRange/start_past_EOF1798=== PAUSE TestParseSingleRange/start_past_EOF1799=== RUN TestParseSingleRange/start_far_past_EOF1800=== PAUSE TestParseSingleRange/start_far_past_EOF1801=== CONT TestReadProxyNarinfo1802--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.55s)1803=== CONT TestIsValidCachePath1804=== RUN TestIsValidCachePath/narinfo1805=== PAUSE TestIsValidCachePath/narinfo1806=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1807=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1808=== RUN TestIsValidCachePath/nar_zst1809=== PAUSE TestIsValidCachePath/nar_zst1810=== RUN TestIsValidCachePath/nar_xz1811=== PAUSE TestIsValidCachePath/nar_xz1812=== RUN TestIsValidCachePath/nar_bz21813=== PAUSE TestIsValidCachePath/nar_bz21814=== RUN TestIsValidCachePath/nar_uncompressed1815=== PAUSE TestIsValidCachePath/nar_uncompressed1816=== RUN TestIsValidCachePath/ls1817=== PAUSE TestIsValidCachePath/ls1818=== RUN TestIsValidCachePath/log1819=== PAUSE TestIsValidCachePath/log1820=== RUN TestIsValidCachePath/realisation1821=== PAUSE TestIsValidCachePath/realisation1822=== RUN TestIsValidCachePath/nix-cache-info1823=== PAUSE TestIsValidCachePath/nix-cache-info1824=== RUN TestIsValidCachePath/index.html1825=== PAUSE TestIsValidCachePath/index.html1826=== RUN TestIsValidCachePath/traversal_parent1827=== PAUSE TestIsValidCachePath/traversal_parent1828=== RUN TestIsValidCachePath/traversal_in_middle1829=== PAUSE TestIsValidCachePath/traversal_in_middle1830=== RUN TestIsValidCachePath/invalid_char_e1831=== PAUSE TestIsValidCachePath/invalid_char_e1832=== RUN TestIsValidCachePath/invalid_char_u1833=== PAUSE TestIsValidCachePath/invalid_char_u1834=== RUN TestIsValidCachePath/random_path1835=== PAUSE TestIsValidCachePath/random_path1836=== RUN TestIsValidCachePath/empty1837=== PAUSE TestIsValidCachePath/empty1838=== RUN TestIsValidCachePath/leading_slash1839=== PAUSE TestIsValidCachePath/leading_slash1840=== RUN TestIsValidCachePath/wrong_extension1841=== PAUSE TestIsValidCachePath/wrong_extension1842=== RUN TestIsValidCachePath/short_hash1843=== PAUSE TestIsValidCachePath/short_hash1844=== CONT TestReadProxyInvalidPath18452026/09/23 13:17:54 OK 20241026095416_initial_model.sql (28.18ms)18462026/09/23 13:17:54 INFO Received uploads request method=POST path=/api/pending_closures18472026/09/23 13:17:54 OK 20251210153512_drop_unused_gin_index.sql (11.57ms)18482026/09/23 13:17:54 OK 20251218171726_add_pins.sql (2.37ms)18492026/09/23 13:17:54 INFO Received uploads request method=POST path=/api/pending_closures18502026/09/23 13:17:54 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)18512026/09/23 13:17:54 INFO Uploading 8842543gr65kd6hq45mn5p9zcm82k1qi-shared-dep (136B)18522026/09/23 13:17:54 INFO Uploading hnv94jknd3ymglqskzx267bsp49qma6w-b (216B)18532026/09/23 13:17:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18542026/09/23 13:17:54 INFO Received uploads request method=POST path=/api/pending_closures18552026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (5.73ms)18562026/09/23 13:17:54 WARN Failed to register uploaded object key=nar/00mh95xkynpc3smlq7i6njxjk1r64sr0sz8z95djk88xfx9mpamd.nar.zst error="server returned 404: 404 page not found\n"18572026/09/23 13:17:54 WARN Failed to register uploaded object key=89zx6pbpqjsx4lmcplbb33jfshh9bd49.ls error="server returned 404: 404 page not found\n"18582026/09/23 13:17:54 WARN Failed to register uploaded object key=hnv94jknd3ymglqskzx267bsp49qma6w.ls error="server returned 404: 404 page not found\n"18592026-09-23 13:17:54.885 UTC [1318] ERROR: relation "goose_db_version" does not exist at character 3618602026-09-23 13:17:54.885 UTC [1318] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18612026/09/23 13:17:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18622026/09/23 13:17:54 INFO Uploading 4pfpnjk14lkjqif28q75l652wsy6qjf6-pinned-file.txt (128B)18632026/09/23 13:17:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18642026/09/23 13:17:54 WARN Failed to register uploaded object key=8842543gr65kd6hq45mn5p9zcm82k1qi.ls error="server returned 404: 404 page not found\n"18652026/09/23 13:17:54 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18662026/09/23 13:17:54 INFO Signed narinfos id=1 count=21867=== NAME TestClientMultipleUploads18682026/09/23 13:17:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign1869 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads28188195/001/store/hfp7y9irsxln3bqdnrz7pzszimlbkh70-test-file-0.txt18702026/09/23 13:17:54 INFO Signed narinfos id=2 count=218712026/09/23 13:17:54 INFO Uploading 4 narinfos18722026/09/23 13:17:54 OK 20260905000000_add_claims.sql (5.57ms)18732026/09/23 13:17:54 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"18742026/09/23 13:17:54 WARN Failed to register uploaded object key=8842543gr65kd6hq45mn5p9zcm82k1qi.narinfo error="server returned 404: 404 page not found\n"18752026/09/23 13:17:54 WARN Failed to register uploaded object key=4pfpnjk14lkjqif28q75l652wsy6qjf6.ls error="server returned 404: 404 page not found\n"18762026/09/23 13:17:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18772026/09/23 13:17:54 INFO Signed narinfos id=1 count=118782026/09/23 13:17:54 INFO Uploading 1 narinfos18792026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (4.14ms)18802026/09/23 13:17:54 WARN Failed to register uploaded object key=hnv94jknd3ymglqskzx267bsp49qma6w.narinfo error="server returned 404: 404 page not found\n"18812026/09/23 13:17:54 WARN Failed to register uploaded object key=89zx6pbpqjsx4lmcplbb33jfshh9bd49.narinfo error="server returned 404: 404 page not found\n"18822026/09/23 13:17:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18832026/09/23 13:17:54 WARN Failed to register uploaded object key=8842543gr65kd6hq45mn5p9zcm82k1qi.narinfo error="server returned 404: 404 page not found\n"1884=== NAME TestClientWithDependencies1885 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2564855944/001/store/81i7hw36c0yaqs5al83r7njjjjg7ck16-test-script18862026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (3.34ms)18872026/09/23 13:17:54 goose: successfully migrated database to version: 202609231200001888--- PASS: TestReadProxyDisabled (0.56s)1889=== CONT TestProxyHeadersOnlyTrustedOnSocket18902026/09/23 13:17:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18912026/09/23 13:17:54 WARN Failed to register uploaded object key=4pfpnjk14lkjqif28q75l652wsy6qjf6.narinfo error="server returned 404: 404 page not found\n"18922026/09/23 13:17:54 OK 20241026095416_initial_model.sql (8.98ms)18932026/09/23 13:17:54 OK 1_commit_pending_closure.sql (4ms)18942026/09/23 13:17:54 INFO Completed upload id=118952026/09/23 13:17:54 OK 20251210153512_drop_unused_gin_index.sql (1.98ms)18962026/09/23 13:17:54 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18972026/09/23 13:17:54 OK 2_object_stats_trigger.sql (1.88ms)18982026/09/23 13:17:54 INFO Completed upload id=118992026/09/23 13:17:54 INFO Upload complete. (67ms)19002026/09/23 13:17:54 INFO Completed upload id=219012026/09/23 13:17:54 INFO Upload complete. (78ms)19022026/09/23 13:17:54 OK 20251218171726_add_pins.sql (2.94ms)1903=== NAME TestClientFallsBackToClosures1904 client_pushes_test.go:112: Retrieved narinfo from S3:19052026/09/23 13:17:54 OK 3_commit_push.sql (2.04ms)1906 StorePath: /build/TestClientFallsBackToClosures3474124414/001/store/8842543gr65kd6hq45mn5p9zcm82k1qi-shared-dep19072026/09/23 13:17:54 goose: up to current file version: 31908 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1909 Compression: zstd1910 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821911 NarSize: 1361912 References: 1913 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n19142026/09/23 13:17:54 INFO Received uploads request method=POST path=/api/pending_closures1915 client_pushes_test.go:112: Retrieved narinfo from S3:1916 StorePath: /build/TestClientFallsBackToClosures3474124414/001/store/89zx6pbpqjsx4lmcplbb33jfshh9bd49-a1917 URL: nar/00mh95xkynpc3smlq7i6njxjk1r64sr0sz8z95djk88xfx9mpamd.nar.zst1918 Compression: zstd19192026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (3.09ms)1920 NarHash: sha256:00mh95xkynpc3smlq7i6njxjk1r64sr0sz8z95djk88xfx9mpamd1921 NarSize: 2161922 References: /build/TestClientFallsBackToClosures3474124414/001/store/8842543gr65kd6hq45mn5p9zcm82k1qi-shared-dep1923 CA: text:sha256:179qihskwbfp11jrfinhgvd82jwq60rrkd66jfxklj4xcicsai6s19242026/09/23 13:17:54 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=Nzk0MTIyNzctOGU0MC00MTUzLWI4MmYtNTU3ZmE3ODI1NTc3LjQyMmUxYTdhLTllYmMtNDVjMi1iMTVlLTgwZTJmNWFjZjRlZngxNzkwMTY5NDc0MzE2OTkxMjUw parts=121925 client_pushes_test.go:112: Retrieved narinfo from S3:1926 StorePath: /build/TestClientFallsBackToClosures3474124414/001/store/hnv94jknd3ymglqskzx267bsp49qma6w-b1927 URL: nar/00mh95xkynpc3smlq7i6njxjk1r64sr0sz8z95djk88xfx9mpamd.nar.zst1928 Compression: zstd1929 NarHash: sha256:00mh95xkynpc3smlq7i6njxjk1r64sr0sz8z95djk88xfx9mpamd1930 NarSize: 2161931 References: /build/TestClientFallsBackToClosures3474124414/001/store/8842543gr65kd6hq45mn5p9zcm82k1qi-shared-dep1932 CA: text:sha256:179qihskwbfp11jrfinhgvd82jwq60rrkd66jfxklj4xcicsai6s1933--- PASS: TestRedundantMultipartUpload (1.46s)1934=== CONT TestResurrectedObjectNotDeleted1935--- PASS: TestClientFallsBackToClosures (0.84s)1936=== CONT TestService_AuthMiddleware_MTLSProxyHeader19372026/09/23 13:17:54 INFO Received uploads request method=POST path=/api/pending_closures1938=== NAME TestClientMultipleUploads19392026/09/23 13:17:54 OK 20260905000000_add_claims.sql (10.55ms)1940 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads28188195/001/store/rrl34932k5ia1j19wnvhhmsbk2vgdvg2-test-file-1.txt19412026/09/23 13:17:54 INFO Received uploads request method=POST path=/api/pending_closures19422026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (3.49ms)19432026/09/23 13:17:54 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)19442026/09/23 13:17:54 INFO Uploading l5qnkkhkivycx00v3iqsj90fsr0vrf4s-b (216B)19452026/09/23 13:17:54 INFO Uploading lzkkrh3r4qand6k877rad1fpym29maxx-shared-dep (136B)19462026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (2.81ms)19472026/09/23 13:17:54 goose: successfully migrated database to version: 2026092312000019482026/09/23 13:17:54 OK 1_commit_pending_closure.sql (2.92ms)19492026/09/23 13:17:54 WARN Failed to register uploaded object key=ap27zzg839p9mpg0d9i3viyxrzindji5.ls error="server returned 404: 404 page not found\n"1950--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.57s)1951=== CONT TestCreatePin_ReservedPins1952=== NAME TestClientWithDependencies1953 client_integration_test.go:615: Found 1 dependencies (including self)19542026/09/23 13:17:54 WARN Failed to register uploaded object key=nar/1kmx3n8akivlicl9fdpadp0hpl16q9pcvkrlvfag8cqsqmsi1yrn.nar.zst error="server returned 404: 404 page not found\n"19552026/09/23 13:17:54 WARN Failed to register uploaded object key=l5qnkkhkivycx00v3iqsj90fsr0vrf4s.ls error="server returned 404: 404 page not found\n"19562026/09/23 13:17:54 OK 2_object_stats_trigger.sql (2.18ms)19572026/09/23 13:17:54 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19582026/09/23 13:17:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign19592026/09/23 13:17:54 WARN Failed to register uploaded object key=lzkkrh3r4qand6k877rad1fpym29maxx.ls error="server returned 404: 404 page not found\n"19602026/09/23 13:17:54 INFO Signed narinfos id=2 count=219612026/09/23 13:17:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19622026/09/23 13:17:54 INFO Signed narinfos id=1 count=219632026/09/23 13:17:54 INFO Uploading 4 narinfos19642026/09/23 13:17:54 OK 3_commit_push.sql (1.68ms)19652026/09/23 13:17:54 goose: up to current file version: 319662026/09/23 13:17:54 WARN Failed to register uploaded object key=lzkkrh3r4qand6k877rad1fpym29maxx.narinfo error="server returned 404: 404 page not found\n"19672026/09/23 13:17:54 WARN Failed to register uploaded object key=ap27zzg839p9mpg0d9i3viyxrzindji5.narinfo error="server returned 404: 404 page not found\n"19682026/09/23 13:17:54 WARN Failed to register uploaded object key=l5qnkkhkivycx00v3iqsj90fsr0vrf4s.narinfo error="server returned 404: 404 page not found\n"19692026/09/23 13:17:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19702026/09/23 13:17:54 WARN Failed to register uploaded object key=lzkkrh3r4qand6k877rad1fpym29maxx.narinfo error="server returned 404: 404 page not found\n"19712026/09/23 13:17:54 INFO Completed upload id=119722026/09/23 13:17:54 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1973=== NAME TestClientMultipleUploads19742026/09/23 13:17:54 INFO Completed upload id=21975 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads28188195/001/store/qrpmzymg81h3pjb569849n80j5dyzl8d-test-file-2.txt1976--- PASS: TestReadProxy404 (0.57s)19772026/09/23 13:17:54 INFO Upload complete. (86ms)1978=== CONT TestOrphanedObjectsGCStressTest1979=== NAME TestClientPushesUseOnePush1980 client_pushes_test.go:97: Retrieved narinfo from S3:1981 StorePath: /build/TestClientPushesUseOnePush1355648479/001/store/lzkkrh3r4qand6k877rad1fpym29maxx-shared-dep1982 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1983 Compression: zstd1984 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821985 NarSize: 1361986 References: 1987 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1988 client_pushes_test.go:97: Retrieved narinfo from S3:1989 StorePath: /build/TestClientPushesUseOnePush1355648479/001/store/ap27zzg839p9mpg0d9i3viyxrzindji5-a1990 URL: nar/1kmx3n8akivlicl9fdpadp0hpl16q9pcvkrlvfag8cqsqmsi1yrn.nar.zst1991 Compression: zstd1992 NarHash: sha256:1kmx3n8akivlicl9fdpadp0hpl16q9pcvkrlvfag8cqsqmsi1yrn1993 NarSize: 2161994 References: /build/TestClientPushesUseOnePush1355648479/001/store/lzkkrh3r4qand6k877rad1fpym29maxx-shared-dep1995 CA: text:sha256:1d7lgxvx8fqmdqwllrgix8fikfbq1qkdvkp8yw5rqnl2k5xar1v61996 client_pushes_test.go:97: Retrieved narinfo from S3:1997 StorePath: /build/TestClientPushesUseOnePush1355648479/001/store/l5qnkkhkivycx00v3iqsj90fsr0vrf4s-b1998 URL: nar/1kmx3n8akivlicl9fdpadp0hpl16q9pcvkrlvfag8cqsqmsi1yrn.nar.zst1999 Compression: zstd2000 NarHash: sha256:1kmx3n8akivlicl9fdpadp0hpl16q9pcvkrlvfag8cqsqmsi1yrn2001 NarSize: 2162002 References: /build/TestClientPushesUseOnePush1355648479/001/store/lzkkrh3r4qand6k877rad1fpym29maxx-shared-dep2003 CA: text:sha256:1d7lgxvx8fqmdqwllrgix8fikfbq1qkdvkp8yw5rqnl2k5xar1v62004 client_pushes_test.go:100: POST /api/pushes calls = 0, want 12005 client_pushes_test.go:104: POST /api/pending_closures calls = 2, want 02006--- FAIL: TestClientPushesUseOnePush (0.86s)2007=== CONT TestOrphanedObjectsGC20082026/09/23 13:17:54 INFO Received uploads request method=POST path=/api/pending_closures20092026-09-23 13:17:54.972 UTC [1485] ERROR: relation "goose_db_version" does not exist at character 3620102026-09-23 13:17:54.972 UTC [1485] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20112026/09/23 13:17:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20122026/09/23 13:17:54 INFO Uploading 242mp1izdbs9wz0x7wbidcwr2x7xa2cw-unpinned-file.txt (128B)20132026-09-23 13:17:54.977 UTC [1494] ERROR: relation "goose_db_version" does not exist at character 3620142026-09-23 13:17:54.977 UTC [1494] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20152026/09/23 13:17:54 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"20162026/09/23 13:17:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign20172026/09/23 13:17:54 INFO Signed narinfos id=2 count=120182026/09/23 13:17:54 INFO Uploading 1 narinfos20192026/09/23 13:17:54 WARN Failed to register uploaded object key=242mp1izdbs9wz0x7wbidcwr2x7xa2cw.ls error="server returned 404: 404 page not found\n"20202026/09/23 13:17:54 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete20212026/09/23 13:17:54 WARN Failed to register uploaded object key=242mp1izdbs9wz0x7wbidcwr2x7xa2cw.narinfo error="server returned 404: 404 page not found\n"2022--- PASS: TestReadProxyNarStreaming (0.59s)2023=== CONT TestProxyWriteTimeout/narinfo2024=== CONT TestProxyWriteTimeout/unknown_size2025=== CONT TestProxyWriteTimeout/10_GiB_nar2026=== CONT TestProxyWriteTimeout/1_GiB_nar2027--- PASS: TestProxyWriteTimeout (0.02s)2028 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2029 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2030 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2031 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2032=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info20332026/09/23 13:17:54 INFO Received uploads request method=POST path=/2034=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key20352026/09/23 13:17:54 INFO Received complete multipart upload request method=POST path=/2036=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal20372026/09/23 13:17:54 INFO Received uploads request method=POST path=/2038=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key20392026/09/23 13:17:54 INFO Received request for more parts method=POST path=/2040--- PASS: TestUploadHandlersRejectInvalidKeys (0.03s)2041 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2042 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2043 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2044 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2045=== CONT TestServerTLSConfig/no_client_CA2046=== CONT TestServerTLSConfig/not_a_PEM_file2047=== CONT TestServerTLSConfig/missing_CA_file2048--- PASS: TestServerTLSConfig (0.11s)2049 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2050 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2051 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2052=== CONT TestIsValidUploadKey/narinfo2053=== CONT TestIsValidUploadKey/realisation_plus_in_output2054=== CONT TestIsValidUploadKey/realisation2055=== CONT TestIsValidUploadKey/build_log_equals2056=== CONT TestIsValidUploadKey/build_log_question_mark2057=== CONT TestIsValidUploadKey/build_log_plus_in_name2058=== CONT TestIsValidUploadKey/build_log_home-manager_file2059=== CONT TestIsValidUploadKey/build_log2060=== CONT TestIsValidUploadKey/listing2061=== CONT TestIsValidUploadKey/nar_plain2062=== CONT TestIsValidUploadKey/nar_xz2063=== CONT TestIsValidUploadKey/nar_zst2064=== CONT TestIsValidUploadKey/traversal_nar2065=== CONT TestIsValidUploadKey/nix-cache-info2066=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2067=== CONT TestIsValidUploadKey/index.html2068=== CONT TestIsValidUploadKey/traversal2069=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2070=== CONT TestIsValidUploadKey/empty_key2071=== CONT TestIsValidUploadKey/unknown_type2072=== CONT TestIsValidUploadKey/absolute2073=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2074--- PASS: TestIsValidUploadKey (0.11s)2075 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2076 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2077 --- PASS: TestIsValidUploadKey/realisation (0.00s)2078 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2079 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2080 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2081 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2082 --- PASS: TestIsValidUploadKey/build_log (0.00s)2083 --- PASS: TestIsValidUploadKey/listing (0.00s)2084 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2085 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2086 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2087 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2088 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2089 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2090 --- PASS: TestIsValidUploadKey/index.html (0.00s)2091 --- PASS: TestIsValidUploadKey/traversal (0.00s)2092 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2093 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2094 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2095 --- PASS: TestIsValidUploadKey/absolute (0.00s)2096 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2097=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure20982026/09/23 13:17:54 INFO Received uploads request method=POST path=/20992026/09/23 13:17:54 INFO Received uploads request method=POST path=/api/pending_closures21002026/09/23 13:17:54 INFO Completed upload id=221012026/09/23 13:17:54 INFO Upload complete. (58ms)21022026/09/23 13:17:54 INFO Received uploads request method=POST path=/api/pending_closures21032026/09/23 13:17:54 OK 20241026095416_initial_model.sql (15.94ms)21042026/09/23 13:17:54 OK 20241026095416_initial_model.sql (20.82ms)21052026/09/23 13:17:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21062026/09/23 13:17:55 INFO Uploading 554nc2vcvj4hqjvq013gpms6ymdd22vj-shared-dep (136B)21072026/09/23 13:17:55 OK 20251210153512_drop_unused_gin_index.sql (2.48ms)21082026/09/23 13:17:55 OK 20251210153512_drop_unused_gin_index.sql (2.67ms)21092026/09/23 13:17:55 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"21102026/09/23 13:17:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign21112026/09/23 13:17:55 WARN Failed to register uploaded object key=554nc2vcvj4hqjvq013gpms6ymdd22vj.ls error="server returned 404: 404 page not found\n"21122026/09/23 13:17:55 INFO Signed narinfos id=2 count=121132026/09/23 13:17:55 INFO Uploading 1 narinfos21142026/09/23 13:17:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21152026/09/23 13:17:55 INFO Uploading 81i7hw36c0yaqs5al83r7njjjjg7ck16-test-script (136B)21162026/09/23 13:17:55 OK 20251218171726_add_pins.sql (4.62ms)21172026/09/23 13:17:55 OK 20251218171726_add_pins.sql (4.75ms)21182026-09-23 13:17:55.009 UTC [1548] ERROR: relation "goose_db_version" does not exist at character 3621192026-09-23 13:17:55.009 UTC [1548] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21202026/09/23 13:17:55 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21212026/09/23 13:17:55 WARN Failed to register uploaded object key=554nc2vcvj4hqjvq013gpms6ymdd22vj.narinfo error="server returned 404: 404 page not found\n"21222026/09/23 13:17:55 OK 20260628120000_add_object_size_and_stats.sql (3.63ms)21232026/09/23 13:17:55 OK 20260628120000_add_object_size_and_stats.sql (4.24ms)21242026/09/23 13:17:55 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"21252026/09/23 13:17:55 WARN Failed to register uploaded object key=81i7hw36c0yaqs5al83r7njjjjg7ck16.ls error="server returned 404: 404 page not found\n"21262026/09/23 13:17:55 WARN Failed to register uploaded object key=log/xfn4ki1my1ai23772609xzx2i2xii1zy-test-script.drv error="server returned 404: 404 page not found\n"21272026/09/23 13:17:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21282026/09/23 13:17:55 INFO Signed narinfos id=1 count=121292026/09/23 13:17:55 INFO Uploading 1 narinfos21302026/09/23 13:17:55 OK 20260905000000_add_claims.sql (3.09ms)21312026/09/23 13:17:55 OK 20260905000000_add_claims.sql (3.24ms)21322026/09/23 13:17:55 INFO Completed upload id=221332026/09/23 13:17:55 INFO Upload complete. (56ms)21342026/09/23 13:17:55 INFO Received uploads request method=POST path=/api/pending_closures21352026/09/23 13:17:55 OK 20260920000000_drop_claims.sql (2.83ms)21362026-09-23 13:17:55.017 UTC [1549] ERROR: relation "goose_db_version" does not exist at character 3621372026-09-23 13:17:55.017 UTC [1549] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21382026/09/23 13:17:55 OK 20260920000000_drop_claims.sql (2.8ms)21392026/09/23 13:17:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21402026/09/23 13:17:55 WARN Failed to register uploaded object key=81i7hw36c0yaqs5al83r7njjjjg7ck16.narinfo error="server returned 404: 404 page not found\n"21412026/09/23 13:17:55 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)21422026/09/23 13:17:55 INFO Uploading 554nc2vcvj4hqjvq013gpms6ymdd22vj-shared-dep (136B)21432026/09/23 13:17:55 INFO Uploading p00rwzg051zm6a6fllzqijnsvdn455g8-top (224B)21442026/09/23 13:17:55 OK 20260923120000_add_pushes.sql (2.14ms)21452026/09/23 13:17:55 goose: successfully migrated database to version: 202609231200002146--- PASS: TestReadProxyConditionalGet (0.58s)2147=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts21482026/09/23 13:17:55 INFO Received request for more parts method=POST path=/21492026/09/23 13:17:55 OK 20260923120000_add_pushes.sql (2.22ms)21502026/09/23 13:17:55 goose: successfully migrated database to version: 2026092312000021512026/09/23 13:17:55 OK 1_commit_pending_closure.sql (2.38ms)21522026/09/23 13:17:55 OK 1_commit_pending_closure.sql (2.3ms)21532026/09/23 13:17:55 OK 2_object_stats_trigger.sql (1.58ms)21542026/09/23 13:17:55 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"21552026/09/23 13:17:55 OK 2_object_stats_trigger.sql (1.79ms)21562026/09/23 13:17:55 OK 20241026095416_initial_model.sql (8.74ms)21572026/09/23 13:17:55 WARN Failed to register uploaded object key=554nc2vcvj4hqjvq013gpms6ymdd22vj.ls error="server returned 404: 404 page not found\n"21582026-09-23 13:17:55.025 UTC [1551] ERROR: relation "goose_db_version" does not exist at character 3621592026-09-23 13:17:55.025 UTC [1551] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21602026/09/23 13:17:55 OK 3_commit_push.sql (1.67ms)21612026/09/23 13:17:55 goose: up to current file version: 321622026/09/23 13:17:55 WARN Failed to register uploaded object key=p00rwzg051zm6a6fllzqijnsvdn455g8.ls error="server returned 404: 404 page not found\n"21632026/09/23 13:17:55 WARN Failed to register uploaded object key=nar/17f6z7fcw2ssvbwfa7vp6bc6adw75hhhhqfrm94izrj13xy5xkvi.nar.zst error="server returned 404: 404 page not found\n"21642026/09/23 13:17:55 OK 3_commit_push.sql (1.71ms)21652026/09/23 13:17:55 goose: up to current file version: 321662026/09/23 13:17:55 OK 20251210153512_drop_unused_gin_index.sql (1.7ms)21672026/09/23 13:17:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21682026/09/23 13:17:55 INFO Completed upload id=121692026/09/23 13:17:55 INFO Upload complete. (66ms)21702026/09/23 13:17:55 INFO Signed narinfos id=1 count=121712026/09/23 13:17:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign21722026/09/23 13:17:55 INFO Signed narinfos id=3 count=121732026/09/23 13:17:55 INFO Uploading 2 narinfos2174=== NAME TestClientWithDependencies2175 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2564855944/001/store) requires matching store prefix21762026/09/23 13:17:55 OK 20251218171726_add_pins.sql (3.36ms)21772026/09/23 13:17:55 INFO Received uploads request method=POST path=/api/pending_closures21782026/09/23 13:17:55 WARN Failed to register uploaded object key=p00rwzg051zm6a6fllzqijnsvdn455g8.narinfo error="server returned 404: 404 page not found\n"21792026/09/23 13:17:55 INFO Received create pin request method=POST path=/api/pins/myapp21802026/09/23 13:17:55 OK 20241026095416_initial_model.sql (9.2ms)21812026/09/23 13:17:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21822026/09/23 13:17:55 WARN Failed to register uploaded object key=554nc2vcvj4hqjvq013gpms6ymdd22vj.narinfo error="server returned 404: 404 page not found\n"21832026/09/23 13:17:55 OK 20260628120000_add_object_size_and_stats.sql (3.44ms)21842026/09/23 13:17:55 INFO Completed upload id=121852026/09/23 13:17:55 OK 20251210153512_drop_unused_gin_index.sql (2.35ms)21862026/09/23 13:17:55 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete21872026/09/23 13:17:55 INFO Completed upload id=321882026/09/23 13:17:55 INFO Upload complete. (155ms)2189--- PASS: TestClientWithDependencies (0.81s)2190=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart21912026/09/23 13:17:55 INFO Received complete multipart upload request method=POST path=/21922026/09/23 13:17:55 OK 20260905000000_add_claims.sql (3.7ms)2193=== NAME TestClientSharedPathCommittedMidPush2194 client_integration_test.go:680: Retrieved narinfo from S3:2195 StorePath: /build/TestClientSharedPathCommittedMidPush2279007034/001/store/554nc2vcvj4hqjvq013gpms6ymdd22vj-shared-dep2196 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2197 Compression: zstd2198 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y8221992026/09/23 13:17:55 INFO Received uploads request method=POST path=/api/pending_closures2200 NarSize: 1362201 References: 2202 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n22032026/09/23 13:17:55 OK 20251218171726_add_pins.sql (3.45ms)22042026/09/23 13:17:55 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2301825947/001/store/4pfpnjk14lkjqif28q75l652wsy6qjf6-pinned-file.txt narinfo_key=4pfpnjk14lkjqif28q75l652wsy6qjf6.narinfo22052026/09/23 13:17:55 INFO Starting cleanup of old closures method=DELETE path=/api/closures22062026/09/23 13:17:55 OK 20260920000000_drop_claims.sql (2.25ms)22072026/09/23 13:17:55 INFO Garbage collection started2208 client_integration_test.go:680: Retrieved narinfo from S3:2209 StorePath: /build/TestClientSharedPathCommittedMidPush2279007034/001/store/p00rwzg051zm6a6fllzqijnsvdn455g8-top2210 URL: nar/17f6z7fcw2ssvbwfa7vp6bc6adw75hhhhqfrm94izrj13xy5xkvi.nar.zst2211 Compression: zstd2212 NarHash: sha256:17f6z7fcw2ssvbwfa7vp6bc6adw75hhhhqfrm94izrj13xy5xkvi2213 NarSize: 2242214 References: /build/TestClientSharedPathCommittedMidPush2279007034/001/store/554nc2vcvj4hqjvq013gpms6ymdd22vj-shared-dep2215 CA: text:sha256:1kfyqq8wp3p3wky34xaxwirsrk86cph92wqdd9d8j6v0v2hw0k2422162026/09/23 13:17:55 INFO Received uploads request method=POST path=/api/pending_closures22172026/09/23 13:17:55 OK 20241026095416_initial_model.sql (9.39ms)22182026/09/23 13:17:55 OK 20260628120000_add_object_size_and_stats.sql (3.17ms)22192026/09/23 13:17:55 OK 20260923120000_add_pushes.sql (1.76ms)22202026/09/23 13:17:55 goose: successfully migrated database to version: 2026092312000022212026/09/23 13:17:55 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)22222026/09/23 13:17:55 INFO Uploading hfp7y9irsxln3bqdnrz7pzszimlbkh70-test-file-0.txt (160B)22232026/09/23 13:17:55 INFO Uploading qrpmzymg81h3pjb569849n80j5dyzl8d-test-file-2.txt (160B)22242026/09/23 13:17:55 INFO Uploading rrl34932k5ia1j19wnvhhmsbk2vgdvg2-test-file-1.txt (160B)22252026/09/23 13:17:55 OK 20251210153512_drop_unused_gin_index.sql (2.7ms)22262026/09/23 13:17:55 OK 1_commit_pending_closure.sql (2.61ms)22272026/09/23 13:17:55 OK 20260905000000_add_claims.sql (3.12ms)22282026/09/23 13:17:55 OK 2_object_stats_trigger.sql (2.3ms)22292026/09/23 13:17:55 OK 20251218171726_add_pins.sql (3.07ms)2230--- PASS: TestClientSharedPathCommittedMidPush (0.85s)2231=== CONT TestResolveDBConnectionString/flag_wins2232=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2233=== CONT TestResolveDBConnectionString/nothing_configured2234=== CONT TestResolveDBConnectionString/missing_file_is_an_error22352026/09/23 13:17:55 OK 20260920000000_drop_claims.sql (2.79ms)2236=== CONT TestResolveDBConnectionString/file_when_flag_empty2237=== CONT TestPush_RejectsBadRequests/bad_root22382026/09/23 13:17:55 INFO Received push request method=POST path=/api/pushes2239=== CONT TestPush_RejectsBadRequests/no_roots22402026/09/23 13:17:55 INFO Received push request method=POST path=/api/pushes2241--- PASS: TestReadProxyHead (0.60s)22422026/09/23 13:17:55 OK 3_commit_push.sql (1.36ms)2243=== CONT TestPush_RejectsBadRequests/no_objects22442026/09/23 13:17:55 goose: up to current file version: 32245--- PASS: TestResolveDBConnectionString (0.00s)2246 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2247 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2248 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2249 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2250 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)22512026/09/23 13:17:55 INFO Received push request method=POST path=/api/pushes2252=== CONT TestPush_RejectsBadRequests/root_not_in_objects2253=== CONT TestClientErrorHandling/InvalidStorePath22542026/09/23 13:17:55 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"22552026/09/23 13:17:55 INFO Received push request method=POST path=/api/pushes2256=== CONT TestClientErrorHandling/ServerNotAvailable22572026/09/23 13:17:55 OK 20260923120000_add_pushes.sql (1.54ms)2258--- PASS: TestPush_RejectsBadRequests (0.73s)2259 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2260 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2261 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2262 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)22632026/09/23 13:17:55 goose: successfully migrated database to version: 2026092312000022642026/09/23 13:17:55 INFO Aborted multipart uploads count=022652026/09/23 13:17:55 WARN Failed to register uploaded object key=hfp7y9irsxln3bqdnrz7pzszimlbkh70.ls error="server returned 404: 404 page not found\n"22662026/09/23 13:17:55 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"22672026/09/23 13:17:55 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"22682026/09/23 13:17:55 OK 20260628120000_add_object_size_and_stats.sql (2.92ms)22692026/09/23 13:17:55 WARN Failed to register uploaded object key=rrl34932k5ia1j19wnvhhmsbk2vgdvg2.ls error="server returned 404: 404 page not found\n"22702026/09/23 13:17:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign22712026/09/23 13:17:55 WARN Failed to register uploaded object key=qrpmzymg81h3pjb569849n80j5dyzl8d.ls error="server returned 404: 404 page not found\n"22722026/09/23 13:17:55 INFO Signed narinfos id=2 count=122732026/09/23 13:17:55 OK 1_commit_pending_closure.sql (2.17ms)22742026/09/23 13:17:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign22752026/09/23 13:17:55 INFO Signed narinfos id=3 count=122762026/09/23 13:17:55 WARN Force mode enabled - objects will be deleted immediately without grace period22772026/09/23 13:17:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign22782026/09/23 13:17:55 OK 2_object_stats_trigger.sql (767.29µs)22792026/09/23 13:17:55 INFO Signed narinfos id=1 count=122802026/09/23 13:17:55 OK 20260905000000_add_claims.sql (2.37ms)22812026/09/23 13:17:55 INFO Uploading 3 narinfos22822026/09/23 13:17:55 OK 3_commit_push.sql (718.58µs)22832026/09/23 13:17:55 goose: up to current file version: 322842026/09/23 13:17:55 OK 20260920000000_drop_claims.sql (1.75ms)22852026/09/23 13:17:55 OK 20260923120000_add_pushes.sql (1.08ms)22862026/09/23 13:17:55 goose: successfully migrated database to version: 2026092312000022872026-09-23 13:17:55.056 UTC [1589] ERROR: relation "goose_db_version" does not exist at character 3622882026-09-23 13:17:55.056 UTC [1589] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22892026/09/23 13:17:55 WARN Failed to register uploaded object key=rrl34932k5ia1j19wnvhhmsbk2vgdvg2.narinfo error="server returned 404: 404 page not found\n"22902026/09/23 13:17:55 OK 1_commit_pending_closure.sql (1.48ms)2291=== CONT TestClientErrorHandling/InvalidAuthToken22922026/09/23 13:17:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22932026/09/23 13:17:55 WARN Failed to register uploaded object key=qrpmzymg81h3pjb569849n80j5dyzl8d.narinfo error="server returned 404: 404 page not found\n"22942026/09/23 13:17:55 OK 2_object_stats_trigger.sql (1.22ms)22952026/09/23 13:17:55 WARN Failed to register uploaded object key=hfp7y9irsxln3bqdnrz7pzszimlbkh70.narinfo error="server returned 404: 404 page not found\n"22962026/09/23 13:17:55 OK 3_commit_push.sql (738.26µs)22972026/09/23 13:17:55 goose: up to current file version: 322982026-09-23 13:17:55.063 UTC [1592] ERROR: relation "goose_db_version" does not exist at character 3622992026-09-23 13:17:55.063 UTC [1592] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23002026/09/23 13:17:55 INFO Completed upload id=123012026/09/23 13:17:55 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete2302--- PASS: TestService_ReadScope_PublicByDefault (0.58s)2303=== CONT TestCacheConfigHandler/full_config,_no_issuer2304=== CONT TestCacheConfigHandler/no_signing_keys2305=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2306=== CONT TestCacheConfigHandler/no_cache_url_configured2307=== CONT TestParseSingleRange/none2308=== CONT TestParseSingleRange/open-ended2309=== CONT TestParseSingleRange/start_far_past_EOF2310=== CONT TestParseSingleRange/start_past_EOF2311=== CONT TestParseSingleRange/single_byte2312=== CONT TestParseSingleRange/malformed_both_empty2313=== CONT TestParseSingleRange/suffix_exceeds_size2314--- PASS: TestCacheConfigHandler (0.00s)2315 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2316 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2317 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2318 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2319=== CONT TestParseSingleRange/closed2320=== CONT TestParseSingleRange/suffix2321=== CONT TestParseSingleRange/malformed_end_before_start2322=== CONT TestParseSingleRange/end_clamped_to_size2323=== CONT TestParseSingleRange/multi-range_ignored2324=== CONT TestParseSingleRange/malformed_no_dash2325=== CONT TestParseSingleRange/unknown_unit2326--- PASS: TestParseSingleRange (0.00s)2327 --- PASS: TestParseSingleRange/none (0.00s)2328 --- PASS: TestParseSingleRange/open-ended (0.00s)2329 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2330 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2331 --- PASS: TestParseSingleRange/single_byte (0.00s)2332 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2333 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2334 --- PASS: TestParseSingleRange/closed (0.00s)2335 --- PASS: TestParseSingleRange/suffix (0.00s)2336 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2337 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2338 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2339 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2340 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2341=== CONT TestIsValidCachePath/narinfo2342=== CONT TestIsValidCachePath/short_hash2343=== CONT TestIsValidCachePath/wrong_extension2344=== CONT TestIsValidCachePath/leading_slash2345=== CONT TestIsValidCachePath/empty2346=== CONT TestIsValidCachePath/random_path2347=== CONT TestIsValidCachePath/invalid_char_u2348=== CONT TestIsValidCachePath/invalid_char_e2349=== CONT TestIsValidCachePath/traversal_in_middle2350=== CONT TestIsValidCachePath/traversal_parent2351=== CONT TestIsValidCachePath/index.html2352=== CONT TestIsValidCachePath/nar_bz22353=== CONT TestIsValidCachePath/nar_xz2354=== CONT TestIsValidCachePath/nar_zst23552026/09/23 13:17:55 INFO Completed upload id=22356=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2357=== CONT TestIsValidCachePath/realisation2358=== CONT TestIsValidCachePath/nar_uncompressed2359=== CONT TestIsValidCachePath/nix-cache-info2360=== CONT TestIsValidCachePath/log2361=== CONT TestIsValidCachePath/ls23622026/09/23 13:17:55 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete2363--- PASS: TestIsValidCachePath (0.00s)2364 --- PASS: TestIsValidCachePath/narinfo (0.00s)2365 --- PASS: TestIsValidCachePath/short_hash (0.00s)2366 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2367 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2368 --- PASS: TestIsValidCachePath/empty (0.00s)2369 --- PASS: TestIsValidCachePath/random_path (0.00s)2370 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2371 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2372 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2373 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2374 --- PASS: TestIsValidCachePath/index.html (0.00s)2375 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2376 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2377 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2378 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2379 --- PASS: TestIsValidCachePath/realisation (0.00s)2380 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2381 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2382 --- PASS: TestIsValidCachePath/log (0.00s)2383 --- PASS: TestIsValidCachePath/ls (0.00s)23842026/09/23 13:17:55 OK 20241026095416_initial_model.sql (8.81ms)23852026/09/23 13:17:55 INFO Completed upload id=323862026/09/23 13:17:55 INFO Upload complete. (84ms)2387=== NAME TestClientMultipleUploads2388 client_integration_test.go:369: Uploaded 3 paths in 118.128733ms23892026/09/23 13:17:55 OK 20251210153512_drop_unused_gin_index.sql (1.6ms)23902026/09/23 13:17:55 OK 20251218171726_add_pins.sql (3.17ms)23912026/09/23 13:17:55 OK 20241026095416_initial_model.sql (9.15ms)23922026/09/23 13:17:55 OK 20251210153512_drop_unused_gin_index.sql (2.12ms)23932026/09/23 13:17:55 OK 20260628120000_add_object_size_and_stats.sql (4.18ms)23942026/09/23 13:17:55 OK 20251218171726_add_pins.sql (2.35ms)23952026/09/23 13:17:55 OK 20260905000000_add_claims.sql (2.65ms)23962026/09/23 13:17:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41191/oidc23972026/09/23 13:17:55 OK 20260920000000_drop_claims.sql (2.4ms)2398--- PASS: TestClientMultipleUploads (0.81s)23992026/09/23 13:17:55 OK 20260628120000_add_object_size_and_stats.sql (3.75ms)24002026/09/23 13:17:55 OK 20260923120000_add_pushes.sql (2.26ms)24012026/09/23 13:17:55 goose: successfully migrated database to version: 2026092312000024022026/09/23 13:17:55 OK 20260905000000_add_claims.sql (2.79ms)24032026/09/23 13:17:55 OK 1_commit_pending_closure.sql (2.19ms)24042026/09/23 13:17:55 OK 2_object_stats_trigger.sql (994.03µs)24052026/09/23 13:17:55 OK 20260920000000_drop_claims.sql (2.9ms)24062026/09/23 13:17:55 OK 3_commit_push.sql (970.76µs)24072026/09/23 13:17:55 goose: up to current file version: 324082026/09/23 13:17:55 OK 20260923120000_add_pushes.sql (1.73ms)24092026/09/23 13:17:55 goose: successfully migrated database to version: 2026092312000024102026/09/23 13:17:55 OK 1_commit_pending_closure.sql (2.61ms)24112026/09/23 13:17:55 OK 2_object_stats_trigger.sql (1.37ms)24122026/09/23 13:17:55 OK 3_commit_push.sql (8.2ms)24132026/09/23 13:17:55 goose: up to current file version: 324142026/09/23 13:17:55 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2415--- PASS: TestCacheStatsHandler (0.62s)24162026-09-23 13:17:55.149 UTC [1648] ERROR: relation "goose_db_version" does not exist at character 3624172026-09-23 13:17:55.149 UTC [1648] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2418--- PASS: TestService_ReadAuthMiddleware (0.59s)24192026-09-23 13:17:55.159 UTC [1650] ERROR: relation "goose_db_version" does not exist at character 3624202026-09-23 13:17:55.159 UTC [1650] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24212026/09/23 13:17:55 OK 20241026095416_initial_model.sql (8.43ms)24222026/09/23 13:17:55 OK 20251210153512_drop_unused_gin_index.sql (1.2ms)24232026/09/23 13:17:55 OK 20251218171726_add_pins.sql (2.51ms)24242026/09/23 13:17:55 OK 20260628120000_add_object_size_and_stats.sql (2.63ms)24252026/09/23 13:17:55 OK 20241026095416_initial_model.sql (8.04ms)24262026/09/23 13:17:55 OK 20260905000000_add_claims.sql (2.75ms)24272026/09/23 13:17:55 OK 20251210153512_drop_unused_gin_index.sql (1.04ms)24282026/09/23 13:17:55 OK 20260920000000_drop_claims.sql (1.68ms)24292026/09/23 13:17:55 OK 20251218171726_add_pins.sql (2.6ms)24302026/09/23 13:17:55 OK 20260923120000_add_pushes.sql (2.08ms)24312026/09/23 13:17:55 goose: successfully migrated database to version: 2026092312000024322026-09-23 13:17:55.178 UTC [1667] ERROR: relation "goose_db_version" does not exist at character 3624332026-09-23 13:17:55.178 UTC [1667] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24342026/09/23 13:17:55 OK 1_commit_pending_closure.sql (1.81ms)24352026/09/23 13:17:55 OK 20260628120000_add_object_size_and_stats.sql (2.53ms)24362026/09/23 13:17:55 OK 2_object_stats_trigger.sql (739.98µs)24372026/09/23 13:17:55 OK 3_commit_push.sql (820.32µs)24382026/09/23 13:17:55 goose: up to current file version: 324392026/09/23 13:17:55 OK 20260905000000_add_claims.sql (2.35ms)24402026/09/23 13:17:55 OK 20260920000000_drop_claims.sql (1.56ms)2441=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2442=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2443=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2444=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2445=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2446=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2447=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured24482026/09/23 13:17:55 OK 20260923120000_add_pushes.sql (1.32ms)2449=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured24502026/09/23 13:17:55 goose: successfully migrated database to version: 202609231200002451=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2452=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected2453=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2454=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected24552026/09/23 13:17:55 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]24562026/09/23 13:17:55 OK 1_commit_pending_closure.sql (2.39ms)24572026/09/23 13:17:55 WARN Authentication failed token_preview=eyJhbGciOi...RrhFzo7WyA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]24582026/09/23 13:17:55 OK 2_object_stats_trigger.sql (1.02ms)24592026/09/23 13:17:55 OK 3_commit_push.sql (858.26µs)24602026/09/23 13:17:55 goose: up to current file version: 324612026/09/23 13:17:55 OK 20241026095416_initial_model.sql (7.18ms)2462--- PASS: TestService_AuthMiddleware_OIDC (0.57s)2463 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2464 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2465 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2466 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)24672026/09/23 13:17:55 OK 20251210153512_drop_unused_gin_index.sql (921.91µs)2468=== NAME TestClientCADerivations2469 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3518273413/001/store/z5s6av5ajsv4g4z8vq0w9dwchc4mnx9d-ca-test24702026/09/23 13:17:55 OK 20251218171726_add_pins.sql (2.2ms)24712026/09/23 13:17:55 OK 20260628120000_add_object_size_and_stats.sql (2.87ms)24722026/09/23 13:17:55 OK 20260905000000_add_claims.sql (2.37ms)24732026/09/23 13:17:55 OK 20260920000000_drop_claims.sql (1.36ms)24742026/09/23 13:17:55 OK 20260923120000_add_pushes.sql (981.94µs)24752026/09/23 13:17:55 goose: successfully migrated database to version: 2026092312000024762026/09/23 13:17:55 OK 1_commit_pending_closure.sql (1.43ms)24772026/09/23 13:17:55 OK 2_object_stats_trigger.sql (698.06µs)24782026/09/23 13:17:55 OK 3_commit_push.sql (621.15µs)24792026/09/23 13:17:55 goose: up to current file version: 324802026/09/23 13:17:55 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"24812026/09/23 13:17:55 WARN mTLS auth: bound subjects configured but subject DN unavailable24822026/09/23 13:17:55 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2483--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.47s)24842026/09/23 13:17:55 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=192.055633ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2485=== NAME TestClientCADerivations2486 client_ca_test.go:139: Found 1 dependencies (including self)2487=== RUN TestService_RequireScope_OIDC/builder_may_write2488=== PAUSE TestService_RequireScope_OIDC/builder_may_write2489=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2490=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2491=== RUN TestService_RequireScope_OIDC/ops_may_admin2492=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2493=== RUN TestService_RequireScope_OIDC/ops_may_not_write2494=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2495=== RUN TestService_RequireScope_OIDC/reader_may_not_write2496=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2497=== RUN TestService_RequireScope_OIDC/static_token_may_admin2498=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2499=== RUN TestService_RequireScope_OIDC/static_token_may_write2500=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2501=== RUN TestService_RequireScope_OIDC/reader_may_read2502=== PAUSE TestService_RequireScope_OIDC/reader_may_read2503=== RUN TestService_RequireScope_OIDC/writer_implies_read2504=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2505=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2506=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2507=== CONT TestService_RequireScope_OIDC/builder_may_write2508=== CONT TestService_RequireScope_OIDC/static_token_may_write2509=== CONT TestService_RequireScope_OIDC/ops_may_not_write2510=== CONT TestService_RequireScope_OIDC/ops_may_admin2511=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2512=== CONT TestService_RequireScope_OIDC/writer_implies_read2513=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2514=== CONT TestService_RequireScope_OIDC/reader_may_not_write2515=== CONT TestService_RequireScope_OIDC/reader_may_read2516=== CONT TestService_RequireScope_OIDC/static_token_may_admin2517--- PASS: TestService_RequireScope_OIDC (0.65s)2518 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2519 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2520 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2521 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2522 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2523 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2524 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2525 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2526 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2527 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2528--- PASS: TestReadProxyNarinfo (0.42s)2529--- PASS: TestReadProxyInvalidPath (0.43s)25302026/09/23 13:17:55 INFO Starting HTTP server address=127.0.0.1:3582125312026/09/23 13:17:55 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket2948363249/001/proxy.sock25322026/09/23 13:17:55 WARN mTLS auth: subject not in bound subjects subject="CN=someone"25332026/09/23 13:17:55 INFO Shutdown signal received, draining in-flight requests timeout=10s2534--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.42s)25352026/09/23 13:17:55 INFO Received uploads request method=POST path=/api/pending_closures25362026/09/23 13:17:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)25372026/09/23 13:17:55 INFO Uploading z5s6av5ajsv4g4z8vq0w9dwchc4mnx9d-ca-test (144B)25382026/09/23 13:17:55 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"25392026/09/23 13:17:55 WARN Failed to register uploaded object key=log/742wq7sisz82m11n8ca07c7yy8sn99az-ca-test.drv error="server returned 404: 404 page not found\n"25402026/09/23 13:17:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign25412026/09/23 13:17:55 WARN Failed to register uploaded object key=z5s6av5ajsv4g4z8vq0w9dwchc4mnx9d.ls error="server returned 404: 404 page not found\n"25422026/09/23 13:17:55 INFO Signed narinfos id=1 count=125432026/09/23 13:17:55 INFO Uploading 1 narinfos25442026/09/23 13:17:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete25452026/09/23 13:17:55 WARN Failed to register uploaded object key=z5s6av5ajsv4g4z8vq0w9dwchc4mnx9d.narinfo error="server returned 404: 404 page not found\n"25462026/09/23 13:17:55 INFO Completed upload id=125472026/09/23 13:17:55 INFO Upload complete. (89ms)2548=== NAME TestClientCADerivations2549 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3518273413/001/store/z5s6av5ajsv4g4z8vq0w9dwchc4mnx9d-ca-test2550 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2551 Compression: zstd2552 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2553 NarSize: 1442554 References: 2555 Deriver: /build/TestClientCADerivations3518273413/001/store/742wq7sisz82m11n8ca07c7yy8sn99az-ca-test.drv2556 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2557 client_ca_test.go:185: Checking for realisation files in S3...2558 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2559 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache2560--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.45s)2561--- PASS: TestResurrectedObjectNotDeleted (0.47s)25622026/09/23 13:17:55 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=399.199121ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2563=== NAME TestClientCADerivations2564 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2565 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2566 error: binary cache 's3://bucket50?endpoint=http://localhost:39787®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3518273413/001/store'2567 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12568--- PASS: TestClientCADerivations (0.97s)25692026/09/23 13:17:55 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux25702026/09/23 13:17:55 WARN Refused reserved pin name=worker-x86_64-linux25712026/09/23 13:17:55 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux25722026/09/23 13:17:55 INFO Received create pin request method=POST path=/api/pins/my-app25732026/09/23 13:17:55 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux2574--- PASS: TestCreatePin_ReservedPins (0.55s)25752026/09/23 13:17:55 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"25762026/09/23 13:17:55 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2577--- PASS: TestUploadHandlersRejectOversizedBody (0.20s)2578 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)2579 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)2580 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.61s)2581=== NAME TestOrphanedObjectsGC2582 orphaned_objects_gc_test.go:290: GC Test Summary:2583 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2584 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2585 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2586 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2587 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2588--- PASS: TestOrphanedObjectsGC (0.76s)25892026/09/23 13:17:55 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=025902026/09/23 13:17:55 INFO Vacuumed table table=pending_closures25912026/09/23 13:17:55 INFO Vacuumed table table=pending_objects25922026/09/23 13:17:55 INFO Vacuumed table table=multipart_uploads25932026/09/23 13:17:55 INFO Vacuumed table table=closures25942026/09/23 13:17:55 INFO Vacuumed table table=objects25952026/09/23 13:17:55 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=749.018004ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present25962026/09/23 13:17: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=025972026/09/23 13:17:56 INFO Vacuumed table table=pending_closures25982026/09/23 13:17:56 INFO Vacuumed table table=pending_objects25992026/09/23 13:17:56 INFO Vacuumed table table=multipart_uploads26002026/09/23 13:17:56 INFO Vacuumed table table=closures26012026/09/23 13:17:56 INFO Vacuumed table table=objects26022026/09/23 13:17:56 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.564822035s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2603=== NAME TestOrphanedObjectsGCStressTest2604 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2605 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion26062026/09/23 13:17:56 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02607=== NAME TestClientIntegration2608 client_integration_test.go:323: Objects in database after GC:2609 client_integration_test.go:323: Successfully deleted all objects with GC --force2610--- PASS: TestClientIntegration (2.79s)26112026/09/23 13:17:57 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02612=== NAME TestPinProtectsFromGC2613 client_integration_test.go:794: Pin successfully protected closure from garbage collection2614--- PASS: TestPinProtectsFromGC (2.91s)2615=== NAME TestOrphanedObjectsGCStressTest2616 orphaned_objects_gc_test.go:509: Stress test completed successfully:2617 orphaned_objects_gc_test.go:510: - Active objects preserved: 202618 orphaned_objects_gc_test.go:511: - Objects deleted: 2102619 orphaned_objects_gc_test.go:512: - Total GC'd: 2102620--- PASS: TestOrphanedObjectsGCStressTest (2.20s)26212026/09/23 13:17:58 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26222026/09/23 13:17:58 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=181.810171ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26232026/09/23 13:17:58 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=409.63168ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26242026/09/23 13:17:58 WARN Rate limiter enabled after throttle name=s3-test rate=526252026/09/23 13:17:58 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2626=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2627 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102628 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002629--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.14s)26302026/09/23 13:17:58 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=751.404685ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26312026/09/23 13:17:59 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.523802991s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26322026/09/23 13:18:01 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"26332026/09/23 13:18:01 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26342026/09/23 13:18:01 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=192.338254ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26352026/09/23 13:18:01 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=432.401239ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26362026/09/23 13:18:01 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=830.143661ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26372026/09/23 13:18:02 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.485084954s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2638--- PASS: TestClientErrorHandling (0.00s)2639 --- PASS: TestClientErrorHandling/InvalidStorePath (0.42s)2640 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.55s)2641 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.15s)2642FAIL2643{"timestamp":"2026-09-23T13:18:04.203145332Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:42982","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2260,"threadName":"rustfs-worker","threadId":"ThreadId(389)"}26442026-09-23 13:18:04.538 UTC [130] LOG: received smart shutdown request26452026-09-23 13:18:04.543 UTC [130] LOG: background worker "logical replication launcher" (PID 140) exited with exit code 126462026-09-23 13:18:04.553 UTC [135] LOG: shutting down26472026-09-23 13:18:04.554 UTC [135] LOG: checkpoint starting: shutdown immediate26482026-09-23 13:18:06.162 UTC [135] LOG: checkpoint complete: wrote 11447 buffers (69.9%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 18 recycled; write=0.289 s, sync=1.281 s, total=1.609 s; sync files=21875, longest=0.043 s, average=0.001 s; distance=297532 kB, estimate=297532 kB; lsn=0/139F4E60, redo lsn=0/139F4E6026492026-09-23 13:18:06.237 UTC [130] LOG: database system is shut down