niks3-go-unit-tests log

failed `niks3-go-unit-tests` `checks.x86_64-linux.go-unit-tests` · build #261 · 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.04s)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 TestDoWithRetry_BodyReplayedViaGetBody99=== CONT TestSetClientTLSErrors100=== CONT TestResolveStorePath101=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess102=== CONT TestScriptTokenEmptyCommand103=== CONT TestRateLimiterFeedback104=== CONT TestScriptTokenScriptFails105=== CONT TestScriptTokenBadJSON106=== CONT TestPathInfoCACompatibility107=== CONT TestScriptTokenEmptyToken108=== CONT TestParsePathInfoJSONMultiplePaths109=== CONT TestScriptTokenCachesUntilRefresh110=== CONT TestParsePathInfoJSON1112026/09/23 13:01:19 WARN Rate limiter enabled after throttle name=server-test rate=5112=== CONT TestScriptTokenNoExpiryRerunsEveryCall113=== CONT TestPathInfoHashCompatibility114=== CONT TestFileTokenEmpty115=== CONT TestGetStorePathHash116=== CONT TestFileTokenMissing117=== CONT TestFileTokenReadsAndCaches118=== CONT TestConvertHashToNix32119=== CONT TestStaticToken120--- PASS: TestEncodeNixBase32WithRealHash (0.00s)121--- PASS: TestShellSplit (0.00s)122=== CONT TestSetClientTLSDoesNotMutateDefaultTransport123=== CONT TestClientSignaturesByStorePath124=== CONT TestStreamPushRequestLine125--- PASS: TestScriptTokenEmptyCommand (0.00s)126=== RUN TestRateLimiterFeedback/429_enables_limiter127=== PAUSE TestRateLimiterFeedback/429_enables_limiter128=== RUN TestRateLimiterFeedback/503_enables_limiter129=== PAUSE TestRateLimiterFeedback/503_enables_limiter130=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter131=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter132=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter133=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter134=== RUN TestPathInfoCACompatibility/null_ca_field135=== CONT TestSetClientTLS136--- PASS: TestResolveStorePath (0.00s)137=== CONT TestUploadMultipart_SupersededByPeer138=== PAUSE TestPathInfoCACompatibility/null_ca_field139=== RUN TestParsePathInfoJSON/Nix_format140=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)141=== RUN TestUploadMultipart_SupersededByPeer/exists142--- PASS: TestScriptTokenScriptFails (0.00s)143=== CONT TestStreamPushBatchesUnderLoad144--- PASS: TestFileTokenEmpty (0.00s)145=== RUN TestConvertHashToNix32/SRI_format_to_Nix32146=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32147--- PASS: TestStaticToken (0.00s)148--- PASS: TestClientSignaturesByStorePath (0.00s)149=== RUN TestConvertHashToNix32/already_Nix32_format150=== PAUSE TestUploadMultipart_SupersededByPeer/exists151=== CONT TestEncodeNixBase32152=== RUN TestEncodeNixBase32/test_string_hash153=== PAUSE TestEncodeNixBase32/test_string_hash154=== CONT TestStreamPushGivesUpOnDeadServer155=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)156=== PAUSE TestParsePathInfoJSON/Nix_format157--- PASS: TestFileTokenReadsAndCaches (0.00s)158=== RUN TestParsePathInfoJSON/Lix_format159=== CONT TestDumpPathWriterError160=== PAUSE TestParsePathInfoJSON/Lix_format1612026/09/23 13:01:19 ERROR Upload failed error="connection refused" count=201622026/09/23 13:01:19 ERROR Server seems unavailable, giving up on batch untried=171632026/09/23 13:01:19 WARN Rate limiter enabled after throttle name=server-test rate=5164=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths165=== RUN TestGetStorePathHash/valid_store_path166=== RUN TestPathInfoCACompatibility/old_string_format_-_text167=== PAUSE TestConvertHashToNix32/already_Nix32_format168=== RUN TestUploadMultipart_SupersededByPeer/missing169=== RUN TestEncodeNixBase32/empty_input170=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon1712026/09/23 13:01:19 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:43689172=== CONT TestStreamPushIsolatesFailures173--- PASS: TestFileTokenMissing (0.00s)174=== RUN TestParsePathInfoJSON/empty_input175--- PASS: TestScriptTokenBadJSON (0.01s)176=== CONT TestDumpPathMatchesNix177=== CONT TestDumpPathSingleFile1782026/09/23 13:01:19 ERROR Upload failed error="bad path" count=3179=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths180=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths181=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text182=== PAUSE TestGetStorePathHash/valid_store_path183=== PAUSE TestUploadMultipart_SupersededByPeer/missing184=== PAUSE TestEncodeNixBase32/empty_input185=== RUN TestConvertHashToNix32/invalid_format186=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon1872026/09/23 13:01:19 WARN Rate limiter backed off name=server-test rate=5188=== PAUSE TestParsePathInfoJSON/empty_input189--- PASS: TestStreamPushIsolatesFailures (0.00s)190=== CONT TestCaseHackSuffix1912026/09/23 13:01:19 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:43689192=== RUN TestSetClientTLSErrors/missing_cert_file193=== CONT TestPartSizeForNAR194=== CONT TestStreamPushReportsEveryPath195=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive196=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths197=== PAUSE TestConvertHashToNix32/invalid_format198=== CONT TestUploadMultipart_PartsInParallel199=== RUN TestGetStorePathHash/basename_without_hyphen_should_error2002026/09/23 13:01:19 ERROR Upload failed error=boom count=1201=== RUN TestParsePathInfoJSON/whitespace_only202=== CONT TestFilterOversizedClosures203=== PAUSE TestParsePathInfoJSON/whitespace_only204=== RUN TestFilterOversizedClosures/no_limit_keeps_everything205=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive206=== RUN TestPartSizeForNAR/zero_stays_at_minimum207=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI208=== PAUSE TestSetClientTLSErrors/missing_cert_file209--- PASS: TestScriptTokenEmptyToken (0.01s)210--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)211=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error212=== CONT TestRegisterUploadedObjectReusesConnections213=== CONT TestRateLimiterFeedback/429_enables_limiter214--- PASS: TestDoServerRequestAttachesToken (0.01s)215=== CONT TestStreamPushReportsSignatures216--- PASS: TestStreamPushReportsEveryPath (0.00s)217--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)218=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter219--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)220=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter2212026/09/23 13:01:19 WARN Rate limiter enabled after throttle name=server-test rate=52222026/09/23 13:01:19 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:457412232026/09/23 13:01:19 ERROR Upload failed error=boom count=1224=== CONT TestShellSplitErrors225=== CONT TestUploadMultipart_SupersededByPeer/missing226=== CONT TestEncodeNixBase32/test_string_hash227=== CONT TestEncodeNixBase32/empty_input228=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths229--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)230--- PASS: TestStreamPushReportsSignatures (0.05s)231--- PASS: TestShellSplitErrors (0.00s)232--- PASS: TestScriptTokenCachesUntilRefresh (0.06s)233=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2342026/09/23 13:01:19 WARN Rate limiter backed off name=server-test rate=5235--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)236 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)237 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)238=== CONT TestConvertHashToNix32/SRI_format_to_Nix32239--- PASS: TestDumpPathSingleFile (0.06s)240=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum241=== RUN TestPathInfoCACompatibility/new_structured_format_-_text242=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error243=== RUN TestSetClientTLSErrors/missing_key_file244=== RUN TestParsePathInfoJSON/invalid_JSON245=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI246=== CONT TestUploadMultipart_SupersededByPeer/exists247=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything248=== PAUSE TestSetClientTLSErrors/missing_key_file249=== RUN TestSetClientTLSErrors/missing_ca_file250=== PAUSE TestSetClientTLSErrors/missing_ca_file251=== RUN TestSetClientTLSErrors/invalid_ca_file252=== PAUSE TestSetClientTLSErrors/invalid_ca_file253=== CONT TestSetClientTLSErrors/missing_cert_file254=== CONT TestConvertHashToNix32/already_Nix32_format255=== PAUSE TestParsePathInfoJSON/invalid_JSON256=== CONT TestParsePathInfoJSON/Nix_format257=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512258=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512259=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)260--- PASS: TestEncodeNixBase32 (0.00s)261 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)262 --- PASS: TestEncodeNixBase32/empty_input (0.00s)263=== CONT TestParsePathInfoJSON/empty_input264=== RUN TestSetClientTLS/rejects_connection_without_client_cert265=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert266=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA267=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA268=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512269=== RUN TestSetClientTLS/preserves_debug_logging_transport270=== PAUSE TestSetClientTLS/preserves_debug_logging_transport271=== CONT TestParsePathInfoJSON/whitespace_only272=== CONT TestSetClientTLS/rejects_connection_without_client_cert273=== CONT TestSetClientTLS/preserves_debug_logging_transport274=== RUN TestPartSizeForNAR/small_stays_at_minimum275=== PAUSE TestPartSizeForNAR/small_stays_at_minimum276=== CONT TestConvertHashToNix32/invalid_format277=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error278=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped279=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text280=== CONT TestSetClientTLSErrors/invalid_ca_file281=== CONT TestSetClientTLSErrors/missing_ca_file282=== CONT TestSetClientTLSErrors/missing_key_file283=== CONT TestRateLimiterFeedback/503_enables_limiter284=== CONT TestParsePathInfoJSON/invalid_JSON285=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped286=== RUN TestFilterOversizedClosures/all_closures_skipped287=== PAUSE TestFilterOversizedClosures/all_closures_skipped288=== CONT TestFilterOversizedClosures/no_limit_keeps_everything289=== CONT TestParsePathInfoJSON/Lix_format290=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI291=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method292=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon293=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum294=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum295=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts296=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts297=== RUN TestPartSizeForNAR/1_TiB298=== PAUSE TestPartSizeForNAR/1_TiB299=== RUN TestPartSizeForNAR/5_TiB_S3_max_object300=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object301=== RUN TestPartSizeForNAR/capped_at_5_GiB302=== PAUSE TestPartSizeForNAR/capped_at_5_GiB303=== CONT TestPartSizeForNAR/zero_stays_at_minimum304--- PASS: TestConvertHashToNix32 (0.01s)305 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)306 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)307 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)308=== CONT TestPartSizeForNAR/capped_at_5_GiB309=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped310=== CONT TestPartSizeForNAR/5_TiB_S3_max_object3112026/09/23 13:01:19 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=2000312--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)313 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)314 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)315=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA3162026/09/23 13:01:19 WARN Rate limiter enabled after throttle name=server-test rate=53172026/09/23 13:01:19 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:36561318--- PASS: TestParsePathInfoJSON (0.06s)319 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)320 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)321 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)322 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)323 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)324--- PASS: TestPathInfoHashCompatibility (0.06s)325 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)326 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)327 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)328 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)3292026/09/23 13:01:19 WARN Rate limiter backed off name=server-test rate=5330=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error331=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method332=== CONT TestFilterOversizedClosures/all_closures_skipped333=== CONT TestPartSizeForNAR/1_TiB334=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts335=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum3362026/09/23 13:01:19 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=50337=== CONT TestPartSizeForNAR/small_stays_at_minimum338=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error339=== CONT TestGetStorePathHash/valid_store_path340--- PASS: TestRateLimiterFeedback (0.00s)341 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.05s)342 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.05s)343 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.05s)344 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)345=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error346=== CONT TestGetStorePathHash/basename_without_hyphen_should_error347=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error348=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method349=== CONT TestPathInfoCACompatibility/new_structured_format_-_text350=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive351=== CONT TestPathInfoCACompatibility/old_string_format_-_text352--- PASS: TestFilterOversizedClosures (0.05s)353 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)354 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)355 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)356=== CONT TestPathInfoCACompatibility/null_ca_field357--- PASS: TestPartSizeForNAR (0.06s)358 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)359 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)360 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)361 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)362 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)363 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)364 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)365--- PASS: TestSetClientTLSErrors (0.07s)366 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)367 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)368 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)369 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)370--- PASS: TestGetStorePathHash (0.06s)371 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)372 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)373 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)374 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)375--- PASS: TestPathInfoCACompatibility (0.07s)376 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)377 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)378 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)379 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)380 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)3812026/09/23 13:01:19 http: TLS handshake error from 127.0.0.1:48900: remote error: tls: bad certificate382--- PASS: TestStreamPushRequestLine (0.08s)383--- PASS: TestSetClientTLS (0.06s)384 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)385 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)386 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)387--- PASS: TestCaseHackSuffix (0.08s)388--- PASS: TestRegisterUploadedObjectReusesConnections (0.08s)389--- PASS: TestDumpPathWriterError (0.11s)390--- PASS: TestStreamPushBatchesUnderLoad (0.11s)391--- PASS: TestDumpPathMatchesNix (0.14s)392--- PASS: TestUploadMultipart_PartsInParallel (0.67s)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/postgres2159139357/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/postgres2159139357/data -l logfile start422423/build/postgres2159139357:5432 - no response4242026-09-23 13:01:21.765 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-09-23 13:01:21.765 UTC [129] LOG: listening on Unix socket "/build/postgres2159139357/.s.PGSQL.5432"4262026-09-23 13:01:21.771 UTC [136] LOG: database system was shut down at 2026-09-23 13:01:21 UTC4272026-09-23 13:01:21.774 UTC [129] LOG: database system is ready to accept connections428/build/postgres2159139357:5432 - accepting connections429{"timestamp":"2026-09-23T13:01:22.070234799Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"29f62bf2-091f-4041-ba89-f9aaca5e2ee8","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(400)"}430=== RUN TestService_AuthMiddleware431=== PAUSE TestService_AuthMiddleware432=== RUN TestService_AuthMiddleware_MTLSProxyHeader433=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader434=== RUN TestService_AuthMiddleware_MTLSBoundSubjects435=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects436=== RUN TestService_ReadAuthMiddleware437=== PAUSE TestService_ReadAuthMiddleware438=== RUN TestService_AuthMiddleware_OIDC439=== PAUSE TestService_AuthMiddleware_OIDC440=== RUN TestService_RequireScope_OIDC441=== PAUSE TestService_RequireScope_OIDC442=== RUN TestService_ReadScope_PublicByDefault443=== PAUSE TestService_ReadScope_PublicByDefault444=== RUN TestCacheConfigHandler445=== PAUSE TestCacheConfigHandler446=== RUN TestCacheStatsHandler447=== PAUSE TestCacheStatsHandler448=== RUN TestClientCADerivations449=== PAUSE TestClientCADerivations450=== RUN TestClientErrorHandling451=== PAUSE TestClientErrorHandling452=== RUN TestClientIntegration453=== PAUSE TestClientIntegration454=== RUN TestClientMultipleUploads455=== PAUSE TestClientMultipleUploads456=== RUN TestClientWithDependencies457=== PAUSE TestClientWithDependencies458=== RUN TestClientSharedPathCommittedMidPush459=== PAUSE TestClientSharedPathCommittedMidPush460=== RUN TestPinProtectsFromGC461=== PAUSE TestPinProtectsFromGC462=== RUN TestClientPushesUseOnePush463=== PAUSE TestClientPushesUseOnePush464=== RUN TestClientFallsBackToClosures465=== PAUSE TestClientFallsBackToClosures466=== RUN TestResolveDBConnectionString467=== PAUSE TestResolveDBConnectionString468=== RUN TestLeadElectsOneAndHandsOver469=== PAUSE TestLeadElectsOneAndHandsOver470=== RUN TestLeadIncumbentWinsAfterRestart4712026-09-23 13:01:22.266 UTC [565] ERROR: relation "goose_db_version" does not exist at character 364722026-09-23 13:01:22.266 UTC [565] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4732026/09/23 13:01:22 OK 20241026095416_initial_model.sql (8.33ms)4742026/09/23 13:01:22 OK 20251210153512_drop_unused_gin_index.sql (1.49ms)4752026/09/23 13:01:22 OK 20251218171726_add_pins.sql (2.01ms)4762026/09/23 13:01:22 OK 20260628120000_add_object_size_and_stats.sql (2.04ms)4772026/09/23 13:01:22 OK 20260905000000_add_claims.sql (2.12ms)4782026/09/23 13:01:22 OK 20260920000000_drop_claims.sql (1.48ms)4792026/09/23 13:01:22 OK 20260923120000_add_pushes.sql (1.22ms)4802026/09/23 13:01:22 goose: successfully migrated database to version: 202609231200004812026/09/23 13:01:22 OK 1_commit_pending_closure.sql (1.4ms)4822026/09/23 13:01:22 OK 2_object_stats_trigger.sql (607.92µs)4832026/09/23 13:01:22 OK 3_commit_push.sql (734.18µs)4842026/09/23 13:01:22 goose: up to current file version: 34852026/09/23 13:01:22 INFO lead: acquired remote=192.0.2.1:12344862026/09/23 13:01:22 INFO lead: released remote=192.0.2.1:12344872026/09/23 13:01:22 INFO lead: acquired remote=192.0.2.1:12344882026/09/23 13:01:22 INFO lead: released remote=192.0.2.1:1234489--- PASS: TestLeadIncumbentWinsAfterRestart (0.80s)490=== RUN TestLeadEndsOnShutdown491=== PAUSE TestLeadEndsOnShutdown492=== RUN TestGCAdvisoryLockBlocksConcurrentRun4932026-09-23 13:01:23.043 UTC [575] ERROR: relation "goose_db_version" does not exist at character 364942026-09-23 13:01:23.043 UTC [575] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4952026/09/23 13:01:23 OK 20241026095416_initial_model.sql (7.05ms)4962026/09/23 13:01:23 OK 20251210153512_drop_unused_gin_index.sql (1.06ms)4972026/09/23 13:01:23 OK 20251218171726_add_pins.sql (2.47ms)4982026/09/23 13:01:23 OK 20260628120000_add_object_size_and_stats.sql (2.69ms)4992026/09/23 13:01:23 OK 20260905000000_add_claims.sql (2.4ms)5002026/09/23 13:01:23 OK 20260920000000_drop_claims.sql (1.43ms)5012026/09/23 13:01:23 OK 20260923120000_add_pushes.sql (1.07ms)5022026/09/23 13:01:23 goose: successfully migrated database to version: 202609231200005032026/09/23 13:01:23 OK 1_commit_pending_closure.sql (1.73ms)5042026/09/23 13:01:23 OK 2_object_stats_trigger.sql (687.86µs)5052026/09/23 13:01:23 OK 3_commit_push.sql (726.3µs)5062026/09/23 13:01:23 goose: up to current file version: 3507--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.13s)508=== RUN TestGCBugBareHashReferences509=== PAUSE TestGCBugBareHashReferences510=== RUN TestGCMetrics511=== PAUSE TestGCMetrics512=== RUN TestGCTaskStore_StartNew513=== PAUSE TestGCTaskStore_StartNew514=== RUN TestGCTaskStore_DeduplicateSameParams515=== PAUSE TestGCTaskStore_DeduplicateSameParams516=== RUN TestGCTaskStore_ConflictDifferentParams517=== PAUSE TestGCTaskStore_ConflictDifferentParams518=== RUN TestGCTaskStore_GetEmpty519=== PAUSE TestGCTaskStore_GetEmpty520=== RUN TestGCTaskStore_GetReturnsLatest521=== PAUSE TestGCTaskStore_GetReturnsLatest522=== RUN TestGCTaskStore_CompletedAllowsNewTask523=== PAUSE TestGCTaskStore_CompletedAllowsNewTask524=== RUN TestGCTaskStore_PhaseUpdates525=== PAUSE TestGCTaskStore_PhaseUpdates526=== RUN TestGCTaskStore_Fail527=== PAUSE TestGCTaskStore_Fail528=== RUN TestGracefulShutdownDrainsInflight529=== PAUSE TestGracefulShutdownDrainsInflight530=== RUN TestService_healthCheckHandler531=== PAUSE TestService_healthCheckHandler532=== RUN TestService_readinessHandler533=== PAUSE TestService_readinessHandler534=== RUN TestGenerateLandingPage535=== PAUSE TestGenerateLandingPage536=== RUN TestCacheConfigHandlerMaxNarSize537=== PAUSE TestCacheConfigHandlerMaxNarSize538=== RUN TestCreatePendingClosureRejectsOversizedNAR539=== PAUSE TestCreatePendingClosureRejectsOversizedNAR540=== RUN TestNARDeduplicationMetadataUploadBug541=== PAUSE TestNARDeduplicationMetadataUploadBug542=== RUN TestMetricsInventory543=== PAUSE TestMetricsInventory544=== RUN TestService_NativeMTLS545=== PAUSE TestService_NativeMTLS546=== RUN TestServerTLSConfig547=== PAUSE TestServerTLSConfig548=== RUN TestMultipartCleanup549=== PAUSE TestMultipartCleanup550=== RUN TestObjectStatsTrigger551=== PAUSE TestObjectStatsTrigger552=== RUN TestOrphanedObjectsGC553=== PAUSE TestOrphanedObjectsGC554=== RUN TestOrphanedObjectsGCStressTest555=== PAUSE TestOrphanedObjectsGCStressTest556=== RUN TestResurrectedObjectNotDeleted557=== PAUSE TestResurrectedObjectNotDeleted558=== RUN TestCreatePin_ReservedPins559=== PAUSE TestCreatePin_ReservedPins560=== RUN TestParseSingleRange561=== PAUSE TestParseSingleRange562=== RUN TestProxyHeadersOnlyTrustedOnSocket563=== PAUSE TestProxyHeadersOnlyTrustedOnSocket564=== RUN TestIsValidCachePath565=== PAUSE TestIsValidCachePath566=== RUN TestReadProxyNarinfo567=== PAUSE TestReadProxyNarinfo568=== RUN TestReadProxyNarinfoAlreadyDecompressed569=== PAUSE TestReadProxyNarinfoAlreadyDecompressed570=== RUN TestReadProxyNarStreaming571=== PAUSE TestReadProxyNarStreaming572=== RUN TestReadProxy404573=== PAUSE TestReadProxy404574=== RUN TestReadProxyInvalidPath575=== PAUSE TestReadProxyInvalidPath576=== RUN TestReadProxyHead577=== PAUSE TestReadProxyHead578=== RUN TestReadProxyConditionalGet579=== PAUSE TestReadProxyConditionalGet580=== RUN TestReadProxyRootRedirectsToIndexHTML581=== PAUSE TestReadProxyRootRedirectsToIndexHTML582=== RUN TestReadProxyDisabled583=== PAUSE TestReadProxyDisabled584=== RUN TestReadRedirectNar585=== PAUSE TestReadRedirectNar586=== RUN TestReadRedirectKeepsNarinfoProxied587=== PAUSE TestReadRedirectKeepsNarinfoProxied588=== RUN TestReadProxyRangeRequest589=== PAUSE TestReadProxyRangeRequest590=== RUN TestReadRedirectUsesPublicS3URL591=== PAUSE TestReadRedirectUsesPublicS3URL592=== RUN TestPush_OverlappingRootsStoreOneRowPerKey593=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey594=== RUN TestPush_CompleteCommitsEveryRoot595=== PAUSE TestPush_CompleteCommitsEveryRoot596=== RUN TestPush_CommitFailsWhenSkippedKeyWasCollected597=== PAUSE TestPush_CommitFailsWhenSkippedKeyWasCollected598=== RUN TestPush_RejectsBadRequests599=== PAUSE TestPush_RejectsBadRequests600=== RUN TestPush_SignsNarinfosOfItsPendingObjects601=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects602=== RUN TestRedundantMultipartUpload603=== PAUSE TestRedundantMultipartUpload604=== RUN TestCompleteMultipartUpload_ErrorButObjectExists605=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists606=== RUN TestCompletedNarNotReofferedAcrossClosures607=== PAUSE TestCompletedNarNotReofferedAcrossClosures608=== RUN TestPresignedUploadRegisteredBeforeCommit609=== PAUSE TestPresignedUploadRegisteredBeforeCommit610=== RUN TestService_Rustfstest611=== PAUSE TestService_Rustfstest612=== RUN TestParseSize613=== PAUSE TestParseSize614=== RUN TestSkippedUploadsHandler615=== PAUSE TestSkippedUploadsHandler616=== RUN TestSystemdListenerNotActivated617--- PASS: TestSystemdListenerNotActivated (0.00s)618=== RUN TestWatchdogBeatsWhenHealthy619--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)620=== RUN TestWatchdogSkipsWhenUnhealthy6212026/09/23 13:01:23 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6222026/09/23 13:01:23 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6232026/09/23 13:01:23 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6242026/09/23 13:01:23 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6252026/09/23 13:01:23 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6262026/09/23 13:01:23 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6272026/09/23 13:01:23 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6282026/09/23 13:01:23 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6292026/09/23 13:01:23 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6302026/09/23 13:01:23 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"631--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)632=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle633=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle634=== RUN TestProxyWriteTimeout635=== PAUSE TestProxyWriteTimeout636=== RUN TestIsValidUploadKey637=== PAUSE TestIsValidUploadKey638=== RUN TestUploadHandlersRejectInvalidKeys639=== PAUSE TestUploadHandlersRejectInvalidKeys640=== RUN TestUploadHandlersRejectOversizedBody641=== PAUSE TestUploadHandlersRejectOversizedBody642=== RUN TestService_cleanupPendingClosuresHandler643=== PAUSE TestService_cleanupPendingClosuresHandler644=== RUN TestService_createPendingClosureHandler645=== PAUSE TestService_createPendingClosureHandler646=== RUN TestService_verifyS3Integrity647=== PAUSE TestService_verifyS3Integrity648=== RUN TestCompleteMultipartUnregistered649=== PAUSE TestCompleteMultipartUnregistered650=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT651=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT652=== CONT TestService_AuthMiddleware653=== CONT TestOrphanedObjectsGC654=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT655=== CONT TestCompleteMultipartUnregistered656=== CONT TestService_verifyS3Integrity657=== CONT TestService_createPendingClosureHandler658=== CONT TestService_cleanupPendingClosuresHandler659=== CONT TestUploadHandlersRejectOversizedBody660=== CONT TestUploadHandlersRejectInvalidKeys661=== CONT TestIsValidUploadKey662=== CONT TestProxyWriteTimeout663=== RUN TestProxyWriteTimeout/narinfo664=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle665=== CONT TestSkippedUploadsHandler666=== CONT TestParseSize667=== CONT TestService_Rustfstest668=== CONT TestGCMetrics669=== CONT TestPresignedUploadRegisteredBeforeCommit670=== CONT TestObjectStatsTrigger671=== CONT TestCompletedNarNotReofferedAcrossClosures672=== CONT TestMultipartCleanup673=== CONT TestCompleteMultipartUpload_ErrorButObjectExists674=== CONT TestServerTLSConfig675=== CONT TestRedundantMultipartUpload676=== CONT TestService_NativeMTLS677=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info678=== RUN TestIsValidUploadKey/narinfo679=== PAUSE TestProxyWriteTimeout/narinfo680=== RUN TestServerTLSConfig/no_client_CA681=== PAUSE TestServerTLSConfig/no_client_CA682=== RUN TestProxyWriteTimeout/1_GiB_nar683=== PAUSE TestProxyWriteTimeout/1_GiB_nar684=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info685=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal686=== PAUSE TestIsValidUploadKey/narinfo687=== RUN TestIsValidUploadKey/nar_zst688--- PASS: TestParseSize (0.00s)689=== CONT TestPush_SignsNarinfosOfItsPendingObjects6902026/09/23 13:01:23 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000691=== RUN TestServerTLSConfig/missing_CA_file692=== RUN TestProxyWriteTimeout/10_GiB_nar693=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal694=== PAUSE TestIsValidUploadKey/nar_zst695=== RUN TestIsValidUploadKey/nar_xz696=== PAUSE TestIsValidUploadKey/nar_xz697=== RUN TestIsValidUploadKey/nar_plain698=== PAUSE TestIsValidUploadKey/nar_plain699=== RUN TestIsValidUploadKey/listing700=== PAUSE TestIsValidUploadKey/listing701=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key702=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key703=== PAUSE TestProxyWriteTimeout/10_GiB_nar704=== PAUSE TestServerTLSConfig/missing_CA_file705=== RUN TestServerTLSConfig/not_a_PEM_file706=== PAUSE TestServerTLSConfig/not_a_PEM_file707=== RUN TestIsValidUploadKey/build_log708=== PAUSE TestIsValidUploadKey/build_log709=== RUN TestIsValidUploadKey/build_log_home-manager_file710=== PAUSE TestIsValidUploadKey/build_log_home-manager_file711=== RUN TestIsValidUploadKey/build_log_plus_in_name712=== PAUSE TestIsValidUploadKey/build_log_plus_in_name713=== RUN TestIsValidUploadKey/build_log_question_mark714=== PAUSE TestIsValidUploadKey/build_log_question_mark715=== RUN TestIsValidUploadKey/build_log_equals716=== PAUSE TestIsValidUploadKey/build_log_equals717=== RUN TestIsValidUploadKey/realisation718=== PAUSE TestIsValidUploadKey/realisation719=== RUN TestIsValidUploadKey/realisation_plus_in_output720=== PAUSE TestIsValidUploadKey/realisation_plus_in_output721=== RUN TestIsValidUploadKey/nix-cache-info722=== PAUSE TestIsValidUploadKey/nix-cache-info723=== RUN TestIsValidUploadKey/index.html724=== PAUSE TestIsValidUploadKey/index.html725=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key726=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key727=== RUN TestProxyWriteTimeout/unknown_size728=== CONT TestPush_RejectsBadRequests729=== RUN TestIsValidUploadKey/narinfo_key,_nar_type730=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type731=== CONT TestMetricsInventory732=== PAUSE TestProxyWriteTimeout/unknown_size733=== RUN TestIsValidUploadKey/nar_key,_narinfo_type734=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type735=== RUN TestIsValidUploadKey/listing_key,_narinfo_type736=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type737=== RUN TestIsValidUploadKey/traversal738=== PAUSE TestIsValidUploadKey/traversal739=== RUN TestIsValidUploadKey/traversal_nar740=== PAUSE TestIsValidUploadKey/traversal_nar741=== RUN TestIsValidUploadKey/absolute742=== PAUSE TestIsValidUploadKey/absolute743=== CONT TestPush_CommitFailsWhenSkippedKeyWasCollected744=== RUN TestIsValidUploadKey/empty_key745=== PAUSE TestIsValidUploadKey/empty_key746=== RUN TestIsValidUploadKey/unknown_type747=== PAUSE TestIsValidUploadKey/unknown_type748=== CONT TestNARDeduplicationMetadataUploadBug749--- PASS: TestSkippedUploadsHandler (0.07s)750=== CONT TestPush_CompleteCommitsEveryRoot751=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts752=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts753=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure754=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure755=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart756=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart757=== CONT TestCreatePendingClosureRejectsOversizedNAR7582026/09/23 13:01:23 INFO Received uploads request method=POST path=/api/pending_closures759--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)760=== CONT TestPush_OverlappingRootsStoreOneRowPerKey7612026-09-23 13:01:23.522 UTC [642] ERROR: relation "goose_db_version" does not exist at character 367622026-09-23 13:01:23.522 UTC [642] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7632026-09-23 13:01:23.534 UTC [644] ERROR: relation "goose_db_version" does not exist at character 367642026-09-23 13:01:23.534 UTC [644] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7652026-09-23 13:01:23.534 UTC [643] ERROR: relation "goose_db_version" does not exist at character 367662026-09-23 13:01:23.534 UTC [643] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7672026-09-23 13:01:23.603 UTC [645] ERROR: relation "goose_db_version" does not exist at character 367682026-09-23 13:01:23.603 UTC [645] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7692026-09-23 13:01:23.605 UTC [646] ERROR: relation "goose_db_version" does not exist at character 367702026-09-23 13:01:23.605 UTC [646] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7712026/09/23 13:01:23 OK 20241026095416_initial_model.sql (51.73ms)7722026/09/23 13:01:23 OK 20241026095416_initial_model.sql (30.5ms)7732026/09/23 13:01:23 OK 20241026095416_initial_model.sql (39.3ms)7742026/09/23 13:01:23 OK 20251210153512_drop_unused_gin_index.sql (5.65ms)7752026/09/23 13:01:23 OK 20251210153512_drop_unused_gin_index.sql (2.82ms)7762026/09/23 13:01:23 OK 20251210153512_drop_unused_gin_index.sql (2.99ms)7772026/09/23 13:01:23 OK 20251218171726_add_pins.sql (6.25ms)7782026/09/23 13:01:23 OK 20251218171726_add_pins.sql (6.63ms)7792026/09/23 13:01:23 OK 20251218171726_add_pins.sql (8.33ms)7802026/09/23 13:01:23 OK 20260628120000_add_object_size_and_stats.sql (7.38ms)7812026/09/23 13:01:23 OK 20260628120000_add_object_size_and_stats.sql (13.13ms)7822026/09/23 13:01:23 OK 20260905000000_add_claims.sql (13.69ms)7832026/09/23 13:01:23 OK 20260628120000_add_object_size_and_stats.sql (31.32ms)7842026/09/23 13:01:23 OK 20260905000000_add_claims.sql (23.27ms)7852026/09/23 13:01:23 OK 20241026095416_initial_model.sql (39.52ms)7862026/09/23 13:01:23 OK 20260920000000_drop_claims.sql (18.08ms)7872026/09/23 13:01:23 OK 20241026095416_initial_model.sql (45.67ms)7882026/09/23 13:01:23 OK 20251210153512_drop_unused_gin_index.sql (5.07ms)7892026/09/23 13:01:23 OK 20260923120000_add_pushes.sql (5.55ms)7902026/09/23 13:01:23 goose: successfully migrated database to version: 202609231200007912026/09/23 13:01:23 OK 20260920000000_drop_claims.sql (7.56ms)7922026/09/23 13:01:23 OK 20260905000000_add_claims.sql (12.81ms)7932026/09/23 13:01:23 OK 20260923120000_add_pushes.sql (5.07ms)7942026/09/23 13:01:23 goose: successfully migrated database to version: 202609231200007952026/09/23 13:01:23 OK 20251218171726_add_pins.sql (6.99ms)7962026/09/23 13:01:23 OK 1_commit_pending_closure.sql (5.24ms)7972026/09/23 13:01:23 OK 20251210153512_drop_unused_gin_index.sql (6.2ms)7982026/09/23 13:01:23 OK 20260920000000_drop_claims.sql (6.91ms)7992026/09/23 13:01:23 OK 2_object_stats_trigger.sql (3.17ms)8002026/09/23 13:01:23 OK 1_commit_pending_closure.sql (5.34ms)8012026-09-23 13:01:23.684 UTC [650] ERROR: relation "goose_db_version" does not exist at character 368022026-09-23 13:01:23.684 UTC [650] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8032026-09-23 13:01:23.685 UTC [651] ERROR: relation "goose_db_version" does not exist at character 368042026-09-23 13:01:23.685 UTC [651] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8052026/09/23 13:01:23 OK 3_commit_push.sql (18.94ms)8062026/09/23 13:01:23 goose: up to current file version: 38072026/09/23 13:01:23 OK 20260628120000_add_object_size_and_stats.sql (22.46ms)8082026/09/23 13:01:23 OK 2_object_stats_trigger.sql (21.67ms)8092026/09/23 13:01:23 OK 20260923120000_add_pushes.sql (23.86ms)8102026/09/23 13:01:23 goose: successfully migrated database to version: 202609231200008112026/09/23 13:01:23 OK 20251218171726_add_pins.sql (21.66ms)8122026/09/23 13:01:23 OK 3_commit_push.sql (3.37ms)8132026/09/23 13:01:23 goose: up to current file version: 38142026/09/23 13:01:23 OK 1_commit_pending_closure.sql (4.33ms)8152026/09/23 13:01:23 OK 20260905000000_add_claims.sql (10.55ms)8162026-09-23 13:01:23.715 UTC [652] ERROR: relation "goose_db_version" does not exist at character 368172026-09-23 13:01:23.715 UTC [652] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8182026-09-23 13:01:23.715 UTC [653] ERROR: relation "goose_db_version" does not exist at character 368192026-09-23 13:01:23.715 UTC [653] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8202026-09-23 13:01:23.716 UTC [655] ERROR: relation "goose_db_version" does not exist at character 368212026-09-23 13:01:23.716 UTC [655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8222026-09-23 13:01:23.716 UTC [654] ERROR: relation "goose_db_version" does not exist at character 368232026-09-23 13:01:23.716 UTC [654] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8242026-09-23 13:01:23.716 UTC [656] ERROR: relation "goose_db_version" does not exist at character 368252026-09-23 13:01:23.716 UTC [656] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8262026/09/23 13:01:23 OK 2_object_stats_trigger.sql (15.55ms)8272026/09/23 13:01:23 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"828--- PASS: TestService_AuthMiddleware (0.38s)829=== CONT TestReadRedirectUsesPublicS3URL8302026/09/23 13:01:23 OK 20260628120000_add_object_size_and_stats.sql (23.32ms)8312026/09/23 13:01:23 OK 3_commit_push.sql (5ms)8322026/09/23 13:01:23 goose: up to current file version: 38332026/09/23 13:01:23 OK 20260920000000_drop_claims.sql (19.08ms)8342026/09/23 13:01:23 OK 20260923120000_add_pushes.sql (7.79ms)8352026/09/23 13:01:23 goose: successfully migrated database to version: 202609231200008362026/09/23 13:01:23 OK 20260905000000_add_claims.sql (9.92ms)8372026-09-23 13:01:23.735 UTC [658] ERROR: relation "goose_db_version" does not exist at character 368382026-09-23 13:01:23.735 UTC [658] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8392026/09/23 13:01:23 OK 20260920000000_drop_claims.sql (4.37ms)8402026/09/23 13:01:23 OK 1_commit_pending_closure.sql (4.85ms)8412026/09/23 13:01:23 OK 20241026095416_initial_model.sql (14.05ms)8422026/09/23 13:01:23 OK 2_object_stats_trigger.sql (2.55ms)8432026/09/23 13:01:23 OK 20260923120000_add_pushes.sql (4.19ms)8442026/09/23 13:01:23 goose: successfully migrated database to version: 202609231200008452026/09/23 13:01:23 OK 20241026095416_initial_model.sql (17.58ms)8462026/09/23 13:01:23 OK 3_commit_push.sql (2.18ms)8472026/09/23 13:01:23 goose: up to current file version: 38482026/09/23 13:01:23 OK 20251210153512_drop_unused_gin_index.sql (3.27ms)8492026-09-23 13:01:23.745 UTC [661] ERROR: relation "goose_db_version" does not exist at character 368502026-09-23 13:01:23.745 UTC [661] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8512026/09/23 13:01:23 OK 20251210153512_drop_unused_gin_index.sql (2.51ms)8522026/09/23 13:01:23 INFO Received uploads request method=POST path=/api/pending_closures8532026/09/23 13:01:23 OK 1_commit_pending_closure.sql (4.73ms)8542026-09-23 13:01:23.749 UTC [663] ERROR: relation "goose_db_version" does not exist at character 368552026-09-23 13:01:23.749 UTC [663] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8562026-09-23 13:01:23.749 UTC [664] ERROR: relation "goose_db_version" does not exist at character 368572026-09-23 13:01:23.749 UTC [664] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8582026/09/23 13:01:23 OK 20251218171726_add_pins.sql (5.08ms)8592026/09/23 13:01:23 OK 20241026095416_initial_model.sql (13.97ms)8602026/09/23 13:01:23 OK 20241026095416_initial_model.sql (14.14ms)8612026/09/23 13:01:23 OK 20241026095416_initial_model.sql (14.2ms)8622026/09/23 13:01:23 OK 20241026095416_initial_model.sql (14.02ms)8632026/09/23 13:01:23 OK 2_object_stats_trigger.sql (2.3ms)8642026/09/23 13:01:23 OK 20241026095416_initial_model.sql (14.15ms)8652026/09/23 13:01:23 OK 20251218171726_add_pins.sql (4.36ms)8662026-09-23 13:01:23.751 UTC [662] ERROR: relation "goose_db_version" does not exist at character 368672026-09-23 13:01:23.751 UTC [662] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8682026/09/23 13:01:23 OK 3_commit_push.sql (1.79ms)8692026/09/23 13:01:23 goose: up to current file version: 38702026-09-23 13:01:23.753 UTC [665] ERROR: relation "goose_db_version" does not exist at character 368712026-09-23 13:01:23.753 UTC [665] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8722026-09-23 13:01:23.753 UTC [666] ERROR: relation "goose_db_version" does not exist at character 368732026-09-23 13:01:23.753 UTC [666] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8742026/09/23 13:01:23 OK 20251210153512_drop_unused_gin_index.sql (3.13ms)8752026/09/23 13:01:23 OK 20251210153512_drop_unused_gin_index.sql (3.07ms)8762026/09/23 13:01:23 OK 20251210153512_drop_unused_gin_index.sql (2.89ms)8772026/09/23 13:01:23 OK 20251210153512_drop_unused_gin_index.sql (3.24ms)8782026/09/23 13:01:23 OK 20251210153512_drop_unused_gin_index.sql (3.08ms)8792026/09/23 13:01:23 OK 20260628120000_add_object_size_and_stats.sql (4.34ms)8802026/09/23 13:01:23 OK 20260628120000_add_object_size_and_stats.sql (5.5ms)8812026-09-23 13:01:23.756 UTC [668] ERROR: relation "goose_db_version" does not exist at character 368822026-09-23 13:01:23.756 UTC [668] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8832026-09-23 13:01:23.757 UTC [669] ERROR: relation "goose_db_version" does not exist at character 368842026-09-23 13:01:23.757 UTC [669] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8852026/09/23 13:01:23 OK 20241026095416_initial_model.sql (11.65ms)8862026/09/23 13:01:23 OK 20251218171726_add_pins.sql (5.05ms)8872026/09/23 13:01:23 OK 20251218171726_add_pins.sql (5.48ms)8882026/09/23 13:01:23 OK 20251218171726_add_pins.sql (5.45ms)8892026/09/23 13:01:23 OK 20260905000000_add_claims.sql (4.25ms)8902026/09/23 13:01:23 OK 20251210153512_drop_unused_gin_index.sql (2.03ms)8912026/09/23 13:01:23 OK 20251218171726_add_pins.sql (5.71ms)8922026/09/23 13:01:23 OK 20260905000000_add_claims.sql (4.14ms)8932026/09/23 13:01:23 OK 20251218171726_add_pins.sql (5.9ms)8942026/09/23 13:01:23 OK 20260920000000_drop_claims.sql (2.6ms)8952026/09/23 13:01:23 OK 20260920000000_drop_claims.sql (3.2ms)8962026/09/23 13:01:23 OK 20260628120000_add_object_size_and_stats.sql (4.69ms)8972026/09/23 13:01:23 OK 20260628120000_add_object_size_and_stats.sql (4.62ms)8982026/09/23 13:01:23 OK 20251218171726_add_pins.sql (3.91ms)8992026/09/23 13:01:23 OK 20260628120000_add_object_size_and_stats.sql (4.17ms)9002026/09/23 13:01:23 OK 20260923120000_add_pushes.sql (2.36ms)9012026/09/23 13:01:23 goose: successfully migrated database to version: 202609231200009022026/09/23 13:01:23 OK 20260628120000_add_object_size_and_stats.sql (4.84ms)9032026/09/23 13:01:23 OK 20260628120000_add_object_size_and_stats.sql (4.71ms)9042026-09-23 13:01:23.765 UTC [670] ERROR: relation "goose_db_version" does not exist at character 369052026-09-23 13:01:23.765 UTC [670] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9062026/09/23 13:01:23 OK 20260923120000_add_pushes.sql (2.21ms)9072026/09/23 13:01:23 goose: successfully migrated database to version: 202609231200009082026/09/23 13:01:23 OK 20241026095416_initial_model.sql (11.57ms)909--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.43s)910=== CONT TestCacheConfigHandlerMaxNarSize911--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)912=== CONT TestReadProxyRangeRequest9132026/09/23 13:01:23 OK 20260905000000_add_claims.sql (4.23ms)9142026/09/23 13:01:23 OK 20260905000000_add_claims.sql (4.2ms)9152026/09/23 13:01:23 OK 1_commit_pending_closure.sql (3.83ms)9162026/09/23 13:01:23 OK 20260905000000_add_claims.sql (4.57ms)9172026/09/23 13:01:23 OK 20251210153512_drop_unused_gin_index.sql (3.02ms)9182026-09-23 13:01:23.770 UTC [671] ERROR: relation "goose_db_version" does not exist at character 369192026-09-23 13:01:23.770 UTC [671] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9202026/09/23 13:01:23 OK 20260905000000_add_claims.sql (4.66ms)9212026/09/23 13:01:23 OK 20241026095416_initial_model.sql (11.52ms)9222026/09/23 13:01:23 OK 1_commit_pending_closure.sql (3.9ms)9232026/09/23 13:01:23 OK 20260628120000_add_object_size_and_stats.sql (5.33ms)9242026/09/23 13:01:23 OK 20260905000000_add_claims.sql (4.7ms)9252026/09/23 13:01:23 OK 20241026095416_initial_model.sql (12.98ms)9262026/09/23 13:01:23 OK 2_object_stats_trigger.sql (1.63ms)9272026/09/23 13:01:23 OK 20260920000000_drop_claims.sql (3.06ms)9282026-09-23 13:01:23.772 UTC [672] ERROR: relation "goose_db_version" does not exist at character 369292026-09-23 13:01:23.772 UTC [672] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9302026/09/23 13:01:23 OK 20260920000000_drop_claims.sql (3.54ms)9312026/09/23 13:01:23 OK 20260920000000_drop_claims.sql (3.51ms)9322026/09/23 13:01:23 OK 2_object_stats_trigger.sql (2.66ms)9332026/09/23 13:01:23 OK 3_commit_push.sql (2.2ms)9342026/09/23 13:01:23 goose: up to current file version: 39352026/09/23 13:01:23 OK 20251210153512_drop_unused_gin_index.sql (3ms)9362026/09/23 13:01:23 OK 20251210153512_drop_unused_gin_index.sql (2.67ms)9372026/09/23 13:01:23 OK 20260920000000_drop_claims.sql (3.3ms)9382026/09/23 13:01:23 OK 20260920000000_drop_claims.sql (3.85ms)9392026/09/23 13:01:23 OK 20260923120000_add_pushes.sql (2.49ms)9402026/09/23 13:01:23 goose: successfully migrated database to version: 202609231200009412026/09/23 13:01:23 OK 20260905000000_add_claims.sql (3.72ms)9422026/09/23 13:01:23 OK 20251218171726_add_pins.sql (4.75ms)9432026/09/23 13:01:23 OK 20241026095416_initial_model.sql (12.11ms)9442026/09/23 13:01:23 OK 3_commit_push.sql (1.7ms)9452026/09/23 13:01:23 goose: up to current file version: 39462026/09/23 13:01:23 OK 20260923120000_add_pushes.sql (2.2ms)9472026/09/23 13:01:23 goose: successfully migrated database to version: 202609231200009482026/09/23 13:01:23 OK 20260923120000_add_pushes.sql (2.14ms)9492026/09/23 13:01:23 goose: successfully migrated database to version: 202609231200009502026/09/23 13:01:23 OK 20241026095416_initial_model.sql (12.15ms)9512026/09/23 13:01:23 OK 20260923120000_add_pushes.sql (2.69ms)9522026/09/23 13:01:23 goose: successfully migrated database to version: 202609231200009532026/09/23 13:01:23 OK 20241026095416_initial_model.sql (13.62ms)9542026/09/23 13:01:23 OK 20241026095416_initial_model.sql (12.17ms)9552026/09/23 13:01:23 OK 20251210153512_drop_unused_gin_index.sql (2.12ms)9562026/09/23 13:01:23 OK 20260920000000_drop_claims.sql (2.75ms)9572026/09/23 13:01:23 OK 1_commit_pending_closure.sql (2.54ms)9582026/09/23 13:01:23 OK 1_commit_pending_closure.sql (3.27ms)9592026/09/23 13:01:23 OK 20260923120000_add_pushes.sql (3.87ms)9602026/09/23 13:01:23 goose: successfully migrated database to version: 202609231200009612026/09/23 13:01:23 OK 1_commit_pending_closure.sql (3.6ms)9622026/09/23 13:01:23 OK 20251218171726_add_pins.sql (5.47ms)9632026/09/23 13:01:23 OK 20251218171726_add_pins.sql (5.38ms)9642026/09/23 13:01:23 OK 20241026095416_initial_model.sql (13.31ms)9652026/09/23 13:01:23 OK 20251210153512_drop_unused_gin_index.sql (2.15ms)9662026/09/23 13:01:23 OK 20251210153512_drop_unused_gin_index.sql (3.13ms)9672026/09/23 13:01:23 OK 20251210153512_drop_unused_gin_index.sql (2.23ms)9682026/09/23 13:01:23 OK 20260923120000_add_pushes.sql (2.05ms)9692026/09/23 13:01:23 goose: successfully migrated database to version: 202609231200009702026/09/23 13:01:23 OK 1_commit_pending_closure.sql (2.9ms)9712026/09/23 13:01:23 OK 2_object_stats_trigger.sql (1.76ms)9722026/09/23 13:01:23 OK 2_object_stats_trigger.sql (1.86ms)9732026/09/23 13:01:23 OK 20260628120000_add_object_size_and_stats.sql (4.98ms)9742026/09/23 13:01:23 OK 1_commit_pending_closure.sql (2.33ms)9752026/09/23 13:01:23 OK 20251218171726_add_pins.sql (3.25ms)9762026/09/23 13:01:23 OK 2_object_stats_trigger.sql (1.39ms)9772026/09/23 13:01:23 OK 3_commit_push.sql (1.34ms)9782026/09/23 13:01:23 goose: up to current file version: 39792026/09/23 13:01:23 OK 20251210153512_drop_unused_gin_index.sql (2.17ms)9802026/09/23 13:01:23 OK 2_object_stats_trigger.sql (1.84ms)9812026/09/23 13:01:23 OK 3_commit_push.sql (1.78ms)9822026/09/23 13:01:23 goose: up to current file version: 39832026/09/23 13:01:23 OK 2_object_stats_trigger.sql (2.43ms)9842026/09/23 13:01:23 OK 3_commit_push.sql (2.39ms)9852026/09/23 13:01:23 goose: up to current file version: 39862026/09/23 13:01:23 OK 20251218171726_add_pins.sql (3.98ms)9872026/09/23 13:01:23 OK 20251218171726_add_pins.sql (4.03ms)9882026/09/23 13:01:23 OK 1_commit_pending_closure.sql (3.6ms)9892026/09/23 13:01:23 OK 20251218171726_add_pins.sql (3.98ms)9902026/09/23 13:01:23 OK 3_commit_push.sql (1.92ms)9912026/09/23 13:01:23 goose: up to current file version: 39922026/09/23 13:01:23 OK 20260628120000_add_object_size_and_stats.sql (5.31ms)9932026/09/23 13:01:23 OK 20260628120000_add_object_size_and_stats.sql (5.16ms)9942026/09/23 13:01:23 OK 20260905000000_add_claims.sql (4.34ms)9952026/09/23 13:01:23 OK 3_commit_push.sql (1.83ms)9962026/09/23 13:01:23 goose: up to current file version: 39972026/09/23 13:01:23 OK 20241026095416_initial_model.sql (10.71ms)9982026/09/23 13:01:23 OK 2_object_stats_trigger.sql (1.6ms)9992026/09/23 13:01:23 OK 20260628120000_add_object_size_and_stats.sql (4.69ms)10002026/09/23 13:01:23 OK 20251218171726_add_pins.sql (3.66ms)10012026/09/23 13:01:23 OK 20260920000000_drop_claims.sql (2.4ms)10022026/09/23 13:01:23 OK 3_commit_push.sql (2.08ms)10032026/09/23 13:01:23 goose: up to current file version: 310042026/09/23 13:01:23 OK 20251210153512_drop_unused_gin_index.sql (2.67ms)10052026/09/23 13:01:23 OK 20260905000000_add_claims.sql (3.84ms)10062026/09/23 13:01:23 OK 20260628120000_add_object_size_and_stats.sql (5ms)10072026/09/23 13:01:23 OK 20260628120000_add_object_size_and_stats.sql (4.83ms)10082026/09/23 13:01:23 OK 20260905000000_add_claims.sql (3.95ms)10092026/09/23 13:01:23 OK 20260628120000_add_object_size_and_stats.sql (4.93ms)10102026/09/23 13:01:23 OK 20260905000000_add_claims.sql (3.7ms)10112026/09/23 13:01:23 INFO Received cleanup request method=DELETE path=/api/pending_closures10122026/09/23 13:01:23 OK 20260628120000_add_object_size_and_stats.sql (4.23ms)10132026/09/23 13:01:23 OK 20260923120000_add_pushes.sql (2.4ms)10142026/09/23 13:01:23 goose: successfully migrated database to version: 2026092312000010152026/09/23 13:01:23 OK 20241026095416_initial_model.sql (10.27ms)10162026/09/23 13:01:23 OK 20241026095416_initial_model.sql (10.82ms)10172026/09/23 13:01:23 OK 20260920000000_drop_claims.sql (3.05ms)10182026/09/23 13:01:23 OK 20251218171726_add_pins.sql (4.34ms)10192026/09/23 13:01:23 OK 20251210153512_drop_unused_gin_index.sql (2.36ms)10202026/09/23 13:01:23 OK 20260905000000_add_claims.sql (3.54ms)10212026/09/23 13:01:23 OK 20260905000000_add_claims.sql (4.13ms)10222026/09/23 13:01:23 OK 20260920000000_drop_claims.sql (3.64ms)10232026/09/23 13:01:23 OK 1_commit_pending_closure.sql (2.79ms)10242026/09/23 13:01:23 OK 20260920000000_drop_claims.sql (3.54ms)10252026/09/23 13:01:23 OK 20260905000000_add_claims.sql (5.14ms)10262026/09/23 13:01:23 OK 20260905000000_add_claims.sql (4.1ms)10272026/09/23 13:01:23 OK 20251210153512_drop_unused_gin_index.sql (2.95ms)10282026/09/23 13:01:23 OK 20260923120000_add_pushes.sql (3.18ms)10292026/09/23 13:01:23 goose: successfully migrated database to version: 2026092312000010302026/09/23 13:01:23 OK 2_object_stats_trigger.sql (1.78ms)10312026/09/23 13:01:23 OK 20260923120000_add_pushes.sql (2.3ms)10322026/09/23 13:01:23 goose: successfully migrated database to version: 2026092312000010332026/09/23 13:01:23 OK 20260923120000_add_pushes.sql (2.45ms)10342026/09/23 13:01:23 INFO Aborted multipart uploads count=010352026/09/23 13:01:23 goose: successfully migrated database to version: 2026092312000010362026/09/23 13:01:23 OK 20260628120000_add_object_size_and_stats.sql (3.92ms)10372026/09/23 13:01:23 OK 20260920000000_drop_claims.sql (2.78ms)10382026/09/23 13:01:23 OK 20260920000000_drop_claims.sql (2.82ms)10392026/09/23 13:01:23 OK 20260920000000_drop_claims.sql (2.18ms)10402026/09/23 13:01:23 OK 3_commit_push.sql (1.26ms)10412026/09/23 13:01:23 goose: up to current file version: 310422026/09/23 13:01:23 OK 20251218171726_add_pins.sql (3.9ms)10432026/09/23 13:01:23 OK 20260920000000_drop_claims.sql (2.7ms)10442026/09/23 13:01:23 OK 1_commit_pending_closure.sql (1.89ms)10452026/09/23 13:01:23 INFO Received uploads request method=POST path=/api/pending_closures10462026/09/23 13:01:23 OK 1_commit_pending_closure.sql (2.22ms)10472026/09/23 13:01:23 OK 20260923120000_add_pushes.sql (2.73ms)10482026/09/23 13:01:23 goose: successfully migrated database to version: 2026092312000010492026/09/23 13:01:23 OK 2_object_stats_trigger.sql (1.97ms)10502026/09/23 13:01:23 OK 20260923120000_add_pushes.sql (2.61ms)10512026/09/23 13:01:23 goose: successfully migrated database to version: 2026092312000010522026/09/23 13:01:23 OK 1_commit_pending_closure.sql (3.38ms)10532026/09/23 13:01:23 OK 20251218171726_add_pins.sql (4.71ms)10542026/09/23 13:01:23 OK 20260923120000_add_pushes.sql (2.67ms)10552026/09/23 13:01:23 goose: successfully migrated database to version: 2026092312000010562026/09/23 13:01:23 OK 20260905000000_add_claims.sql (3.8ms)10572026/09/23 13:01:23 OK 20260923120000_add_pushes.sql (3.11ms)10582026/09/23 13:01:23 goose: successfully migrated database to version: 2026092312000010592026/09/23 13:01:23 OK 3_commit_push.sql (1.15ms)10602026/09/23 13:01:23 goose: up to current file version: 310612026/09/23 13:01:23 OK 2_object_stats_trigger.sql (2.37ms)10622026/09/23 13:01:23 OK 1_commit_pending_closure.sql (1.98ms)10632026/09/23 13:01:23 OK 2_object_stats_trigger.sql (1.55ms)10642026/09/23 13:01:23 OK 20260628120000_add_object_size_and_stats.sql (4.54ms)10652026/09/23 13:01:23 OK 1_commit_pending_closure.sql (2.63ms)10662026/09/23 13:01:23 OK 20260920000000_drop_claims.sql (2.77ms)10672026/09/23 13:01:23 OK 3_commit_push.sql (2.4ms)10682026/09/23 13:01:23 goose: up to current file version: 310692026/09/23 13:01:23 OK 3_commit_push.sql (1.83ms)10702026/09/23 13:01:23 goose: up to current file version: 310712026/09/23 13:01:23 OK 2_object_stats_trigger.sql (2.06ms)10722026/09/23 13:01:23 OK 1_commit_pending_closure.sql (3.06ms)10732026/09/23 13:01:23 OK 1_commit_pending_closure.sql (3.43ms)10742026/09/23 13:01:23 OK 2_object_stats_trigger.sql (1.66ms)10752026/09/23 13:01:23 OK 20260923120000_add_pushes.sql (1.96ms)10762026/09/23 13:01:23 goose: successfully migrated database to version: 2026092312000010772026/09/23 13:01:23 OK 20260628120000_add_object_size_and_stats.sql (5.17ms)10782026/09/23 13:01:23 OK 3_commit_push.sql (1.46ms)10792026/09/23 13:01:23 goose: up to current file version: 310802026/09/23 13:01:23 OK 20260905000000_add_claims.sql (3.36ms)10812026/09/23 13:01:23 OK 2_object_stats_trigger.sql (2.12ms)10822026/09/23 13:01:23 OK 3_commit_push.sql (1.69ms)10832026/09/23 13:01:23 goose: up to current file version: 310842026/09/23 13:01:23 OK 2_object_stats_trigger.sql (2.11ms)10852026/09/23 13:01:23 OK 3_commit_push.sql (1.39ms)10862026/09/23 13:01:23 goose: up to current file version: 310872026/09/23 13:01:23 OK 1_commit_pending_closure.sql (2.74ms)10882026/09/23 13:01:23 OK 3_commit_push.sql (1.85ms)10892026/09/23 13:01:23 goose: up to current file version: 310902026/09/23 13:01:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10912026/09/23 13:01:23 OK 20260905000000_add_claims.sql (3.27ms)10922026/09/23 13:01:23 INFO Received cleanup request method=DELETE path=/api/pending_closures10932026/09/23 13:01:23 OK 20260920000000_drop_claims.sql (3.02ms)10942026/09/23 13:01:23 OK 2_object_stats_trigger.sql (1.09ms)10952026/09/23 13:01:23 OK 20260920000000_drop_claims.sql (2.53ms)10962026/09/23 13:01:23 INFO Aborted multipart uploads count=110972026/09/23 13:01:23 OK 20260923120000_add_pushes.sql (2.56ms)10982026/09/23 13:01:23 goose: successfully migrated database to version: 2026092312000010992026/09/23 13:01:23 OK 3_commit_push.sql (2.2ms)11002026/09/23 13:01:23 goose: up to current file version: 311012026/09/23 13:01:23 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1102--- PASS: TestCompleteMultipartUnregistered (0.47s)1103=== CONT TestGenerateLandingPage1104--- PASS: TestGenerateLandingPage (0.00s)1105=== CONT TestReadRedirectKeepsNarinfoProxied11062026/09/23 13:01:23 OK 20260923120000_add_pushes.sql (10.03ms)11072026/09/23 13:01:23 goose: successfully migrated database to version: 2026092312000011082026/09/23 13:01:23 OK 1_commit_pending_closure.sql (11.51ms)11092026/09/23 13:01:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11102026/09/23 13:01:23 OK 1_commit_pending_closure.sql (2.15ms)11112026-09-23 13:01:23.824 UTC [646] ERROR: Closure does not exist: id=111122026-09-23 13:01:23.824 UTC [646] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE11132026-09-23 13:01:23.824 UTC [646] STATEMENT: -- name: CommitPendingClosure :exec1114 SELECT commit_pending_closure($1::bigint)1115 1116--- PASS: TestService_cleanupPendingClosuresHandler (0.48s)1117=== CONT TestService_readinessHandler11182026/09/23 13:01:23 OK 2_object_stats_trigger.sql (1.46ms)11192026/09/23 13:01:23 OK 2_object_stats_trigger.sql (1.66ms)11202026/09/23 13:01:23 OK 3_commit_push.sql (1.4ms)11212026/09/23 13:01:23 goose: up to current file version: 311222026/09/23 13:01:23 OK 3_commit_push.sql (1.68ms)11232026/09/23 13:01:23 goose: up to current file version: 311242026/09/23 13:01:23 INFO Received uploads request method=POST path=/api/pending_closures11252026-09-23 13:01:23.843 UTC [679] ERROR: relation "goose_db_version" does not exist at character 3611262026-09-23 13:01:23.843 UTC [679] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11272026/09/23 13:01:23 INFO Received uploads request method=POST path=/api/pending_closures11282026/09/23 13:01:23 OK 20241026095416_initial_model.sql (8.4ms)11292026/09/23 13:01:23 OK 20251210153512_drop_unused_gin_index.sql (1.88ms)11302026/09/23 13:01:23 OK 20251218171726_add_pins.sql (2.44ms)1131--- PASS: TestService_Rustfstest (0.52s)11322026/09/23 13:01:23 OK 20260628120000_add_object_size_and_stats.sql (3.14ms)1133=== CONT TestReadRedirectNar11342026-09-23 13:01:23.867 UTC [680] ERROR: relation "goose_db_version" does not exist at character 3611352026-09-23 13:01:23.867 UTC [680] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11362026/09/23 13:01:23 OK 20260905000000_add_claims.sql (2.53ms)11372026/09/23 13:01:23 OK 20260920000000_drop_claims.sql (1.9ms)11382026/09/23 13:01:23 OK 20260923120000_add_pushes.sql (1.81ms)11392026/09/23 13:01:23 goose: successfully migrated database to version: 2026092312000011402026/09/23 13:01:23 OK 1_commit_pending_closure.sql (2.08ms)11412026/09/23 13:01:23 OK 2_object_stats_trigger.sql (1.45ms)11422026/09/23 13:01:23 OK 3_commit_push.sql (1.88ms)11432026/09/23 13:01:23 goose: up to current file version: 311442026/09/23 13:01:23 OK 20241026095416_initial_model.sql (9.48ms)11452026/09/23 13:01:23 OK 20251210153512_drop_unused_gin_index.sql (1.79ms)11462026/09/23 13:01:23 INFO Received uploads request method=POST path=/api/pending_closures11472026/09/23 13:01:23 OK 20251218171726_add_pins.sql (2.77ms)11482026/09/23 13:01:23 OK 20260628120000_add_object_size_and_stats.sql (3.84ms)11492026/09/23 13:01:23 OK 20260905000000_add_claims.sql (3.35ms)11502026/09/23 13:01:23 OK 20260920000000_drop_claims.sql (2.76ms)11512026/09/23 13:01:23 OK 20260923120000_add_pushes.sql (2.53ms)11522026/09/23 13:01:23 goose: successfully migrated database to version: 2026092312000011532026/09/23 13:01:23 OK 1_commit_pending_closure.sql (2.29ms)11542026/09/23 13:01:23 OK 2_object_stats_trigger.sql (1.49ms)11552026/09/23 13:01:23 OK 3_commit_push.sql (1.55ms)11562026/09/23 13:01:23 goose: up to current file version: 311572026/09/23 13:01:23 INFO Received uploads request method=POST path=/api/pending_closures11582026-09-23 13:01:23.916 UTC [683] ERROR: relation "goose_db_version" does not exist at character 3611592026-09-23 13:01:23.916 UTC [683] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11602026-09-23 13:01:23.919 UTC [684] ERROR: relation "goose_db_version" does not exist at character 3611612026-09-23 13:01:23.919 UTC [684] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11622026/09/23 13:01:23 INFO Received cleanup request method=DELETE path=/api/pending_closures11632026/09/23 13:01:23 INFO Received uploads request method=POST path=/api/pending_closures11642026/09/23 13:01:23 INFO Aborted multipart uploads count=111652026/09/23 13:01:23 OK 20241026095416_initial_model.sql (19.69ms)11662026/09/23 13:01:23 OK 20241026095416_initial_model.sql (19.63ms)11672026/09/23 13:01:23 OK 20251210153512_drop_unused_gin_index.sql (1.63ms)11682026/09/23 13:01:23 OK 20251210153512_drop_unused_gin_index.sql (1.73ms)1169--- PASS: TestMultipartCleanup (0.61s)1170=== CONT TestService_healthCheckHandler11712026/09/23 13:01:23 OK 20251218171726_add_pins.sql (3.29ms)11722026/09/23 13:01:23 OK 20251218171726_add_pins.sql (3.22ms)11732026/09/23 13:01:23 OK 20260628120000_add_object_size_and_stats.sql (2.91ms)11742026/09/23 13:01:23 OK 20260628120000_add_object_size_and_stats.sql (3.08ms)11752026/09/23 13:01:23 OK 20260905000000_add_claims.sql (3.03ms)11762026/09/23 13:01:23 OK 20260905000000_add_claims.sql (3.53ms)11772026/09/23 13:01:23 OK 20260920000000_drop_claims.sql (2.09ms)11782026/09/23 13:01:23 OK 20260920000000_drop_claims.sql (2.67ms)11792026/09/23 13:01:23 OK 20260923120000_add_pushes.sql (1.1ms)11802026/09/23 13:01:23 goose: successfully migrated database to version: 2026092312000011812026/09/23 13:01:23 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11822026/09/23 13:01:23 INFO Received uploads request method=POST path=/api/pending_closures11832026/09/23 13:01:23 OK 20260923120000_add_pushes.sql (1.84ms)11842026/09/23 13:01:23 goose: successfully migrated database to version: 2026092312000011852026-09-23 13:01:23.972 UTC [687] ERROR: relation "goose_db_version" does not exist at character 3611862026-09-23 13:01:23.972 UTC [687] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1187--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.63s)11882026/09/23 13:01:23 OK 1_commit_pending_closure.sql (2.98ms)1189=== CONT TestReadProxyDisabled11902026/09/23 13:01:23 OK 1_commit_pending_closure.sql (2.26ms)11912026/09/23 13:01:23 OK 2_object_stats_trigger.sql (857.27µs)11922026/09/23 13:01:23 OK 2_object_stats_trigger.sql (828.89µs)11932026/09/23 13:01:23 OK 3_commit_push.sql (860.82µs)11942026/09/23 13:01:23 goose: up to current file version: 311952026/09/23 13:01:23 OK 3_commit_push.sql (933.34µs)11962026/09/23 13:01:23 goose: up to current file version: 311972026/09/23 13:01:23 INFO Aborted multipart uploads count=011982026/09/23 13:01:23 WARN Force mode enabled - objects will be deleted immediately without grace period11992026/09/23 13:01:23 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=012002026/09/23 13:01:23 INFO Vacuumed table table=pending_closures12012026/09/23 13:01:23 INFO Vacuumed table table=pending_objects12022026/09/23 13:01:23 INFO Vacuumed table table=multipart_uploads12032026/09/23 13:01:23 INFO Vacuumed table table=closures12042026/09/23 13:01:23 INFO Vacuumed table table=objects12052026/09/23 13:01:24 OK 20241026095416_initial_model.sql (21.93ms)1206--- PASS: TestGCMetrics (0.66s)1207=== CONT TestGracefulShutdownDrainsInflight12082026/09/23 13:01:24 INFO Starting HTTP server address=127.0.0.1:4369112092026/09/23 13:01:24 INFO Shutdown signal received, draining in-flight requests timeout=10s12102026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (24.85ms)12112026/09/23 13:01:24 OK 20251218171726_add_pins.sql (10.45ms)12122026/09/23 13:01:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12132026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (7.67ms)12142026/09/23 13:01:24 OK 20260905000000_add_claims.sql (4.5ms)12152026/09/23 13:01:24 INFO Received uploads request method=POST path=/api/pending_closures12162026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (3.27ms)12172026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (2.74ms)12182026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000012192026/09/23 13:01:24 OK 1_commit_pending_closure.sql (2.65ms)12202026/09/23 13:01:24 OK 2_object_stats_trigger.sql (1.68ms)12212026-09-23 13:01:24.059 UTC [693] ERROR: relation "goose_db_version" does not exist at character 3612222026-09-23 13:01:24.059 UTC [693] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12232026/09/23 13:01:24 OK 3_commit_push.sql (1.53ms)12242026/09/23 13:01:24 goose: up to current file version: 312252026/09/23 13:01:24 INFO Received uploads request method=POST path=/api/pending_closures12262026/09/23 13:01:24 OK 20241026095416_initial_model.sql (7.54ms)1227--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1228=== CONT TestReadProxyRootRedirectsToIndexHTML12292026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (1.68ms)12302026/09/23 13:01:24 OK 20251218171726_add_pins.sql (2.46ms)12312026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (3.32ms)12322026/09/23 13:01:24 OK 20260905000000_add_claims.sql (3.18ms)1233--- PASS: TestObjectStatsTrigger (0.74s)1234=== CONT TestGCTaskStore_Fail1235--- PASS: TestGCTaskStore_Fail (0.00s)1236=== CONT TestReadProxyConditionalGet12372026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (2.11ms)12382026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (2.04ms)12392026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000012402026/09/23 13:01:24 OK 1_commit_pending_closure.sql (2.2ms)12412026/09/23 13:01:24 OK 2_object_stats_trigger.sql (1.38ms)1242=== RUN TestPush_RejectsBadRequests/root_not_in_objects1243=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1244=== RUN TestPush_RejectsBadRequests/no_roots1245=== PAUSE TestPush_RejectsBadRequests/no_roots1246=== RUN TestPush_RejectsBadRequests/no_objects1247=== PAUSE TestPush_RejectsBadRequests/no_objects1248=== RUN TestPush_RejectsBadRequests/bad_root1249=== PAUSE TestPush_RejectsBadRequests/bad_root1250=== CONT TestGCTaskStore_PhaseUpdates1251--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)12522026/09/23 13:01:24 OK 3_commit_push.sql (1.37ms)1253=== CONT TestReadProxyHead12542026/09/23 13:01:24 goose: up to current file version: 312552026-09-23 13:01:24.117 UTC [703] ERROR: relation "goose_db_version" does not exist at character 3612562026-09-23 13:01:24.117 UTC [703] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1257=== NAME TestOrphanedObjectsGC1258 orphaned_objects_gc_test.go:290: GC Test Summary:1259 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1260 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1261 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1262 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1263 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1264--- PASS: TestOrphanedObjectsGC (0.79s)1265=== CONT TestReadProxyInvalidPath12662026/09/23 13:01:24 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12672026/09/23 13:01:24 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1268--- PASS: TestService_NativeMTLS (0.80s)1269=== CONT TestGCTaskStore_CompletedAllowsNewTask1270--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1271=== CONT TestReadProxy40412722026/09/23 13:01:24 OK 20241026095416_initial_model.sql (29ms)12732026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (5.4ms)1274=== NAME TestNARDeduplicationMetadataUploadBug1275 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2609773704/001/store/dhf5qwhdz89abxp2qsclm3r8ll6qpbm8-file1.txt12762026/09/23 13:01:24 OK 20251218171726_add_pins.sql (3.84ms)12772026/09/23 13:01:24 INFO Received push request method=POST path=/api/pushes12782026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (4.79ms)12792026/09/23 13:01:24 OK 20260905000000_add_claims.sql (4.14ms)12802026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (3.44ms)12812026-09-23 13:01:24.178 UTC [733] ERROR: relation "goose_db_version" does not exist at character 3612822026-09-23 13:01:24.178 UTC [733] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12832026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (2.66ms)12842026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000012852026/09/23 13:01:24 OK 1_commit_pending_closure.sql (2.32ms)12862026/09/23 13:01:24 OK 2_object_stats_trigger.sql (1.98ms)12872026/09/23 13:01:24 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12882026/09/23 13:01:24 INFO Signed narinfos id=1 count=11289--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.84s)1290=== CONT TestGCTaskStore_GetReturnsLatest12912026/09/23 13:01:24 OK 3_commit_push.sql (1.2ms)1292--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)12932026/09/23 13:01:24 goose: up to current file version: 31294=== CONT TestReadProxyNarStreaming12952026/09/23 13:01:24 INFO Received push request method=POST path=/api/pushes12962026/09/23 13:01:24 OK 20241026095416_initial_model.sql (8.72ms)12972026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (1.22ms)12982026/09/23 13:01:24 OK 20251218171726_add_pins.sql (2.87ms)12992026-09-23 13:01:24.199 UTC [742] ERROR: relation "goose_db_version" does not exist at character 3613002026-09-23 13:01:24.199 UTC [742] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13012026-09-23 13:01:24.199 UTC [737] ERROR: relation "goose_db_version" does not exist at character 3613022026-09-23 13:01:24.199 UTC [737] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13032026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (3.57ms)13042026/09/23 13:01:24 OK 20260905000000_add_claims.sql (3.69ms)13052026/09/23 13:01:24 INFO Received uploads request method=POST path=/api/pending_closures13062026/09/23 13:01:24 INFO Received uploads request method=POST path=/api/pending_closures13072026/09/23 13:01:24 INFO Received uploads request method=POST path=/api/pending_closures13082026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (2.52ms)13092026/09/23 13:01:24 INFO Received complete push request method=POST path=/api/pushes/1/complete13102026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (3.11ms)13112026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000013122026/09/23 13:01:24 OK 1_commit_pending_closure.sql (2.62ms)13132026/09/23 13:01:24 OK 20241026095416_initial_model.sql (10.29ms)13142026/09/23 13:01:24 OK 2_object_stats_trigger.sql (1.52ms)13152026/09/23 13:01:24 OK 20241026095416_initial_model.sql (10.08ms)13162026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (1.61ms)13172026/09/23 13:01:24 OK 3_commit_push.sql (1.9ms)13182026/09/23 13:01:24 goose: up to current file version: 313192026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (2.04ms)13202026/09/23 13:01:24 INFO Received push request method=POST path=/api/pushes13212026/09/23 13:01:24 OK 20251218171726_add_pins.sql (3.76ms)13222026/09/23 13:01:24 INFO Received uploads request method=POST path=/api/pending_closures13232026/09/23 13:01:24 OK 20251218171726_add_pins.sql (11.13ms)13242026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (11.2ms)13252026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (4.03ms)13262026/09/23 13:01:24 OK 20260905000000_add_claims.sql (3.33ms)13272026/09/23 13:01:24 OK 20260905000000_add_claims.sql (2.93ms)13282026/09/23 13:01:24 INFO Received complete push request method=POST path=/api/pushes/2/complete13292026-09-23 13:01:24.237 UTC [755] ERROR: Push object missing: aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo13302026-09-23 13:01:24.237 UTC [755] CONTEXT: PL/pgSQL function commit_push(bigint) line 37 at RAISE13312026-09-23 13:01:24.237 UTC [755] STATEMENT: -- name: CommitPush :exec1332 SELECT commit_push($1::bigint)1333 13342026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (1.8ms)13352026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (1.66ms)1336--- PASS: TestPush_CommitFailsWhenSkippedKeyWasCollected (0.83s)1337=== CONT TestGCTaskStore_GetEmpty1338--- PASS: TestGCTaskStore_GetEmpty (0.00s)1339=== CONT TestReadProxyNarinfoAlreadyDecompressed13402026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (1.96ms)13412026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000013422026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (2.19ms)13432026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000013442026/09/23 13:01:24 OK 1_commit_pending_closure.sql (1.44ms)13452026/09/23 13:01:24 OK 1_commit_pending_closure.sql (1.55ms)13462026/09/23 13:01:24 OK 2_object_stats_trigger.sql (867.24µs)13472026/09/23 13:01:24 OK 2_object_stats_trigger.sql (901.06µs)13482026-09-23 13:01:24.243 UTC [757] ERROR: relation "goose_db_version" does not exist at character 3613492026-09-23 13:01:24.243 UTC [757] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13502026/09/23 13:01:24 OK 3_commit_push.sql (1.54ms)13512026/09/23 13:01:24 goose: up to current file version: 313522026/09/23 13:01:24 OK 3_commit_push.sql (1.04ms)13532026/09/23 13:01:24 goose: up to current file version: 313542026-09-23 13:01:24.251 UTC [777] ERROR: relation "goose_db_version" does not exist at character 3613552026-09-23 13:01:24.251 UTC [777] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13562026/09/23 13:01:24 INFO Received push request method=POST path=/api/pushes13572026/09/23 13:01:24 INFO Received uploads request method=POST path=/api/pending_closures13582026/09/23 13:01:24 OK 20241026095416_initial_model.sql (9.64ms)13592026/09/23 13:01:24 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13602026/09/23 13:01:24 INFO Uploading dhf5qwhdz89abxp2qsclm3r8ll6qpbm8-file1.txt (160B)13612026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (2.1ms)13622026/09/23 13:01:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13632026/09/23 13:01:24 OK 20251218171726_add_pins.sql (3.63ms)13642026/09/23 13:01:24 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"13652026/09/23 13:01:24 WARN Failed to register uploaded object key=dhf5qwhdz89abxp2qsclm3r8ll6qpbm8.ls error="server returned 404: 404 page not found\n"13662026/09/23 13:01:24 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13672026/09/23 13:01:24 INFO Signed narinfos id=1 count=113682026/09/23 13:01:24 OK 20241026095416_initial_model.sql (10.15ms)13692026/09/23 13:01:24 INFO Uploading 1 narinfos13702026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (2.13ms)13712026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (4.51ms)13722026/09/23 13:01:24 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NTY2YjA4NGItNTgwYy00ZWJjLTliNTEtMjViNTU0MGRiYzcyLmZmYTMyMmVlLTMxZjUtNDQzMS05NzdlLTBkMDQxYzdhZTg1N3gxNzkwMTY4NDg0MjQxNzc2OTQ413732026/09/23 13:01:24 OK 20251218171726_add_pins.sql (2.8ms)13742026/09/23 13:01:24 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13752026/09/23 13:01:24 WARN Failed to register uploaded object key=dhf5qwhdz89abxp2qsclm3r8ll6qpbm8.narinfo error="server returned 404: 404 page not found\n"13762026/09/23 13:01:24 OK 20260905000000_add_claims.sql (2.34ms)13772026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (1.85ms)1378--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.80s)1379=== CONT TestGCTaskStore_ConflictDifferentParams1380--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)13812026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (2.99ms)1382=== CONT TestReadProxyNarinfo13832026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (1.11ms)13842026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000013852026/09/23 13:01:24 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NTY2YjA4NGItNTgwYy00ZWJjLTliNTEtMjViNTU0MGRiYzcyLmZmYTMyMmVlLTMxZjUtNDQzMS05NzdlLTBkMDQxYzdhZTg1N3gxNzkwMTY4NDg0MjQxNzc2OTQ4 parts=11386--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.94s)1387=== CONT TestGCTaskStore_DeduplicateSameParams1388--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1389=== CONT TestIsValidCachePath13902026/09/23 13:01:24 OK 1_commit_pending_closure.sql (1.63ms)1391=== RUN TestIsValidCachePath/narinfo1392=== PAUSE TestIsValidCachePath/narinfo1393=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1394=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1395=== RUN TestIsValidCachePath/nar_zst1396=== PAUSE TestIsValidCachePath/nar_zst1397=== RUN TestIsValidCachePath/nar_xz1398=== PAUSE TestIsValidCachePath/nar_xz1399=== RUN TestIsValidCachePath/nar_bz21400=== PAUSE TestIsValidCachePath/nar_bz21401=== RUN TestIsValidCachePath/nar_uncompressed1402=== PAUSE TestIsValidCachePath/nar_uncompressed1403=== RUN TestIsValidCachePath/ls1404=== PAUSE TestIsValidCachePath/ls1405=== RUN TestIsValidCachePath/log1406=== PAUSE TestIsValidCachePath/log1407=== RUN TestIsValidCachePath/realisation1408=== PAUSE TestIsValidCachePath/realisation14092026/09/23 13:01:24 OK 20260905000000_add_claims.sql (2.68ms)1410=== RUN TestIsValidCachePath/nix-cache-info1411=== PAUSE TestIsValidCachePath/nix-cache-info1412=== RUN TestIsValidCachePath/index.html1413=== PAUSE TestIsValidCachePath/index.html1414=== RUN TestIsValidCachePath/traversal_parent1415=== PAUSE TestIsValidCachePath/traversal_parent1416=== RUN TestIsValidCachePath/traversal_in_middle1417=== PAUSE TestIsValidCachePath/traversal_in_middle1418=== RUN TestIsValidCachePath/invalid_char_e1419=== PAUSE TestIsValidCachePath/invalid_char_e1420=== RUN TestIsValidCachePath/invalid_char_u1421=== PAUSE TestIsValidCachePath/invalid_char_u1422=== RUN TestIsValidCachePath/random_path1423=== PAUSE TestIsValidCachePath/random_path1424=== RUN TestIsValidCachePath/empty1425=== PAUSE TestIsValidCachePath/empty1426=== RUN TestIsValidCachePath/leading_slash1427=== PAUSE TestIsValidCachePath/leading_slash1428=== RUN TestIsValidCachePath/wrong_extension1429=== PAUSE TestIsValidCachePath/wrong_extension1430=== RUN TestIsValidCachePath/short_hash14312026/09/23 13:01:24 OK 2_object_stats_trigger.sql (1.68ms)1432=== PAUSE TestIsValidCachePath/short_hash1433=== CONT TestGCTaskStore_StartNew1434--- PASS: TestGCTaskStore_StartNew (0.00s)1435=== CONT TestProxyHeadersOnlyTrustedOnSocket14362026/09/23 13:01:24 INFO Completed upload id=114372026/09/23 13:01:24 OK 3_commit_push.sql (705.38µs)14382026/09/23 13:01:24 goose: up to current file version: 314392026/09/23 13:01:24 INFO Upload complete. (76ms)14402026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (2.11ms)1441=== NAME TestNARDeduplicationMetadataUploadBug1442 metadata_upload_test.go:54: Retrieved narinfo from S3:1443 StorePath: /build/TestNARDeduplicationMetadataUploadBug2609773704/001/store/dhf5qwhdz89abxp2qsclm3r8ll6qpbm8-file1.txt1444 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1445 Compression: zstd1446 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1447 NarSize: 16014482026-09-23 13:01:24.286 UTC [781] ERROR: relation "goose_db_version" does not exist at character 3614492026-09-23 13:01:24.286 UTC [781] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1450 References: 1451 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf14522026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (1.63ms)14532026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000014542026/09/23 13:01:24 OK 1_commit_pending_closure.sql (1.63ms)1455 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1456 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1457 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}14582026/09/23 13:01:24 OK 2_object_stats_trigger.sql (1.73ms)14592026/09/23 13:01:24 OK 3_commit_push.sql (901.61µs)14602026/09/23 13:01:24 goose: up to current file version: 314612026/09/23 13:01:24 INFO Received push request method=POST path=/api/pushes14622026/09/23 13:01:24 OK 20241026095416_initial_model.sql (9.75ms)1463--- PASS: TestMetricsInventory (0.89s)1464=== CONT TestResurrectedObjectNotDeleted14652026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (1.99ms)14662026/09/23 13:01:24 OK 20251218171726_add_pins.sql (3.18ms)14672026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (3.83ms)14682026/09/23 13:01:24 OK 20260905000000_add_claims.sql (3.19ms)14692026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (3.09ms)14702026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (2.4ms)14712026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000014722026/09/23 13:01:24 INFO Received complete push request method=POST path=/api/pushes/1/complete14732026/09/23 13:01:24 OK 1_commit_pending_closure.sql (3.37ms)14742026/09/23 13:01:24 OK 2_object_stats_trigger.sql (2.41ms)14752026/09/23 13:01:24 OK 3_commit_push.sql (1.45ms)14762026/09/23 13:01:24 goose: up to current file version: 31477=== NAME TestNARDeduplicationMetadataUploadBug1478 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2609773704/001/store/1q72l06f142njn5j7sn23viwn61a7wnv-file2.txt1479--- PASS: TestPush_CompleteCommitsEveryRoot (0.92s)1480=== CONT TestCreatePin_ReservedPins14812026-09-23 13:01:24.341 UTC [807] ERROR: relation "goose_db_version" does not exist at character 3614822026-09-23 13:01:24.341 UTC [807] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1483--- PASS: TestReadRedirectUsesPublicS3URL (0.62s)1484=== CONT TestOrphanedObjectsGCStressTest1485--- PASS: TestReadProxyRangeRequest (0.59s)1486=== CONT TestParseSingleRange1487=== RUN TestParseSingleRange/none1488=== PAUSE TestParseSingleRange/none1489=== RUN TestParseSingleRange/unknown_unit1490=== PAUSE TestParseSingleRange/unknown_unit1491=== RUN TestParseSingleRange/multi-range_ignored1492=== PAUSE TestParseSingleRange/multi-range_ignored1493=== RUN TestParseSingleRange/malformed_no_dash1494=== PAUSE TestParseSingleRange/malformed_no_dash1495=== RUN TestParseSingleRange/malformed_both_empty1496=== PAUSE TestParseSingleRange/malformed_both_empty1497=== RUN TestParseSingleRange/malformed_end_before_start1498=== PAUSE TestParseSingleRange/malformed_end_before_start1499=== RUN TestParseSingleRange/closed1500=== PAUSE TestParseSingleRange/closed1501=== RUN TestParseSingleRange/open-ended1502=== PAUSE TestParseSingleRange/open-ended1503=== RUN TestParseSingleRange/end_clamped_to_size1504=== PAUSE TestParseSingleRange/end_clamped_to_size1505=== RUN TestParseSingleRange/suffix1506=== PAUSE TestParseSingleRange/suffix1507=== RUN TestParseSingleRange/suffix_exceeds_size1508=== PAUSE TestParseSingleRange/suffix_exceeds_size1509=== RUN TestParseSingleRange/single_byte1510=== PAUSE TestParseSingleRange/single_byte1511=== RUN TestParseSingleRange/start_past_EOF1512=== PAUSE TestParseSingleRange/start_past_EOF1513=== RUN TestParseSingleRange/start_far_past_EOF1514=== PAUSE TestParseSingleRange/start_far_past_EOF1515=== CONT TestClientIntegration15162026/09/23 13:01:24 WARN readiness check failed error="closed pool"1517--- PASS: TestService_readinessHandler (0.54s)1518=== CONT TestGCBugBareHashReferences15192026/09/23 13:01:24 OK 20241026095416_initial_model.sql (9.32ms)15202026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (2.9ms)15212026/09/23 13:01:24 OK 20251218171726_add_pins.sql (5.21ms)15222026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (4.51ms)15232026/09/23 13:01:24 OK 20260905000000_add_claims.sql (4.07ms)15242026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (3.15ms)15252026-09-23 13:01:24.394 UTC [832] ERROR: relation "goose_db_version" does not exist at character 3615262026-09-23 13:01:24.394 UTC [832] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15272026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (3.37ms)15282026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000015292026-09-23 13:01:24.395 UTC [833] ERROR: relation "goose_db_version" does not exist at character 3615302026-09-23 13:01:24.395 UTC [833] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1531--- PASS: TestReadRedirectKeepsNarinfoProxied (0.58s)1532=== CONT TestLeadEndsOnShutdown15332026/09/23 13:01:24 OK 1_commit_pending_closure.sql (2.81ms)15342026/09/23 13:01:24 OK 2_object_stats_trigger.sql (2.98ms)15352026/09/23 13:01:24 OK 3_commit_push.sql (1.51ms)15362026/09/23 13:01:24 goose: up to current file version: 315372026/09/23 13:01:24 OK 20241026095416_initial_model.sql (11.61ms)15382026/09/23 13:01:24 INFO Received uploads request method=POST path=/api/pending_closures15392026/09/23 13:01:24 OK 20241026095416_initial_model.sql (11.07ms)15402026/09/23 13:01:24 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)15412026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (2.28ms)15422026-09-23 13:01:24.419 UTC [853] ERROR: relation "goose_db_version" does not exist at character 3615432026-09-23 13:01:24.419 UTC [853] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15442026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (2.69ms)15452026/09/23 13:01:24 WARN Failed to register uploaded object key=1q72l06f142njn5j7sn23viwn61a7wnv.ls error="server returned 404: 404 page not found\n"15462026/09/23 13:01:24 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15472026/09/23 13:01:24 OK 20251218171726_add_pins.sql (4.55ms)15482026/09/23 13:01:24 INFO Signed narinfos id=2 count=115492026/09/23 13:01:24 INFO Uploading 1 narinfos15502026/09/23 13:01:24 OK 20251218171726_add_pins.sql (3.35ms)1551--- PASS: TestReadRedirectNar (0.56s)1552=== CONT TestLeadElectsOneAndHandsOver15532026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (4.77ms)15542026/09/23 13:01:24 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15552026/09/23 13:01:24 WARN Failed to register uploaded object key=1q72l06f142njn5j7sn23viwn61a7wnv.narinfo error="server returned 404: 404 page not found\n"15562026/09/23 13:01:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15572026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (3.35ms)15582026/09/23 13:01:24 INFO Completed upload id=215592026/09/23 13:01:24 INFO Upload complete. (59ms)1560=== NAME TestNARDeduplicationMetadataUploadBug1561 metadata_upload_test.go:76: Retrieved narinfo from S3:1562 StorePath: /build/TestNARDeduplicationMetadataUploadBug2609773704/001/store/1q72l06f142njn5j7sn23viwn61a7wnv-file2.txt1563 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1564 Compression: zstd1565 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1566 NarSize: 1601567 References: 1568 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1569 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1570 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1571 {"version":1,"root":{"type":"regular","size":44}}15722026/09/23 13:01:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1573--- PASS: TestService_healthCheckHandler (0.48s)1574=== CONT TestResolveDBConnectionString1575=== RUN TestResolveDBConnectionString/flag_wins1576=== PAUSE TestResolveDBConnectionString/flag_wins1577=== RUN TestResolveDBConnectionString/file_when_flag_empty1578=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1579=== RUN TestResolveDBConnectionString/missing_file_is_an_error1580=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1581=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1582=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1583=== RUN TestResolveDBConnectionString/nothing_configured1584=== PAUSE TestResolveDBConnectionString/nothing_configured1585=== CONT TestClientFallsBackToClosures1586--- PASS: TestNARDeduplicationMetadataUploadBug (1.03s)1587=== CONT TestClientPushesUseOnePush15882026/09/23 13:01:24 OK 20260905000000_add_claims.sql (15.58ms)15892026/09/23 13:01:24 OK 20260905000000_add_claims.sql (19.25ms)15902026/09/23 13:01:24 OK 20241026095416_initial_model.sql (20.95ms)15912026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (6.81ms)15922026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (4.73ms)15932026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (4.08ms)15942026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000015952026/09/23 13:01:24 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NTY2YjA4NGItNTgwYy00ZWJjLTliNTEtMjViNTU0MGRiYzcyLjEzMTFjMzJmLWQ0YWMtNGIzNy1hZDA1LWI0ODFiZDZlY2JhN3gxNzkwMTY4NDgzOTI4MTY1MTQy parts=1015962026/09/23 13:01:24 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15972026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (7.06ms)15982026/09/23 13:01:24 OK 20251218171726_add_pins.sql (3.75ms)15992026/09/23 13:01:24 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NTY2YjA4NGItNTgwYy00ZWJjLTliNTEtMjViNTU0MGRiYzcyLmU5ODM4YWM1LWFmNGMtNDY3My1hOTFiLWVkM2NiMDljYzUzOHgxNzkwMTY4NDgzODU3NjI1MDU5 parts=1216002026/09/23 13:01:24 OK 1_commit_pending_closure.sql (3.37ms)16012026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (2.81ms)16022026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000016032026/09/23 13:01:24 INFO Received uploads request method=POST path=/api/pending_closures1604--- PASS: TestReadProxyDisabled (0.48s)1605=== CONT TestPinProtectsFromGC16062026/09/23 13:01:24 INFO Completed upload id=116072026/09/23 13:01:24 OK 1_commit_pending_closure.sql (2.93ms)16082026/09/23 13:01:24 OK 2_object_stats_trigger.sql (3.06ms)16092026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (4.3ms)16102026/09/23 13:01:24 INFO Received uploads request method=POST path=/api/pending_closures16112026-09-23 13:01:24.459 UTC [872] ERROR: relation "goose_db_version" does not exist at character 3616122026-09-23 13:01:24.459 UTC [872] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1613--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.12s)1614=== CONT TestClientSharedPathCommittedMidPush16152026/09/23 13:01:24 OK 2_object_stats_trigger.sql (1.72ms)16162026/09/23 13:01:24 OK 3_commit_push.sql (1.66ms)16172026/09/23 13:01:24 goose: up to current file version: 316182026/09/23 13:01:24 INFO Received uploads request method=POST path=/api/pending_closures16192026/09/23 13:01:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44123/oidc16202026/09/23 13:01:24 OK 20260905000000_add_claims.sql (3.26ms)16212026/09/23 13:01:24 OK 3_commit_push.sql (1.6ms)16222026/09/23 13:01:24 goose: up to current file version: 316232026/09/23 13:01:24 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo16242026/09/23 13:01:24 WARN Found objects in DB but missing from S3, will re-upload count=116252026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (3.31ms)1626--- PASS: TestService_verifyS3Integrity (1.13s)1627=== CONT TestClientWithDependencies16282026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (2.99ms)16292026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000016302026-09-23 13:01:24.471 UTC [875] ERROR: relation "goose_db_version" does not exist at character 3616312026-09-23 13:01:24.471 UTC [875] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16322026/09/23 13:01:24 OK 1_commit_pending_closure.sql (2.91ms)16332026/09/23 13:01:24 OK 2_object_stats_trigger.sql (1.84ms)16342026/09/23 13:01:24 OK 3_commit_push.sql (2.83ms)16352026/09/23 13:01:24 goose: up to current file version: 316362026/09/23 13:01:24 OK 20241026095416_initial_model.sql (10.66ms)16372026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (2.1ms)1638--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.41s)1639=== CONT TestClientMultipleUploads16402026-09-23 13:01:24.482 UTC [882] ERROR: relation "goose_db_version" does not exist at character 3616412026-09-23 13:01:24.482 UTC [882] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16422026/09/23 13:01:24 OK 20251218171726_add_pins.sql (4.81ms)16432026/09/23 13:01:24 OK 20241026095416_initial_model.sql (10.61ms)16442026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (5.26ms)16452026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (2.57ms)16462026/09/23 13:01:24 OK 20260905000000_add_claims.sql (3.79ms)16472026/09/23 13:01:24 OK 20251218171726_add_pins.sql (16.01ms)1648--- PASS: TestReadProxyConditionalGet (0.42s)1649=== CONT TestService_ReadScope_PublicByDefault16502026/09/23 13:01:24 OK 20241026095416_initial_model.sql (22.26ms)16512026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (18.17ms)16522026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (2.27ms)16532026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (2.97ms)16542026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000016552026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (10.22ms)16562026/09/23 13:01:24 OK 1_commit_pending_closure.sql (2.83ms)16572026/09/23 13:01:24 OK 20251218171726_add_pins.sql (4.41ms)16582026-09-23 13:01:24.522 UTC [887] ERROR: relation "goose_db_version" does not exist at character 3616592026-09-23 13:01:24.522 UTC [887] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16602026/09/23 13:01:24 OK 2_object_stats_trigger.sql (4.46ms)16612026/09/23 13:01:24 OK 20260905000000_add_claims.sql (5.95ms)16622026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (6.2ms)16632026/09/23 13:01:24 OK 3_commit_push.sql (3.33ms)16642026/09/23 13:01:24 goose: up to current file version: 316652026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (4.03ms)16662026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (3.58ms)16672026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000016682026/09/23 13:01:24 OK 20260905000000_add_claims.sql (6.08ms)1669--- PASS: TestReadProxyHead (0.44s)1670=== CONT TestClientErrorHandling1671=== RUN TestClientErrorHandling/InvalidStorePath1672=== PAUSE TestClientErrorHandling/InvalidStorePath1673=== RUN TestClientErrorHandling/InvalidAuthToken1674=== PAUSE TestClientErrorHandling/InvalidAuthToken1675=== RUN TestClientErrorHandling/ServerNotAvailable1676=== PAUSE TestClientErrorHandling/ServerNotAvailable1677=== CONT TestClientCADerivations16782026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (3.45ms)16792026/09/23 13:01:24 OK 1_commit_pending_closure.sql (4.38ms)16802026/09/23 13:01:24 OK 2_object_stats_trigger.sql (2.12ms)16812026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (4.29ms)16822026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000016832026/09/23 13:01:24 OK 3_commit_push.sql (2.81ms)16842026/09/23 13:01:24 goose: up to current file version: 316852026/09/23 13:01:24 OK 1_commit_pending_closure.sql (2.85ms)1686--- PASS: TestReadProxyInvalidPath (0.42s)1687=== CONT TestCacheStatsHandler16882026/09/23 13:01:24 OK 20241026095416_initial_model.sql (26.65ms)16892026/09/23 13:01:24 OK 2_object_stats_trigger.sql (16.65ms)16902026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (3.94ms)16912026/09/23 13:01:24 OK 3_commit_push.sql (2.99ms)16922026/09/23 13:01:24 goose: up to current file version: 316932026/09/23 13:01:24 OK 20251218171726_add_pins.sql (7.03ms)16942026-09-23 13:01:24.571 UTC [892] ERROR: relation "goose_db_version" does not exist at character 3616952026-09-23 13:01:24.571 UTC [892] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16962026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (6.52ms)1697--- PASS: TestReadProxy404 (0.43s)1698=== CONT TestCacheConfigHandler1699=== RUN TestCacheConfigHandler/full_config,_no_issuer1700=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1701=== RUN TestCacheConfigHandler/no_cache_url_configured1702=== PAUSE TestCacheConfigHandler/no_cache_url_configured1703=== RUN TestCacheConfigHandler/no_signing_keys1704=== PAUSE TestCacheConfigHandler/no_signing_keys1705=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1706=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1707=== CONT TestService_ReadAuthMiddleware17082026-09-23 13:01:24.578 UTC [893] ERROR: relation "goose_db_version" does not exist at character 3617092026-09-23 13:01:24.578 UTC [893] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17102026-09-23 13:01:24.579 UTC [894] ERROR: relation "goose_db_version" does not exist at character 3617112026-09-23 13:01:24.579 UTC [894] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17122026/09/23 13:01:24 OK 20260905000000_add_claims.sql (6.14ms)17132026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (4.52ms)17142026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (5.01ms)17152026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000017162026/09/23 13:01:24 OK 20241026095416_initial_model.sql (12.92ms)17172026/09/23 13:01:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17182026-09-23 13:01:24.599 UTC [897] ERROR: relation "goose_db_version" does not exist at character 3617192026-09-23 13:01:24.599 UTC [897] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17202026-09-23 13:01:24.604 UTC [898] ERROR: relation "goose_db_version" does not exist at character 3617212026-09-23 13:01:24.604 UTC [898] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1722--- PASS: TestReadProxyNarStreaming (0.42s)1723=== CONT TestService_RequireScope_OIDC17242026/09/23 13:01:24 OK 1_commit_pending_closure.sql (18.71ms)17252026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (17.53ms)17262026/09/23 13:01:24 OK 20241026095416_initial_model.sql (27.28ms)17272026/09/23 13:01:24 OK 20241026095416_initial_model.sql (27.27ms)17282026/09/23 13:01:24 OK 20251218171726_add_pins.sql (7.96ms)17292026/09/23 13:01:24 OK 2_object_stats_trigger.sql (8.43ms)17302026-09-23 13:01:24.625 UTC [899] ERROR: relation "goose_db_version" does not exist at character 3617312026-09-23 13:01:24.625 UTC [899] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17322026-09-23 13:01:24.626 UTC [900] ERROR: relation "goose_db_version" does not exist at character 3617332026-09-23 13:01:24.626 UTC [900] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17342026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (12.57ms)17352026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (12.61ms)17362026-09-23 13:01:24.631 UTC [901] ERROR: relation "goose_db_version" does not exist at character 3617372026-09-23 13:01:24.631 UTC [901] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17382026/09/23 13:01:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35719/oidc17392026/09/23 13:01:24 OK 3_commit_push.sql (22.82ms)17402026/09/23 13:01:24 goose: up to current file version: 317412026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (23.17ms)17422026/09/23 13:01:24 OK 20241026095416_initial_model.sql (26.26ms)17432026/09/23 13:01:24 OK 20251218171726_add_pins.sql (27.97ms)17442026/09/23 13:01:24 OK 20251218171726_add_pins.sql (28.04ms)17452026/09/23 13:01:24 OK 20241026095416_initial_model.sql (36.25ms)17462026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (21.4ms)17472026-09-23 13:01:24.670 UTC [904] ERROR: relation "goose_db_version" does not exist at character 3617482026-09-23 13:01:24.670 UTC [904] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17492026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (20.73ms)17502026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (20.84ms)17512026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (20.67ms)17522026/09/23 13:01:24 OK 20260905000000_add_claims.sql (34.71ms)17532026/09/23 13:01:24 OK 20251218171726_add_pins.sql (18.44ms)17542026/09/23 13:01:24 OK 20241026095416_initial_model.sql (25.45ms)17552026/09/23 13:01:24 OK 20241026095416_initial_model.sql (25.51ms)17562026/09/23 13:01:24 OK 20241026095416_initial_model.sql (25.31ms)17572026/09/23 13:01:24 OK 20251218171726_add_pins.sql (6.03ms)17582026/09/23 13:01:24 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NTY2YjA4NGItNTgwYy00ZWJjLTliNTEtMjViNTU0MGRiYzcyLjk4OTBlZDgzLTY5NTAtNDEzMC1hOTVkLWNlZmEyNDQxMTRmZngxNzkwMTY4NDg0MDYzOTY2ODAy parts=1217592026/09/23 13:01:24 OK 20260905000000_add_claims.sql (5.94ms)17602026/09/23 13:01:24 OK 20260905000000_add_claims.sql (6.37ms)17612026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (2.36ms)17622026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (2.28ms)17632026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (2.32ms)17642026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (7.32ms)1765--- PASS: TestRedundantMultipartUpload (1.34s)1766=== CONT TestService_AuthMiddleware_OIDC17672026/09/23 13:01:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17682026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (5.95ms)17692026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (4.73ms)17702026/09/23 13:01:24 OK 20251218171726_add_pins.sql (4.7ms)17712026/09/23 13:01:24 OK 20251218171726_add_pins.sql (4.94ms)17722026/09/23 13:01:24 OK 20251218171726_add_pins.sql (5ms)17732026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (4.76ms)17742026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000017752026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (5.98ms)17762026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (7.08ms)17772026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (3.42ms)17782026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000017792026/09/23 13:01:24 OK 20260905000000_add_claims.sql (4.57ms)1780--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.45s)1781=== CONT TestService_AuthMiddleware_MTLSBoundSubjects17822026-09-23 13:01:24.693 UTC [905] ERROR: relation "goose_db_version" does not exist at character 3617832026-09-23 13:01:24.693 UTC [905] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17842026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (4ms)17852026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (3.66ms)17862026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000017872026/09/23 13:01:24 OK 20241026095416_initial_model.sql (10.28ms)17882026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (3.97ms)17892026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (4.14ms)17902026/09/23 13:01:24 OK 1_commit_pending_closure.sql (3.72ms)17912026-09-23 13:01:24.694 UTC [906] ERROR: relation "goose_db_version" does not exist at character 3617922026-09-23 13:01:24.694 UTC [906] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17932026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (1.89ms)17942026/09/23 13:01:24 OK 1_commit_pending_closure.sql (2.97ms)17952026/09/23 13:01:24 OK 20260905000000_add_claims.sql (5.52ms)17962026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (1.84ms)17972026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000017982026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (2.69ms)17992026/09/23 13:01:24 OK 2_object_stats_trigger.sql (2.32ms)18002026/09/23 13:01:24 OK 20260905000000_add_claims.sql (3.29ms)18012026/09/23 13:01:24 OK 20260905000000_add_claims.sql (3ms)18022026/09/23 13:01:24 OK 1_commit_pending_closure.sql (3.16ms)18032026/09/23 13:01:24 OK 20260905000000_add_claims.sql (2.75ms)18042026/09/23 13:01:24 OK 2_object_stats_trigger.sql (2.11ms)18052026/09/23 13:01:24 OK 1_commit_pending_closure.sql (1.86ms)18062026/09/23 13:01:24 OK 3_commit_push.sql (1.86ms)18072026/09/23 13:01:24 goose: up to current file version: 318082026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (3.38ms)18092026/09/23 13:01:24 OK 2_object_stats_trigger.sql (2.2ms)18102026/09/23 13:01:24 OK 3_commit_push.sql (1.9ms)18112026/09/23 13:01:24 goose: up to current file version: 318122026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (2.58ms)18132026/09/23 13:01:24 OK 20251218171726_add_pins.sql (3.21ms)18142026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (2.39ms)18152026/09/23 13:01:24 OK 2_object_stats_trigger.sql (1.9ms)18162026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (2.76ms)18172026/09/23 13:01:24 OK 3_commit_push.sql (1.5ms)18182026/09/23 13:01:24 goose: up to current file version: 318192026/09/23 13:01:24 OK 3_commit_push.sql (1.89ms)18202026/09/23 13:01:24 goose: up to current file version: 318212026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (3.13ms)18222026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000018232026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (2.34ms)18242026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000018252026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (2.63ms)18262026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000018272026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (2.9ms)18282026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000018292026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (3.25ms)18302026/09/23 13:01:24 OK 1_commit_pending_closure.sql (2.44ms)18312026/09/23 13:01:24 OK 1_commit_pending_closure.sql (2.74ms)18322026/09/23 13:01:24 OK 1_commit_pending_closure.sql (3.5ms)18332026/09/23 13:01:24 OK 1_commit_pending_closure.sql (2.63ms)18342026/09/23 13:01:24 OK 2_object_stats_trigger.sql (1.29ms)18352026/09/23 13:01:24 OK 20260905000000_add_claims.sql (3.09ms)18362026/09/23 13:01:24 OK 2_object_stats_trigger.sql (1.16ms)18372026/09/23 13:01:24 OK 2_object_stats_trigger.sql (1.83ms)18382026/09/23 13:01:24 OK 3_commit_push.sql (1.43ms)18392026/09/23 13:01:24 goose: up to current file version: 318402026/09/23 13:01:24 OK 2_object_stats_trigger.sql (1.94ms)18412026/09/23 13:01:24 OK 3_commit_push.sql (1.32ms)18422026/09/23 13:01:24 goose: up to current file version: 318432026/09/23 13:01:24 OK 20241026095416_initial_model.sql (9.34ms)18442026/09/23 13:01:24 OK 20241026095416_initial_model.sql (8.82ms)18452026-09-23 13:01:24.710 UTC [909] ERROR: relation "goose_db_version" does not exist at character 3618462026-09-23 13:01:24.710 UTC [909] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18472026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (2.44ms)18482026/09/23 13:01:24 OK 3_commit_push.sql (1.64ms)18492026/09/23 13:01:24 goose: up to current file version: 318502026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (1.06ms)18512026/09/23 13:01:24 OK 3_commit_push.sql (1.7ms)18522026/09/23 13:01:24 goose: up to current file version: 318532026/09/23 13:01:24 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NTY2YjA4NGItNTgwYy00ZWJjLTliNTEtMjViNTU0MGRiYzcyLjgwMTA1NGQ0LTQyZmYtNGU2Yi04M2Q5LThkZTI3OGYxY2ZlZXgxNzkwMTY4NDg0MjE1ODk3NDg5 parts=1018542026/09/23 13:01:24 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18552026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (2.12ms)18562026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (2.32ms)18572026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000018582026/09/23 13:01:24 OK 20251218171726_add_pins.sql (4.09ms)1859--- PASS: TestReadProxyNarinfo (0.44s)1860=== CONT TestService_AuthMiddleware_MTLSProxyHeader18612026/09/23 13:01:24 OK 1_commit_pending_closure.sql (3.85ms)18622026/09/23 13:01:24 OK 20251218171726_add_pins.sql (4.36ms)18632026/09/23 13:01:24 INFO Completed upload id=118642026/09/23 13:01:24 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000018652026/09/23 13:01:24 INFO Received uploads request method=POST path=/api/pending_closures18662026/09/23 13:01:24 OK 2_object_stats_trigger.sql (8.99ms)18672026/09/23 13:01:24 INFO Starting HTTP server address=127.0.0.1:4611918682026/09/23 13:01:24 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket2857315404/001/proxy.sock18692026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (15.21ms)18702026/09/23 13:01:24 INFO Starting cleanup of old closures method=DELETE path=/api/closures18712026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (13.8ms)18722026/09/23 13:01:24 OK 20241026095416_initial_model.sql (13.51ms)18732026/09/23 13:01:24 WARN mTLS auth: subject not in bound subjects subject="CN=someone"18742026/09/23 13:01:24 OK 3_commit_push.sql (5.39ms)18752026/09/23 13:01:24 goose: up to current file version: 318762026/09/23 13:01:24 INFO Shutdown signal received, draining in-flight requests timeout=10s1877--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.45s)18782026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (1.8ms)1879=== CONT TestServerTLSConfig/no_client_CA1880=== CONT TestServerTLSConfig/not_a_PEM_file18812026/09/23 13:01:24 OK 20260905000000_add_claims.sql (3.28ms)1882=== CONT TestServerTLSConfig/missing_CA_file1883--- PASS: TestServerTLSConfig (0.06s)1884 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1885 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1886 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1887=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18882026/09/23 13:01:24 INFO Received uploads request method=POST path=/1889=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18902026/09/23 13:01:24 OK 20260905000000_add_claims.sql (4.04ms)18912026/09/23 13:01:24 INFO Received uploads request method=POST path=/1892=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18932026/09/23 13:01:24 INFO Received request for more parts method=POST path=/1894=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18952026/09/23 13:01:24 INFO Received complete multipart upload request method=POST path=/1896--- PASS: TestUploadHandlersRejectInvalidKeys (0.07s)1897 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1898 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1899 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1900 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1901=== CONT TestProxyWriteTimeout/narinfo1902=== CONT TestProxyWriteTimeout/10_GiB_nar1903=== CONT TestProxyWriteTimeout/1_GiB_nar1904=== CONT TestProxyWriteTimeout/unknown_size19052026/09/23 13:01:24 OK 20251218171726_add_pins.sql (2.95ms)1906--- PASS: TestProxyWriteTimeout (0.07s)1907 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1908 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1909 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1910 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1911=== CONT TestIsValidUploadKey/narinfo1912=== CONT TestIsValidUploadKey/realisation_plus_in_output1913=== CONT TestIsValidUploadKey/unknown_type1914=== CONT TestIsValidUploadKey/empty_key1915=== CONT TestIsValidUploadKey/absolute1916=== CONT TestIsValidUploadKey/traversal_nar1917=== CONT TestIsValidUploadKey/traversal1918=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1919=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1920=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1921=== CONT TestIsValidUploadKey/index.html1922=== CONT TestIsValidUploadKey/nix-cache-info1923=== CONT TestIsValidUploadKey/build_log_home-manager_file1924=== CONT TestIsValidUploadKey/realisation1925=== CONT TestIsValidUploadKey/build_log_equals1926=== CONT TestIsValidUploadKey/build_log_question_mark1927=== CONT TestIsValidUploadKey/build_log_plus_in_name1928=== CONT TestIsValidUploadKey/nar_plain1929=== CONT TestIsValidUploadKey/build_log1930=== CONT TestIsValidUploadKey/listing1931=== CONT TestIsValidUploadKey/nar_xz1932=== CONT TestIsValidUploadKey/nar_zst1933--- PASS: TestIsValidUploadKey (0.07s)1934 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1935 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1936 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1937 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1938 --- PASS: TestIsValidUploadKey/absolute (0.00s)1939 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1940 --- PASS: TestIsValidUploadKey/traversal (0.00s)1941 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1942 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1943 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1944 --- PASS: TestIsValidUploadKey/index.html (0.00s)1945 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1946 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1947 --- PASS: TestIsValidUploadKey/realisation (0.00s)1948 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1949 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1950 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1951 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1952 --- PASS: TestIsValidUploadKey/build_log (0.00s)1953 --- PASS: TestIsValidUploadKey/listing (0.00s)1954 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1955 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1956=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts19572026/09/23 13:01:24 INFO Received request for more parts method=POST path=/19582026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (6.08ms)19592026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (5.5ms)19602026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (1.9ms)19612026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000019622026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (2.23ms)19632026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000019642026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (7.04ms)19652026/09/23 13:01:24 OK 1_commit_pending_closure.sql (2.72ms)19662026/09/23 13:01:24 OK 1_commit_pending_closure.sql (2.98ms)19672026/09/23 13:01:24 INFO Aborted multipart uploads count=019682026/09/23 13:01:24 OK 2_object_stats_trigger.sql (1.35ms)19692026/09/23 13:01:24 OK 20260905000000_add_claims.sql (3.48ms)19702026/09/23 13:01:24 OK 2_object_stats_trigger.sql (1.24ms)19712026/09/23 13:01:24 OK 3_commit_push.sql (1.34ms)19722026/09/23 13:01:24 goose: up to current file version: 319732026/09/23 13:01:24 OK 3_commit_push.sql (1.52ms)19742026/09/23 13:01:24 goose: up to current file version: 319752026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (2.85ms)19762026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (2.04ms)19772026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000019782026/09/23 13:01:24 OK 1_commit_pending_closure.sql (2.51ms)19792026/09/23 13:01:24 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=019802026/09/23 13:01:24 OK 2_object_stats_trigger.sql (2.34ms)19812026/09/23 13:01:24 OK 3_commit_push.sql (1.85ms)19822026/09/23 13:01:24 goose: up to current file version: 319832026/09/23 13:01:24 INFO Vacuumed table table=pending_closures19842026/09/23 13:01:24 INFO Vacuumed table table=pending_objects19852026/09/23 13:01:24 INFO Vacuumed table table=multipart_uploads19862026/09/23 13:01:24 INFO Vacuumed table table=closures19872026/09/23 13:01:24 INFO Vacuumed table table=objects19882026/09/23 13:01:24 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001989--- PASS: TestService_createPendingClosureHandler (1.44s)1990=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19912026/09/23 13:01:24 INFO Received complete multipart upload request method=POST path=/1992=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19932026/09/23 13:01:24 INFO Received uploads request method=POST path=/19942026-09-23 13:01:24.793 UTC [913] ERROR: relation "goose_db_version" does not exist at character 3619952026-09-23 13:01:24.793 UTC [913] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19962026-09-23 13:01:24.797 UTC [914] ERROR: relation "goose_db_version" does not exist at character 3619972026-09-23 13:01:24.797 UTC [914] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1998--- PASS: TestResurrectedObjectNotDeleted (0.50s)1999=== CONT TestPush_RejectsBadRequests/root_not_in_objects20002026/09/23 13:01:24 INFO Received push request method=POST path=/api/pushes2001=== CONT TestPush_RejectsBadRequests/no_objects20022026/09/23 13:01:24 INFO Received push request method=POST path=/api/pushes2003=== CONT TestPush_RejectsBadRequests/bad_root20042026/09/23 13:01:24 INFO Received push request method=POST path=/api/pushes2005=== CONT TestPush_RejectsBadRequests/no_roots20062026/09/23 13:01:24 INFO Received push request method=POST path=/api/pushes2007=== CONT TestIsValidCachePath/narinfo2008=== CONT TestIsValidCachePath/index.html2009--- PASS: TestPush_RejectsBadRequests (0.68s)2010 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2011 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2012 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2013 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2014=== CONT TestIsValidCachePath/short_hash2015=== CONT TestIsValidCachePath/wrong_extension2016=== CONT TestIsValidCachePath/leading_slash2017=== CONT TestIsValidCachePath/empty2018=== CONT TestIsValidCachePath/nar_uncompressed2019=== CONT TestIsValidCachePath/traversal_in_middle2020=== CONT TestIsValidCachePath/nix-cache-info2021=== CONT TestIsValidCachePath/invalid_char_e2022=== CONT TestIsValidCachePath/traversal_parent2023=== CONT TestIsValidCachePath/realisation2024=== CONT TestIsValidCachePath/random_path2025=== CONT TestIsValidCachePath/invalid_char_u2026=== CONT TestIsValidCachePath/log2027=== CONT TestIsValidCachePath/ls2028=== CONT TestIsValidCachePath/nar_bz22029=== CONT TestIsValidCachePath/nar_zst2030=== CONT TestIsValidCachePath/nar_xz2031=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2032--- PASS: TestIsValidCachePath (0.00s)2033 --- PASS: TestIsValidCachePath/narinfo (0.00s)2034 --- PASS: TestIsValidCachePath/index.html (0.00s)2035 --- PASS: TestIsValidCachePath/short_hash (0.00s)2036 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2037 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2038 --- PASS: TestIsValidCachePath/empty (0.00s)2039 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2040 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2041 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2042 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2043 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2044 --- PASS: TestIsValidCachePath/realisation (0.00s)2045 --- PASS: TestIsValidCachePath/random_path (0.00s)2046 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2047 --- PASS: TestIsValidCachePath/log (0.00s)2048 --- PASS: TestIsValidCachePath/ls (0.00s)2049 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2050 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2051 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2052 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2053=== CONT TestParseSingleRange/none2054=== CONT TestParseSingleRange/open-ended2055=== CONT TestParseSingleRange/closed20562026/09/23 13:01:24 OK 20241026095416_initial_model.sql (7.55ms)2057=== CONT TestParseSingleRange/malformed_end_before_start2058=== CONT TestParseSingleRange/malformed_both_empty2059=== CONT TestParseSingleRange/malformed_no_dash2060=== CONT TestParseSingleRange/multi-range_ignored2061=== CONT TestParseSingleRange/unknown_unit2062=== CONT TestParseSingleRange/start_past_EOF2063=== CONT TestParseSingleRange/end_clamped_to_size2064=== CONT TestParseSingleRange/single_byte2065=== CONT TestParseSingleRange/suffix_exceeds_size2066=== CONT TestParseSingleRange/suffix2067=== CONT TestParseSingleRange/start_far_past_EOF2068--- PASS: TestParseSingleRange (0.00s)2069 --- PASS: TestParseSingleRange/none (0.00s)2070 --- PASS: TestParseSingleRange/open-ended (0.00s)2071 --- PASS: TestParseSingleRange/closed (0.00s)2072 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2073 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2074 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2075 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2076 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2077 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2078 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2079 --- PASS: TestParseSingleRange/single_byte (0.00s)2080 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2081 --- PASS: TestParseSingleRange/suffix (0.00s)2082 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2083=== CONT TestResolveDBConnectionString/flag_wins2084=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2085=== CONT TestResolveDBConnectionString/nothing_configured2086=== CONT TestResolveDBConnectionString/missing_file_is_an_error2087=== CONT TestResolveDBConnectionString/file_when_flag_empty2088=== CONT TestClientErrorHandling/InvalidStorePath20892026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (963.46µs)2090--- PASS: TestResolveDBConnectionString (0.00s)2091 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2092 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2093 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2094 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2095 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)20962026/09/23 13:01:24 OK 20241026095416_initial_model.sql (7.48ms)20972026/09/23 13:01:24 OK 20251218171726_add_pins.sql (2.08ms)20982026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (920.27µs)20992026-09-23 13:01:24.812 UTC [916] ERROR: relation "goose_db_version" does not exist at character 3621002026-09-23 13:01:24.812 UTC [916] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21012026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (2.46ms)21022026/09/23 13:01:24 OK 20251218171726_add_pins.sql (1.89ms)21032026/09/23 13:01:24 OK 20260905000000_add_claims.sql (2.29ms)21042026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (2.11ms)21052026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (1.63ms)21062026/09/23 13:01:24 OK 20260905000000_add_claims.sql (2.19ms)21072026/09/23 13:01:24 INFO lead: acquired remote=192.0.2.1:123421082026/09/23 13:01:24 INFO lead: released remote=192.0.2.1:12342109--- PASS: TestLeadEndsOnShutdown (0.42s)2110=== CONT TestClientErrorHandling/ServerNotAvailable21112026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (1.75ms)21122026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000021132026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (2.27ms)21142026/09/23 13:01:24 OK 1_commit_pending_closure.sql (1.47ms)21152026/09/23 13:01:24 OK 2_object_stats_trigger.sql (1.24ms)21162026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (2.29ms)21172026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000021182026/09/23 13:01:24 OK 3_commit_push.sql (1.37ms)21192026/09/23 13:01:24 goose: up to current file version: 321202026/09/23 13:01:24 OK 20241026095416_initial_model.sql (8.21ms)21212026/09/23 13:01:24 OK 1_commit_pending_closure.sql (2.59ms)21222026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (1.33ms)21232026/09/23 13:01:24 OK 2_object_stats_trigger.sql (1.13ms)21242026/09/23 13:01:24 OK 3_commit_push.sql (909.67µs)21252026/09/23 13:01:24 goose: up to current file version: 321262026/09/23 13:01:24 OK 20251218171726_add_pins.sql (2.2ms)2127=== CONT TestClientErrorHandling/InvalidAuthToken21282026/09/23 13:01:24 INFO lead: acquired remote=192.0.2.1:123421292026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (3.44ms)2130=== NAME TestClientIntegration2131 client_integration_test.go:286: Created store path: /build/TestClientIntegration3361591072/002/store/vll8ivhchpbgsvpbajvi02sjlp16a8ix-test-file.txt21322026/09/23 13:01:24 OK 20260905000000_add_claims.sql (2.53ms)21332026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (1.78ms)21342026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (1.55ms)21352026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000021362026/09/23 13:01:24 OK 1_commit_pending_closure.sql (1.7ms)21372026/09/23 13:01:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43693/oidc21382026/09/23 13:01:24 OK 2_object_stats_trigger.sql (1.33ms)21392026/09/23 13:01:24 OK 3_commit_push.sql (1.22ms)21402026/09/23 13:01:24 goose: up to current file version: 321412026/09/23 13:01:24 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/present21422026/09/23 13:01:24 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux21432026/09/23 13:01:24 WARN Refused reserved pin name=worker-x86_64-linux21442026/09/23 13:01:24 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux21452026/09/23 13:01:24 INFO Received create pin request method=POST path=/api/pins/my-app21462026/09/23 13:01:24 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux2147--- PASS: TestCreatePin_ReservedPins (0.57s)2148=== CONT TestCacheConfigHandler/full_config,_no_issuer2149=== CONT TestCacheConfigHandler/no_signing_keys2150=== CONT TestCacheConfigHandler/no_cache_url_configured2151=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator21522026-09-23 13:01:24.902 UTC [1030] ERROR: relation "goose_db_version" does not exist at character 3621532026-09-23 13:01:24.902 UTC [1030] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2154--- PASS: TestCacheConfigHandler (0.00s)2155 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2156 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2157 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2158 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)21592026/09/23 13:01:24 INFO Received uploads request method=POST path=/api/pending_closures21602026/09/23 13:01:24 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21612026/09/23 13:01:24 INFO Uploading vll8ivhchpbgsvpbajvi02sjlp16a8ix-test-file.txt (152B)21622026/09/23 13:01:24 OK 20241026095416_initial_model.sql (9.23ms)21632026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (1.37ms)21642026/09/23 13:01:24 WARN Failed to register uploaded object key=vll8ivhchpbgsvpbajvi02sjlp16a8ix.ls error="server returned 404: 404 page not found\n"21652026/09/23 13:01:24 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21662026/09/23 13:01:24 INFO Signed narinfos id=1 count=121672026/09/23 13:01:24 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"21682026/09/23 13:01:24 INFO Uploading 1 narinfos21692026/09/23 13:01:24 OK 20251218171726_add_pins.sql (2.65ms)21702026/09/23 13:01:24 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21712026/09/23 13:01:24 WARN Failed to register uploaded object key=vll8ivhchpbgsvpbajvi02sjlp16a8ix.narinfo error="server returned 404: 404 page not found\n"21722026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (2.8ms)21732026/09/23 13:01:24 OK 20260905000000_add_claims.sql (2.44ms)21742026/09/23 13:01:24 INFO Completed upload id=121752026/09/23 13:01:24 INFO Upload complete. (60ms)21762026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (1.89ms)21772026-09-23 13:01:24.932 UTC [1083] ERROR: relation "goose_db_version" does not exist at character 3621782026-09-23 13:01:24.932 UTC [1083] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21792026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (1.91ms)21802026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000021812026/09/23 13:01:24 OK 1_commit_pending_closure.sql (1.29ms)21822026/09/23 13:01:24 OK 2_object_stats_trigger.sql (572.06µs)21832026/09/23 13:01:24 OK 3_commit_push.sql (557.43µs)21842026/09/23 13:01:24 goose: up to current file version: 321852026-09-23 13:01:24.942 UTC [1103] ERROR: relation "goose_db_version" does not exist at character 3621862026-09-23 13:01:24.942 UTC [1103] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21872026/09/23 13:01:24 OK 20241026095416_initial_model.sql (7.46ms)21882026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (1.4ms)21892026/09/23 13:01:24 OK 20251218171726_add_pins.sql (4.39ms)2190--- PASS: TestService_ReadScope_PublicByDefault (0.44s)21912026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (3.42ms)21922026/09/23 13:01:24 OK 20260905000000_add_claims.sql (5.42ms)21932026/09/23 13:01:24 OK 20241026095416_initial_model.sql (10.46ms)21942026/09/23 13:01:24 OK 20251210153512_drop_unused_gin_index.sql (1.23ms)21952026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (1.74ms)21962026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (1.27ms)21972026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000021982026/09/23 13:01:24 OK 20251218171726_add_pins.sql (2.32ms)21992026/09/23 13:01:24 OK 1_commit_pending_closure.sql (1.81ms)22002026/09/23 13:01:24 OK 2_object_stats_trigger.sql (606.44µs)2201=== NAME TestClientMultipleUploads2202 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads2981102277/001/store/zkdr7z2mhg5lg21ym0n0pqvihq13b5dp-test-file-0.txt22032026/09/23 13:01:24 OK 3_commit_push.sql (591.09µs)22042026/09/23 13:01:24 goose: up to current file version: 322052026/09/23 13:01:24 OK 20260628120000_add_object_size_and_stats.sql (2.61ms)22062026/09/23 13:01:24 INFO All 1 paths already cached22072026/09/23 13:01:24 OK 20260905000000_add_claims.sql (2.62ms)2208=== NAME TestClientIntegration2209 client_integration_test.go:312: Retrieved narinfo from S3:2210 StorePath: /build/TestClientIntegration3361591072/002/store/vll8ivhchpbgsvpbajvi02sjlp16a8ix-test-file.txt2211 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2212 Compression: zstd2213 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12214 NarSize: 1522215 References: 2216 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk122172026/09/23 13:01:24 OK 20260920000000_drop_claims.sql (1.53ms)2218 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2219 client_integration_test.go:313: Decompressed .ls content (64 bytes):2220 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2221 client_integration_test.go:316: Testing garbage collection...22222026/09/23 13:01:24 OK 20260923120000_add_pushes.sql (1.68ms)22232026/09/23 13:01:24 goose: successfully migrated database to version: 2026092312000022242026/09/23 13:01:24 OK 1_commit_pending_closure.sql (1.39ms)22252026/09/23 13:01:24 OK 2_object_stats_trigger.sql (625.21µs)22262026/09/23 13:01:24 OK 3_commit_push.sql (622.94µs)22272026/09/23 13:01:24 goose: up to current file version: 322282026/09/23 13:01:24 INFO lead: released remote=192.0.2.1:12342229--- PASS: TestCacheStatsHandler (0.43s)2230--- PASS: TestService_ReadAuthMiddleware (0.41s)22312026/09/23 13:01:24 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=194.389563ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2232=== NAME TestClientMultipleUploads2233 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads2981102277/001/store/3k5kkyxy9kn64vy2lzqxjq1gn9rhp85n-test-file-1.txt2234=== NAME TestClientWithDependencies2235 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies1820140070/001/store/pywxbwjycylld1izpg7shnmbswaq9hsj-test-script2236=== RUN TestService_RequireScope_OIDC/builder_may_write2237=== PAUSE TestService_RequireScope_OIDC/builder_may_write2238=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2239=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2240=== RUN TestService_RequireScope_OIDC/ops_may_admin2241=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2242=== RUN TestService_RequireScope_OIDC/ops_may_not_write2243=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2244=== RUN TestService_RequireScope_OIDC/reader_may_not_write2245=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2246=== RUN TestService_RequireScope_OIDC/static_token_may_admin2247=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2248=== RUN TestService_RequireScope_OIDC/static_token_may_write2249=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2250=== RUN TestService_RequireScope_OIDC/reader_may_read2251=== PAUSE TestService_RequireScope_OIDC/reader_may_read2252=== RUN TestService_RequireScope_OIDC/writer_implies_read2253=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2254=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2255=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2256=== CONT TestService_RequireScope_OIDC/builder_may_write2257=== CONT TestService_RequireScope_OIDC/static_token_may_admin2258=== CONT TestService_RequireScope_OIDC/static_token_may_write2259=== CONT TestService_RequireScope_OIDC/ops_may_not_write2260=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2261=== CONT TestService_RequireScope_OIDC/ops_may_admin2262=== CONT TestService_RequireScope_OIDC/writer_implies_read2263=== CONT TestService_RequireScope_OIDC/reader_may_read2264=== CONT TestService_RequireScope_OIDC/reader_may_not_write2265=== CONT TestService_RequireScope_OIDC/builder_may_not_admin22662026/09/23 13:01:25 INFO Starting cleanup of old closures method=DELETE path=/api/closures22672026/09/23 13:01:25 INFO Garbage collection started2268--- PASS: TestService_RequireScope_OIDC (0.40s)2269 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2270 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2271 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2272 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2273 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2274 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2275 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2276 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2277 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2278 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)22792026/09/23 13:01:25 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"22802026/09/23 13:01:25 WARN mTLS auth: bound subjects configured but subject DN unavailable22812026/09/23 13:01:25 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2282--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.32s)2283=== NAME TestPinProtectsFromGC2284 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC2620048727/001/store/7xgb5s8hy8hk30rk9znln23yr874prsz-pinned-file.txt2285 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC2620048727/001/store/l8s5bxzhfbv2cjs2r52f0q24y2rvp8bx-unpinned-file.txt22862026/09/23 13:01:25 INFO Aborted multipart uploads count=02287--- PASS: TestGCBugBareHashReferences (0.65s)22882026/09/23 13:01:25 WARN Force mode enabled - objects will be deleted immediately without grace period2289--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.31s)22902026/09/23 13:01:25 INFO lead: acquired remote=192.0.2.1:123422912026/09/23 13:01:25 INFO lead: released remote=192.0.2.1:12342292--- PASS: TestLeadElectsOneAndHandsOver (0.61s)22932026/09/23 13:01:25 INFO Received uploads request method=POST path=/api/pending_closures22942026/09/23 13:01:25 INFO Received uploads request method=POST path=/api/pending_closures2295=== NAME TestClientWithDependencies2296 client_integration_test.go:615: Found 1 dependencies (including self)2297=== NAME TestClientMultipleUploads2298 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads2981102277/001/store/bxagj9zmkznm47dhnvzzmfndbvpqvb76-test-file-2.txt22992026/09/23 13:01:25 INFO Received uploads request method=POST path=/api/pending_closures23002026/09/23 13:01:25 INFO Received uploads request method=POST path=/api/pending_closures23012026/09/23 13:01:25 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)23022026/09/23 13:01:25 INFO Uploading 1h6zgbc5iv4ihlvcwkimd6my3x9qn6i2-shared-dep (136B)23032026/09/23 13:01:25 INFO Uploading pi5xl93szif880il2jrb8k1ryb2kh42n-b (216B)23042026/09/23 13:01:25 WARN Failed to register uploaded object key=ip3hxmlfg5lm24ad88sx07xvx1my5wrg.ls error="server returned 404: 404 page not found\n"23052026/09/23 13:01:25 INFO Received uploads request method=POST path=/api/pending_closures23062026/09/23 13:01:25 WARN Failed to register uploaded object key=nar/1b2jwpvlwd2msjzajqz4fxb6w3xxjxv0qdax55h9ximv35lwq13k.nar.zst error="server returned 404: 404 page not found\n"23072026/09/23 13:01:25 WARN Failed to register uploaded object key=pi5xl93szif880il2jrb8k1ryb2kh42n.ls error="server returned 404: 404 page not found\n"23082026/09/23 13:01:25 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"23092026/09/23 13:01:25 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)23102026/09/23 13:01:25 INFO Uploading y0ihxllkn56xd6lpir0506plprla2z4m-a (216B)23112026/09/23 13:01:25 INFO Uploading pq3cz8hsl5qk0p7rvxgn3lrqvh5sj5yx-shared-dep (136B)23122026/09/23 13:01:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign23132026/09/23 13:01:25 WARN Failed to register uploaded object key=1h6zgbc5iv4ihlvcwkimd6my3x9qn6i2.ls error="server returned 404: 404 page not found\n"23142026/09/23 13:01:25 INFO Signed narinfos id=1 count=223152026/09/23 13:01:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign23162026/09/23 13:01:25 INFO Signed narinfos id=2 count=223172026/09/23 13:01:25 INFO Uploading 4 narinfos23182026/09/23 13:01:25 WARN Failed to register uploaded object key=ba9a997ffhhasr5mpwcwa9gaafb882m4.ls error="server returned 404: 404 page not found\n"23192026/09/23 13:01:25 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"23202026/09/23 13:01:25 WARN Failed to register uploaded object key=1h6zgbc5iv4ihlvcwkimd6my3x9qn6i2.narinfo error="server returned 404: 404 page not found\n"23212026/09/23 13:01:25 WARN Failed to register uploaded object key=nar/1sg4zsxv2mw81h1nfvygbhcpl9viydaisqwam346k7zhz5j57q4w.nar.zst error="server returned 404: 404 page not found\n"23222026/09/23 13:01:25 WARN Failed to register uploaded object key=pq3cz8hsl5qk0p7rvxgn3lrqvh5sj5yx.ls error="server returned 404: 404 page not found\n"23232026/09/23 13:01:25 WARN Failed to register uploaded object key=y0ihxllkn56xd6lpir0506plprla2z4m.ls error="server returned 404: 404 page not found\n"23242026/09/23 13:01:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign23252026/09/23 13:01:25 INFO Signed narinfos id=1 count=223262026/09/23 13:01:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign23272026/09/23 13:01:25 INFO Signed narinfos id=2 count=223282026/09/23 13:01:25 INFO Uploading 4 narinfos2329=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2330=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2331=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2332=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2333=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2334=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2335=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured23362026/09/23 13:01:25 WARN Failed to register uploaded object key=1h6zgbc5iv4ihlvcwkimd6my3x9qn6i2.narinfo error="server returned 404: 404 page not found\n"2337=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2338=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2339=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected2340=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured23412026/09/23 13:01:25 WARN Failed to register uploaded object key=ip3hxmlfg5lm24ad88sx07xvx1my5wrg.narinfo error="server returned 404: 404 page not found\n"2342=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected23432026/09/23 13:01:25 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]23442026/09/23 13:01:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete23452026/09/23 13:01:25 WARN Failed to register uploaded object key=pi5xl93szif880il2jrb8k1ryb2kh42n.narinfo error="server returned 404: 404 page not found\n"23462026/09/23 13:01:25 WARN Failed to register uploaded object key=pq3cz8hsl5qk0p7rvxgn3lrqvh5sj5yx.narinfo error="server returned 404: 404 page not found\n"23472026/09/23 13:01:25 WARN Authentication failed token_preview=eyJhbGciOi...9n70ViBDmQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2348--- PASS: TestService_AuthMiddleware_OIDC (0.38s)2349 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2350 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2351 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2352 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)23532026/09/23 13:01:25 WARN Failed to register uploaded object key=ba9a997ffhhasr5mpwcwa9gaafb882m4.narinfo error="server returned 404: 404 page not found\n"23542026/09/23 13:01:25 WARN Failed to register uploaded object key=y0ihxllkn56xd6lpir0506plprla2z4m.narinfo error="server returned 404: 404 page not found\n"23552026/09/23 13:01:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete23562026/09/23 13:01:25 WARN Failed to register uploaded object key=pq3cz8hsl5qk0p7rvxgn3lrqvh5sj5yx.narinfo error="server returned 404: 404 page not found\n"23572026/09/23 13:01:25 INFO Completed upload id=123582026/09/23 13:01:25 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete23592026/09/23 13:01:25 INFO Completed upload id=22360=== NAME TestClientCADerivations23612026/09/23 13:01:25 INFO Upload complete. (69ms)2362 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations151025606/001/store/n9qg43gp6aplz2279h5ilv6ia3smha8f-ca-test2363=== NAME TestClientFallsBackToClosures2364 client_pushes_test.go:112: Retrieved narinfo from S3:2365 StorePath: /build/TestClientFallsBackToClosures214722019/001/store/1h6zgbc5iv4ihlvcwkimd6my3x9qn6i2-shared-dep2366 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2367 Compression: zstd2368 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822369 NarSize: 1362370 References: 2371 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n23722026/09/23 13:01:25 INFO Completed upload id=123732026/09/23 13:01:25 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete2374 client_pushes_test.go:112: Retrieved narinfo from S3:2375 StorePath: /build/TestClientFallsBackToClosures214722019/001/store/ip3hxmlfg5lm24ad88sx07xvx1my5wrg-a2376 URL: nar/1b2jwpvlwd2msjzajqz4fxb6w3xxjxv0qdax55h9ximv35lwq13k.nar.zst2377 Compression: zstd2378 NarHash: sha256:1b2jwpvlwd2msjzajqz4fxb6w3xxjxv0qdax55h9ximv35lwq13k2379 NarSize: 2162380 References: /build/TestClientFallsBackToClosures214722019/001/store/1h6zgbc5iv4ihlvcwkimd6my3x9qn6i2-shared-dep2381 CA: text:sha256:092kim915jmr1mqzzgfbvh7k7ld3imd2jfplsmf7mn48w98f7sxk23822026/09/23 13:01:25 INFO Completed upload id=223832026/09/23 13:01:25 INFO Upload complete. (61ms)2384=== NAME TestClientPushesUseOnePush2385 client_pushes_test.go:97: Retrieved narinfo from S3:2386 StorePath: /build/TestClientPushesUseOnePush1952730587/001/store/pq3cz8hsl5qk0p7rvxgn3lrqvh5sj5yx-shared-dep2387 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2388 Compression: zstd2389 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822390 NarSize: 1362391 References: 2392 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2393=== NAME TestClientFallsBackToClosures2394 client_pushes_test.go:112: Retrieved narinfo from S3:2395 StorePath: /build/TestClientFallsBackToClosures214722019/001/store/pi5xl93szif880il2jrb8k1ryb2kh42n-b2396 URL: nar/1b2jwpvlwd2msjzajqz4fxb6w3xxjxv0qdax55h9ximv35lwq13k.nar.zst2397 Compression: zstd2398 NarHash: sha256:1b2jwpvlwd2msjzajqz4fxb6w3xxjxv0qdax55h9ximv35lwq13k2399 NarSize: 2162400 References: /build/TestClientFallsBackToClosures214722019/001/store/1h6zgbc5iv4ihlvcwkimd6my3x9qn6i2-shared-dep2401 CA: text:sha256:092kim915jmr1mqzzgfbvh7k7ld3imd2jfplsmf7mn48w98f7sxk2402=== NAME TestClientPushesUseOnePush2403 client_pushes_test.go:97: Retrieved narinfo from S3:2404 StorePath: /build/TestClientPushesUseOnePush1952730587/001/store/y0ihxllkn56xd6lpir0506plprla2z4m-a2405 URL: nar/1sg4zsxv2mw81h1nfvygbhcpl9viydaisqwam346k7zhz5j57q4w.nar.zst2406 Compression: zstd2407 NarHash: sha256:1sg4zsxv2mw81h1nfvygbhcpl9viydaisqwam346k7zhz5j57q4w2408 NarSize: 2162409 References: /build/TestClientPushesUseOnePush1952730587/001/store/pq3cz8hsl5qk0p7rvxgn3lrqvh5sj5yx-shared-dep2410 CA: text:sha256:10xswxgb9wlq4k02g92s7f6kj2vcxwmwdnd02k548y9fysj3i6da2411 client_pushes_test.go:97: Retrieved narinfo from S3:2412 StorePath: /build/TestClientPushesUseOnePush1952730587/001/store/ba9a997ffhhasr5mpwcwa9gaafb882m4-b2413 URL: nar/1sg4zsxv2mw81h1nfvygbhcpl9viydaisqwam346k7zhz5j57q4w.nar.zst2414 Compression: zstd2415 NarHash: sha256:1sg4zsxv2mw81h1nfvygbhcpl9viydaisqwam346k7zhz5j57q4w2416 NarSize: 2162417 References: /build/TestClientPushesUseOnePush1952730587/001/store/pq3cz8hsl5qk0p7rvxgn3lrqvh5sj5yx-shared-dep2418 CA: text:sha256:10xswxgb9wlq4k02g92s7f6kj2vcxwmwdnd02k548y9fysj3i6da2419--- PASS: TestClientFallsBackToClosures (0.64s)2420=== NAME TestClientPushesUseOnePush2421 client_pushes_test.go:100: POST /api/pushes calls = 0, want 12422 client_pushes_test.go:104: POST /api/pending_closures calls = 2, want 02423--- FAIL: TestClientPushesUseOnePush (0.65s)24242026/09/23 13:01:25 INFO Received uploads request method=POST path=/api/pending_closures24252026/09/23 13:01:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)24262026/09/23 13:01:25 INFO Uploading 7xgb5s8hy8hk30rk9znln23yr874prsz-pinned-file.txt (128B)2427=== NAME TestClientCADerivations2428 client_ca_test.go:139: Found 1 dependencies (including self)24292026/09/23 13:01:25 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"24302026/09/23 13:01:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign24312026/09/23 13:01:25 WARN Failed to register uploaded object key=7xgb5s8hy8hk30rk9znln23yr874prsz.ls error="server returned 404: 404 page not found\n"24322026/09/23 13:01:25 INFO Signed narinfos id=1 count=124332026/09/23 13:01:25 INFO Uploading 1 narinfos24342026/09/23 13:01:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete24352026/09/23 13:01:25 WARN Failed to register uploaded object key=7xgb5s8hy8hk30rk9znln23yr874prsz.narinfo error="server returned 404: 404 page not found\n"24362026/09/23 13:01:25 INFO Completed upload id=124372026/09/23 13:01:25 INFO Upload complete. (64ms)24382026/09/23 13:01:25 INFO Received uploads request method=POST path=/api/pending_closures24392026/09/23 13:01:25 INFO Received uploads request method=POST path=/api/pending_closures24402026/09/23 13:01:25 INFO Received uploads request method=POST path=/api/pending_closures24412026/09/23 13:01:25 INFO Received uploads request method=POST path=/api/pending_closures24422026/09/23 13:01:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)24432026/09/23 13:01:25 INFO Uploading pywxbwjycylld1izpg7shnmbswaq9hsj-test-script (136B)24442026/09/23 13:01:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)24452026/09/23 13:01:25 INFO Uploading 8qd3c8b1sjpiy40khxc3bs4vwv9h9vwg-shared-dep (136B)24462026/09/23 13:01:25 INFO Received uploads request method=POST path=/api/pending_closures24472026/09/23 13:01:25 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)24482026/09/23 13:01:25 INFO Uploading 3k5kkyxy9kn64vy2lzqxjq1gn9rhp85n-test-file-1.txt (160B)24492026/09/23 13:01:25 INFO Uploading bxagj9zmkznm47dhnvzzmfndbvpqvb76-test-file-2.txt (160B)24502026/09/23 13:01:25 INFO Uploading zkdr7z2mhg5lg21ym0n0pqvihq13b5dp-test-file-0.txt (160B)24512026/09/23 13:01:25 WARN Failed to register uploaded object key=pywxbwjycylld1izpg7shnmbswaq9hsj.ls error="server returned 404: 404 page not found\n"24522026/09/23 13:01:25 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"24532026/09/23 13:01:25 WARN Failed to register uploaded object key=log/nfwp3xyhngiihh5kn03vqxydmrwpb0r0-test-script.drv error="server returned 404: 404 page not found\n"24542026/09/23 13:01:25 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"24552026/09/23 13:01:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign24562026/09/23 13:01:25 WARN Failed to register uploaded object key=8qd3c8b1sjpiy40khxc3bs4vwv9h9vwg.ls error="server returned 404: 404 page not found\n"24572026/09/23 13:01:25 INFO Signed narinfos id=1 count=124582026/09/23 13:01:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign24592026/09/23 13:01:25 INFO Uploading 1 narinfos24602026/09/23 13:01:25 INFO Signed narinfos id=2 count=124612026/09/23 13:01:25 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"24622026/09/23 13:01:25 INFO Uploading 1 narinfos24632026/09/23 13:01:25 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"24642026/09/23 13:01:25 WARN Failed to register uploaded object key=3k5kkyxy9kn64vy2lzqxjq1gn9rhp85n.ls error="server returned 404: 404 page not found\n"24652026/09/23 13:01:25 WARN Failed to register uploaded object key=zkdr7z2mhg5lg21ym0n0pqvihq13b5dp.ls error="server returned 404: 404 page not found\n"24662026/09/23 13:01:25 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"24672026/09/23 13:01:25 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"24682026/09/23 13:01:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign24692026/09/23 13:01:25 WARN Failed to register uploaded object key=bxagj9zmkznm47dhnvzzmfndbvpqvb76.ls error="server returned 404: 404 page not found\n"24702026/09/23 13:01:25 INFO Signed narinfos id=3 count=124712026/09/23 13:01:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign24722026/09/23 13:01:25 INFO Signed narinfos id=1 count=124732026/09/23 13:01:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign24742026/09/23 13:01:25 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete24752026/09/23 13:01:25 WARN Failed to register uploaded object key=8qd3c8b1sjpiy40khxc3bs4vwv9h9vwg.narinfo error="server returned 404: 404 page not found\n"24762026/09/23 13:01:25 INFO Signed narinfos id=2 count=124772026/09/23 13:01:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete24782026/09/23 13:01:25 INFO Uploading 3 narinfos24792026/09/23 13:01:25 WARN Failed to register uploaded object key=pywxbwjycylld1izpg7shnmbswaq9hsj.narinfo error="server returned 404: 404 page not found\n"24802026/09/23 13:01:25 WARN Failed to register uploaded object key=zkdr7z2mhg5lg21ym0n0pqvihq13b5dp.narinfo error="server returned 404: 404 page not found\n"24812026/09/23 13:01:25 WARN Failed to register uploaded object key=3k5kkyxy9kn64vy2lzqxjq1gn9rhp85n.narinfo error="server returned 404: 404 page not found\n"24822026/09/23 13:01:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete24832026/09/23 13:01:25 WARN Failed to register uploaded object key=bxagj9zmkznm47dhnvzzmfndbvpqvb76.narinfo error="server returned 404: 404 page not found\n"24842026/09/23 13:01:25 INFO Completed upload id=124852026/09/23 13:01:25 INFO Upload complete. (62ms)24862026/09/23 13:01:25 INFO Completed upload id=224872026/09/23 13:01:25 INFO Upload complete. (52ms)24882026/09/23 13:01:25 INFO Received uploads request method=POST path=/api/pending_closures24892026/09/23 13:01:25 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)2490=== NAME TestClientWithDependencies24912026/09/23 13:01:25 INFO Uploading 8qd3c8b1sjpiy40khxc3bs4vwv9h9vwg-shared-dep (136B)2492 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1820140070/001/store) requires matching store prefix24932026/09/23 13:01:25 INFO Uploading brsmhwhn4l29ljgwhmm3sy5zadqq37ys-top (224B)24942026/09/23 13:01:25 INFO Completed upload id=124952026/09/23 13:01:25 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete24962026/09/23 13:01:25 INFO Completed upload id=224972026/09/23 13:01:25 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete24982026/09/23 13:01:25 WARN Failed to register uploaded object key=nar/0qszfd4ih45g5820025ad7im6bn0q59pfpghh91bzx7mjrisl0fz.nar.zst error="server returned 404: 404 page not found\n"24992026/09/23 13:01:25 WARN Failed to register uploaded object key=8qd3c8b1sjpiy40khxc3bs4vwv9h9vwg.ls error="server returned 404: 404 page not found\n"25002026/09/23 13:01:25 INFO Completed upload id=325012026/09/23 13:01:25 WARN Failed to register uploaded object key=brsmhwhn4l29ljgwhmm3sy5zadqq37ys.ls error="server returned 404: 404 page not found\n"25022026/09/23 13:01:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign25032026/09/23 13:01:25 INFO Upload complete. (69ms)2504=== NAME TestClientMultipleUploads25052026/09/23 13:01:25 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"2506 client_integration_test.go:369: Uploaded 3 paths in 101.957447ms25072026/09/23 13:01:25 INFO Signed narinfos id=1 count=125082026/09/23 13:01:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign25092026/09/23 13:01:25 INFO Signed narinfos id=3 count=125102026/09/23 13:01:25 INFO Uploading 2 narinfos2511--- PASS: TestClientWithDependencies (0.69s)25122026/09/23 13:01:25 WARN Failed to register uploaded object key=8qd3c8b1sjpiy40khxc3bs4vwv9h9vwg.narinfo error="server returned 404: 404 page not found\n"25132026/09/23 13:01:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete25142026/09/23 13:01:25 WARN Failed to register uploaded object key=brsmhwhn4l29ljgwhmm3sy5zadqq37ys.narinfo error="server returned 404: 404 page not found\n"25152026/09/23 13:01:25 INFO Completed upload id=125162026/09/23 13:01:25 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete25172026/09/23 13:01:25 INFO Completed upload id=325182026/09/23 13:01:25 INFO Upload complete. (161ms)2519=== NAME TestClientSharedPathCommittedMidPush2520 client_integration_test.go:680: Retrieved narinfo from S3:2521 StorePath: /build/TestClientSharedPathCommittedMidPush729803477/001/store/8qd3c8b1sjpiy40khxc3bs4vwv9h9vwg-shared-dep2522 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2523 Compression: zstd2524 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822525 NarSize: 1362526 References: 2527 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2528 client_integration_test.go:680: Retrieved narinfo from S3:2529 StorePath: /build/TestClientSharedPathCommittedMidPush729803477/001/store/brsmhwhn4l29ljgwhmm3sy5zadqq37ys-top2530 URL: nar/0qszfd4ih45g5820025ad7im6bn0q59pfpghh91bzx7mjrisl0fz.nar.zst2531 Compression: zstd2532 NarHash: sha256:0qszfd4ih45g5820025ad7im6bn0q59pfpghh91bzx7mjrisl0fz2533 NarSize: 2242534 References: /build/TestClientSharedPathCommittedMidPush729803477/001/store/8qd3c8b1sjpiy40khxc3bs4vwv9h9vwg-shared-dep2535 CA: text:sha256:1ns5mrdzmh72v5r0hswbs91ygcpf21s0z8jr2f3bf4n0dk8ry3k22536--- PASS: TestClientMultipleUploads (0.68s)25372026/09/23 13:01:25 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2538--- PASS: TestClientSharedPathCommittedMidPush (0.71s)25392026/09/23 13:01:25 INFO Received uploads request method=POST path=/api/pending_closures25402026/09/23 13:01:25 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=439.059086ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present25412026/09/23 13:01:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)25422026/09/23 13:01:25 INFO Uploading l8s5bxzhfbv2cjs2r52f0q24y2rvp8bx-unpinned-file.txt (128B)25432026/09/23 13:01:25 WARN Failed to register uploaded object key=l8s5bxzhfbv2cjs2r52f0q24y2rvp8bx.ls error="server returned 404: 404 page not found\n"25442026/09/23 13:01:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign25452026/09/23 13:01:25 INFO Signed narinfos id=2 count=125462026/09/23 13:01:25 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"25472026/09/23 13:01:25 INFO Uploading 1 narinfos25482026/09/23 13:01:25 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete25492026/09/23 13:01:25 WARN Failed to register uploaded object key=l8s5bxzhfbv2cjs2r52f0q24y2rvp8bx.narinfo error="server returned 404: 404 page not found\n"25502026/09/23 13:01:25 INFO Completed upload id=225512026/09/23 13:01:25 INFO Upload complete. (52ms)25522026/09/23 13:01:25 INFO Received uploads request method=POST path=/api/pending_closures25532026/09/23 13:01:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)25542026/09/23 13:01:25 INFO Uploading n9qg43gp6aplz2279h5ilv6ia3smha8f-ca-test (144B)25552026/09/23 13:01:25 WARN Failed to register uploaded object key=n9qg43gp6aplz2279h5ilv6ia3smha8f.ls error="server returned 404: 404 page not found\n"25562026/09/23 13:01:25 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"25572026/09/23 13:01:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign25582026/09/23 13:01:25 WARN Failed to register uploaded object key=log/f4qhx0y25k9nlsz6rcjw6444z084cpg1-ca-test.drv error="server returned 404: 404 page not found\n"25592026/09/23 13:01:25 INFO Signed narinfos id=1 count=125602026/09/23 13:01:25 INFO Uploading 1 narinfos25612026/09/23 13:01:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete25622026/09/23 13:01:25 WARN Failed to register uploaded object key=n9qg43gp6aplz2279h5ilv6ia3smha8f.narinfo error="server returned 404: 404 page not found\n"25632026/09/23 13:01:25 INFO Completed upload id=125642026/09/23 13:01:25 INFO Upload complete. (97ms)2565=== NAME TestClientCADerivations2566 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations151025606/001/store/n9qg43gp6aplz2279h5ilv6ia3smha8f-ca-test2567 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2568 Compression: zstd2569 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2570 NarSize: 1442571 References: 2572 Deriver: /build/TestClientCADerivations151025606/001/store/f4qhx0y25k9nlsz6rcjw6444z084cpg1-ca-test.drv2573 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2574 client_ca_test.go:185: Checking for realisation files in S3...2575 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2576 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache25772026/09/23 13:01:25 INFO Received create pin request method=POST path=/api/pins/myapp25782026/09/23 13:01:25 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2620048727/001/store/7xgb5s8hy8hk30rk9znln23yr874prsz-pinned-file.txt narinfo_key=7xgb5s8hy8hk30rk9znln23yr874prsz.narinfo25792026/09/23 13:01:25 INFO Starting cleanup of old closures method=DELETE path=/api/closures25802026/09/23 13:01:25 INFO Garbage collection started25812026/09/23 13:01:25 INFO Aborted multipart uploads count=025822026/09/23 13:01:25 WARN Force mode enabled - objects will be deleted immediately without grace period2583 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2584 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2585 error: binary cache 's3://bucket57?endpoint=http://localhost:43591&region=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations151025606/001/store'2586 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12587--- PASS: TestUploadHandlersRejectOversizedBody (0.13s)2588 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.05s)2589 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)2590 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.61s)2591--- PASS: TestClientCADerivations (0.86s)25922026/09/23 13:01:25 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=821.881376ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present25932026/09/23 13:01:25 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=025942026/09/23 13:01:25 INFO Vacuumed table table=pending_closures25952026/09/23 13:01:25 INFO Vacuumed table table=pending_objects25962026/09/23 13:01:25 INFO Vacuumed table table=multipart_uploads25972026/09/23 13:01:25 INFO Vacuumed table table=closures25982026/09/23 13:01:25 INFO Vacuumed table table=objects2599=== NAME TestOrphanedObjectsGCStressTest2600 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2601 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion26022026/09/23 13:01:26 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=026032026/09/23 13:01:26 INFO Vacuumed table table=pending_closures26042026/09/23 13:01:26 INFO Vacuumed table table=pending_objects26052026/09/23 13:01:26 INFO Vacuumed table table=multipart_uploads26062026/09/23 13:01:26 INFO Vacuumed table table=closures26072026/09/23 13:01:26 INFO Vacuumed table table=objects26082026/09/23 13:01:26 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.564492904s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2609 orphaned_objects_gc_test.go:509: Stress test completed successfully:2610 orphaned_objects_gc_test.go:510: - Active objects preserved: 202611 orphaned_objects_gc_test.go:511: - Objects deleted: 2102612 orphaned_objects_gc_test.go:512: - Total GC'd: 2102613--- PASS: TestOrphanedObjectsGCStressTest (2.23s)26142026/09/23 13:01:27 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02615=== NAME TestClientIntegration2616 client_integration_test.go:323: Objects in database after GC:2617 client_integration_test.go:323: Successfully deleted all objects with GC --force2618--- PASS: TestClientIntegration (2.67s)26192026/09/23 13:01:27 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02620=== NAME TestPinProtectsFromGC2621 client_integration_test.go:794: Pin successfully protected closure from garbage collection2622--- PASS: TestPinProtectsFromGC (2.81s)26232026/09/23 13:01:28 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-config26242026/09/23 13:01:28 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=186.761806ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26252026/09/23 13:01:28 WARN Rate limiter enabled after throttle name=s3-test rate=526262026/09/23 13:01:28 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2627=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2628 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102629 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002630--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.98s)26312026/09/23 13:01:28 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=437.35251ms 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:01:28 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=760.541835ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26332026/09/23 13:01:29 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.630925081s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26342026/09/23 13:01:31 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"26352026/09/23 13:01:31 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_closures26362026/09/23 13:01:31 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=210.554765ms 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:01:31 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=377.483731ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26382026/09/23 13:01:31 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=744.254525ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26392026/09/23 13:01:32 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.452794478s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2640--- PASS: TestClientErrorHandling (0.00s)2641 --- PASS: TestClientErrorHandling/InvalidStorePath (0.27s)2642 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.34s)2643 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.27s)2644FAIL2645{"timestamp":"2026-09-23T13:01:34.086152203Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:48386","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(390)"}26462026-09-23 13:01:34.424 UTC [129] LOG: received smart shutdown request26472026-09-23 13:01:34.429 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 126482026-09-23 13:01:34.436 UTC [134] LOG: shutting down26492026-09-23 13:01:34.436 UTC [134] LOG: checkpoint starting: shutdown immediate26502026-09-23 13:01:35.063 UTC [134] LOG: checkpoint complete: wrote 11089 buffers (67.7%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 18 recycled; write=0.258 s, sync=0.333 s, total=0.628 s; sync files=21875, longest=0.030 s, average=0.001 s; distance=297532 kB, estimate=297532 kB; lsn=0/139F4ED8, redo lsn=0/139F4ED826512026-09-23 13:01:35.136 UTC [129] LOG: database system is shut down

failed niks3-go-unit-tests checks.x86_64-linux.go-unit-tests · build #261 · raw

failed `niks3-go-unit-tests` `checks.x86_64-linux.go-unit-tests` · build #261 · raw