niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #264
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestCaseHackSuffix8=== PAUSE TestCaseHackSuffix9=== RUN TestFilterOversizedClosures10=== PAUSE TestFilterOversizedClosures11=== RUN TestUploadMultipart_PartsInParallel12=== PAUSE TestUploadMultipart_PartsInParallel13=== RUN TestPartSizeForNAR14=== PAUSE TestPartSizeForNAR15=== RUN TestUploadMultipart_SupersededByPeer16=== PAUSE TestUploadMultipart_SupersededByPeer17=== RUN TestDumpPathCaseHackMatchesNix18--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)19=== RUN TestDumpPathCaseHackCollision20--- PASS: TestDumpPathCaseHackCollision (0.00s)21=== RUN TestDumpPathMatchesNix22=== PAUSE TestDumpPathMatchesNix23=== RUN TestDumpPathSingleFile24=== PAUSE TestDumpPathSingleFile25=== RUN TestDumpPathWriterError26=== PAUSE TestDumpPathWriterError27=== RUN TestEncodeNixBase3228=== PAUSE TestEncodeNixBase3229=== RUN TestEncodeNixBase32WithRealHash30=== PAUSE TestEncodeNixBase32WithRealHash31=== RUN TestConvertHashToNix3232=== PAUSE TestConvertHashToNix3233=== RUN TestGetStorePathHash34=== PAUSE TestGetStorePathHash35=== RUN TestPathInfoHashCompatibility36=== PAUSE TestPathInfoHashCompatibility37=== RUN TestParsePathInfoJSON38=== PAUSE TestParsePathInfoJSON39=== RUN TestParsePathInfoJSONMultiplePaths40=== PAUSE TestParsePathInfoJSONMultiplePaths41=== RUN TestPathInfoCACompatibility42=== PAUSE TestPathInfoCACompatibility43=== RUN TestRateLimiterFeedback44=== PAUSE TestRateLimiterFeedback45=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess47=== RUN TestResolveStorePath48=== PAUSE TestResolveStorePath49=== RUN TestDoWithRetry_BodyReplayedViaGetBody50=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody51=== RUN TestShellSplit52=== PAUSE TestShellSplit53=== RUN TestShellSplitErrors54=== PAUSE TestShellSplitErrors55=== RUN TestStreamPushReportsEveryPath56=== PAUSE TestStreamPushReportsEveryPath57=== RUN TestStreamPushBatchesUnderLoad58=== PAUSE TestStreamPushBatchesUnderLoad59=== RUN TestStreamPushIsolatesFailures60=== PAUSE TestStreamPushIsolatesFailures61=== RUN TestStreamPushGivesUpOnDeadServer62=== PAUSE TestStreamPushGivesUpOnDeadServer63=== RUN TestStreamPushRequestLine64=== PAUSE TestStreamPushRequestLine65=== RUN TestStreamPushReportsSignatures66=== PAUSE TestStreamPushReportsSignatures67=== RUN TestClientSignaturesByStorePath68=== PAUSE TestClientSignaturesByStorePath69=== RUN TestSetClientTLS70=== PAUSE TestSetClientTLS71=== RUN TestSetClientTLSDoesNotMutateDefaultTransport72=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport73=== RUN TestSetClientTLSErrors74=== PAUSE TestSetClientTLSErrors75=== RUN TestStaticToken76=== PAUSE TestStaticToken77=== RUN TestFileTokenReadsAndCaches78=== PAUSE TestFileTokenReadsAndCaches79=== RUN TestFileTokenMissing80=== PAUSE TestFileTokenMissing81=== RUN TestFileTokenEmpty82=== PAUSE TestFileTokenEmpty83=== RUN TestScriptTokenNoExpiryRerunsEveryCall84=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall85=== RUN TestScriptTokenCachesUntilRefresh86=== PAUSE TestScriptTokenCachesUntilRefresh87=== RUN TestScriptTokenEmptyToken88=== PAUSE TestScriptTokenEmptyToken89=== RUN TestScriptTokenBadJSON90=== PAUSE TestScriptTokenBadJSON91=== RUN TestScriptTokenScriptFails92=== PAUSE TestScriptTokenScriptFails93=== RUN TestScriptTokenEmptyCommand94=== PAUSE TestScriptTokenEmptyCommand95=== CONT TestDoServerRequestAttachesToken96=== CONT TestScriptTokenBadJSON97=== CONT TestScriptTokenScriptFails98=== CONT TestScriptTokenEmptyToken99=== CONT TestScriptTokenCachesUntilRefresh100=== CONT TestEncodeNixBase32101=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess102=== CONT TestRateLimiterFeedback103=== RUN TestRateLimiterFeedback/429_enables_limiter104=== PAUSE TestRateLimiterFeedback/429_enables_limiter105=== RUN TestRateLimiterFeedback/503_enables_limiter106=== PAUSE TestRateLimiterFeedback/503_enables_limiter107=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter108=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter109=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter110=== CONT TestPathInfoCACompatibility111=== CONT TestParsePathInfoJSONMultiplePaths112=== CONT TestParsePathInfoJSON113=== CONT TestPathInfoHashCompatibility114=== CONT TestGetStorePathHash115=== CONT TestConvertHashToNix32116=== CONT TestEncodeNixBase32WithRealHash117=== CONT TestClientSignaturesByStorePath118=== CONT TestScriptTokenNoExpiryRerunsEveryCall119=== CONT TestFileTokenEmpty120=== CONT TestFileTokenMissing1212026/09/23 13:18:04 WARN Rate limiter enabled after throttle name=server-test rate=5122=== RUN TestPathInfoCACompatibility/null_ca_field123=== PAUSE TestPathInfoCACompatibility/null_ca_field124=== RUN TestPathInfoCACompatibility/old_string_format_-_text125=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text126=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive127=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive128=== CONT TestFileTokenReadsAndCaches129=== CONT TestStaticToken130=== CONT TestSetClientTLSErrors131=== CONT TestSetClientTLSDoesNotMutateDefaultTransport132=== CONT TestResolveStorePath133=== RUN TestEncodeNixBase32/test_string_hash134=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths135=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths136=== CONT TestSetClientTLS137=== RUN TestPathInfoCACompatibility/new_structured_format_-_text138=== CONT TestStreamPushReportsSignatures139=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text140=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method141=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method142=== RUN TestGetStorePathHash/valid_store_path143=== PAUSE TestGetStorePathHash/valid_store_path144=== RUN TestGetStorePathHash/basename_without_hyphen_should_error145=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error146=== RUN TestParsePathInfoJSON/Nix_format147=== PAUSE TestParsePathInfoJSON/Nix_format148=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths149--- PASS: TestClientSignaturesByStorePath (0.00s)150=== CONT TestStreamPushBatchesUnderLoad151=== CONT TestStreamPushReportsEveryPath152=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error153=== CONT TestShellSplitErrors154=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)155=== CONT TestStreamPushIsolatesFailures156=== CONT TestDumpPathSingleFile157=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter1582026/09/23 13:18:04 ERROR Upload failed error=boom count=1159=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)1602026/09/23 13:18:04 ERROR Upload failed error="bad path" count=3161=== PAUSE TestEncodeNixBase32/test_string_hash162=== RUN TestConvertHashToNix32/SRI_format_to_Nix32163=== RUN TestParsePathInfoJSON/Lix_format164=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths165--- PASS: TestEncodeNixBase32WithRealHash (0.00s)166=== CONT TestStreamPushRequestLine167=== CONT TestShellSplit168=== CONT TestDumpPathMatchesNix169=== CONT TestUploadMultipart_SupersededByPeer170=== RUN TestUploadMultipart_SupersededByPeer/exists171=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error172=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error173=== CONT TestStreamPushGivesUpOnDeadServer174=== CONT TestDoWithRetry_BodyReplayedViaGetBody175=== CONT TestFilterOversizedClosures176=== CONT TestDumpPathWriterError177=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon178=== RUN TestEncodeNixBase32/empty_input1792026/09/23 13:18:04 ERROR Upload failed error=boom count=11802026/09/23 13:18:04 ERROR Upload failed error="connection refused" count=20181=== CONT TestUploadMultipart_PartsInParallel182=== PAUSE TestEncodeNixBase32/empty_input183=== PAUSE TestParsePathInfoJSON/Lix_format1842026/09/23 13:18:04 ERROR Server seems unavailable, giving up on batch untried=17185=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32186=== CONT TestScriptTokenEmptyCommand187--- PASS: TestStaticToken (0.00s)188=== PAUSE TestUploadMultipart_SupersededByPeer/exists189--- PASS: TestScriptTokenScriptFails (0.00s)190--- PASS: TestScriptTokenBadJSON (0.00s)191--- PASS: TestFileTokenEmpty (0.00s)192--- PASS: TestShellSplitErrors (0.00s)193=== RUN TestUploadMultipart_SupersededByPeer/missing1942026/09/23 13:18:04 WARN Rate limiter enabled after throttle name=server-test rate=5195=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error196=== RUN TestFilterOversizedClosures/no_limit_keeps_everything197=== CONT TestCaseHackSuffix1982026/09/23 13:18:04 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:41091199=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon200=== CONT TestRegisterUploadedObjectReusesConnections201=== RUN TestParsePathInfoJSON/empty_input202=== PAUSE TestParsePathInfoJSON/empty_input203=== RUN TestParsePathInfoJSON/whitespace_only204=== PAUSE TestParsePathInfoJSON/whitespace_only205=== RUN TestParsePathInfoJSON/invalid_JSON206=== PAUSE TestParsePathInfoJSON/invalid_JSON207=== CONT TestPathInfoCACompatibility/null_ca_field208=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive209=== RUN TestConvertHashToNix32/already_Nix32_format210=== PAUSE TestConvertHashToNix32/already_Nix32_format211=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter212=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter2132026/09/23 13:18:04 WARN Rate limiter backed off name=server-test rate=5214=== CONT TestPathInfoCACompatibility/old_string_format_-_text2152026/09/23 13:18:04 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:41091216=== CONT TestRateLimiterFeedback/503_enables_limiter217=== CONT TestPartSizeForNAR218=== RUN TestPartSizeForNAR/zero_stays_at_minimum219=== RUN TestConvertHashToNix32/invalid_format220=== PAUSE TestConvertHashToNix32/invalid_format221=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths222=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method223=== CONT TestEncodeNixBase32/test_string_hash224=== CONT TestEncodeNixBase32/empty_input225=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error2262026/09/23 13:18:04 WARN Rate limiter enabled after throttle name=server-test rate=5227=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error2282026/09/23 13:18:04 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:33865229=== CONT TestParsePathInfoJSON/Nix_format230=== CONT TestParsePathInfoJSON/whitespace_only2312026/09/23 13:18:04 WARN Rate limiter backed off name=server-test rate=5232=== CONT TestParsePathInfoJSON/empty_input233=== CONT TestParsePathInfoJSON/Lix_format234=== CONT TestConvertHashToNix32/SRI_format_to_Nix32235=== CONT TestGetStorePathHash/valid_store_path236=== CONT TestParsePathInfoJSON/invalid_JSON237=== CONT TestGetStorePathHash/basename_without_hyphen_should_error238=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything239=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped240=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped241=== RUN TestFilterOversizedClosures/all_closures_skipped242=== PAUSE TestFilterOversizedClosures/all_closures_skipped243=== RUN TestSetClientTLSErrors/missing_cert_file244=== RUN TestSetClientTLS/rejects_connection_without_client_cert245=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI246=== CONT TestRateLimiterFeedback/429_enables_limiter247--- PASS: TestFileTokenMissing (0.00s)248=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum249=== CONT TestFilterOversizedClosures/no_limit_keeps_everything250--- PASS: TestScriptTokenEmptyToken (0.00s)251=== PAUSE TestUploadMultipart_SupersededByPeer/missing252=== CONT TestUploadMultipart_SupersededByPeer/exists253=== RUN TestPartSizeForNAR/small_stays_at_minimum254=== PAUSE TestPartSizeForNAR/small_stays_at_minimum255=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum256=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum257=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths258=== CONT TestPathInfoCACompatibility/new_structured_format_-_text259=== CONT TestConvertHashToNix32/invalid_format260=== CONT TestConvertHashToNix32/already_Nix32_format261=== PAUSE TestSetClientTLSErrors/missing_cert_file262=== RUN TestSetClientTLSErrors/missing_key_file263=== PAUSE TestSetClientTLSErrors/missing_key_file264=== RUN TestSetClientTLSErrors/missing_ca_file265=== PAUSE TestSetClientTLSErrors/missing_ca_file2662026/09/23 13:18:04 WARN Rate limiter enabled after throttle name=server-test rate=5267=== RUN TestSetClientTLSErrors/invalid_ca_file2682026/09/23 13:18:04 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:44373269=== PAUSE TestSetClientTLSErrors/invalid_ca_file270=== CONT TestSetClientTLSErrors/missing_cert_file271=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts272=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts273=== RUN TestPartSizeForNAR/1_TiB274=== PAUSE TestPartSizeForNAR/1_TiB275=== RUN TestPartSizeForNAR/5_TiB_S3_max_object276=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object277=== RUN TestPartSizeForNAR/capped_at_5_GiB278=== PAUSE TestPartSizeForNAR/capped_at_5_GiB279=== CONT TestPartSizeForNAR/zero_stays_at_minimum280=== CONT TestUploadMultipart_SupersededByPeer/missing2812026/09/23 13:18:04 WARN Rate limiter backed off name=server-test rate=5282=== CONT TestPartSizeForNAR/1_TiB283=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum284=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert285=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA286=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA287=== RUN TestSetClientTLS/preserves_debug_logging_transport288=== CONT TestPartSizeForNAR/small_stays_at_minimum289=== CONT TestSetClientTLSErrors/missing_ca_file290=== CONT TestSetClientTLSErrors/invalid_ca_file291=== PAUSE TestSetClientTLS/preserves_debug_logging_transport292=== CONT TestSetClientTLS/rejects_connection_without_client_cert293=== CONT TestSetClientTLS/preserves_debug_logging_transport294=== CONT TestPartSizeForNAR/capped_at_5_GiB295--- PASS: TestStreamPushReportsEveryPath (0.00s)296--- PASS: TestStreamPushReportsSignatures (0.00s)297--- PASS: TestStreamPushIsolatesFailures (0.00s)298--- PASS: TestResolveStorePath (0.00s)299--- PASS: TestFileTokenReadsAndCaches (0.00s)300--- PASS: TestShellSplit (0.00s)301--- PASS: TestDoServerRequestAttachesToken (0.01s)302=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI303=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512304=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512305=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)306--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)307--- PASS: TestScriptTokenEmptyCommand (0.00s)308--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)309=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512310=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI311=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon312=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts313=== CONT TestPartSizeForNAR/5_TiB_S3_max_object314=== CONT TestFilterOversizedClosures/all_closures_skipped315=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA3162026/09/23 13:18:04 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-small nar_size=1000 max_nar_size=50317=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3182026/09/23 13:18:04 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=2000319--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)320--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.05s)321--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.05s)322--- PASS: TestEncodeNixBase32 (0.01s)323 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)324 --- PASS: TestEncodeNixBase32/empty_input (0.00s)325--- PASS: TestPathInfoHashCompatibility (0.05s)326 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)327 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)328 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)329 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)330--- PASS: TestParsePathInfoJSON (0.05s)331 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)332 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)333 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)334 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)335 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)336--- PASS: TestGetStorePathHash (0.01s)337 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)338 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)339 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)340 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)341--- PASS: TestConvertHashToNix32 (0.05s)342 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)343 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)344 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)345--- PASS: TestRateLimiterFeedback (0.00s)346 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)347 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)348 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)349 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)350=== CONT TestSetClientTLSErrors/missing_key_file351--- PASS: TestUploadMultipart_SupersededByPeer (0.05s)352 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)353 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)354--- PASS: TestFilterOversizedClosures (0.05s)355 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)356 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)357 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)358--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)359 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)360 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)361--- PASS: TestPathInfoCACompatibility (0.00s)362 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)363 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)364 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)365 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)366 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)367--- PASS: TestPartSizeForNAR (0.00s)368 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)369 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)370 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)371 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)372 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)373 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)374 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)375--- PASS: TestSetClientTLSErrors (0.05s)376 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)377 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)378 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)379 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)380--- PASS: TestDumpPathSingleFile (0.06s)3812026/09/23 13:18:04 http: TLS handshake error from 127.0.0.1:34056: remote error: tls: bad certificate382--- PASS: TestSetClientTLS (0.05s)383 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)384 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)385 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)386--- PASS: TestCaseHackSuffix (0.07s)387--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)388--- PASS: TestStreamPushRequestLine (0.08s)389--- PASS: TestDumpPathWriterError (0.09s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestDumpPathMatchesNix (0.15s)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/postgres1426772273/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/postgres1426772273/data -l logfile start422423/build/postgres1426772273:5432 - no response4242026-09-23 13:18:06.606 UTC [128] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-09-23 13:18:06.607 UTC [128] LOG: listening on Unix socket "/build/postgres1426772273/.s.PGSQL.5432"4262026-09-23 13:18:06.612 UTC [135] LOG: database system was shut down at 2026-09-23 13:18:06 UTC4272026-09-23 13:18:06.616 UTC [128] LOG: database system is ready to accept connections428/build/postgres1426772273:5432 - accepting connections429=== RUN TestService_AuthMiddleware430=== PAUSE TestService_AuthMiddleware431=== RUN TestService_AuthMiddleware_MTLSProxyHeader432=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader433=== RUN TestService_AuthMiddleware_MTLSBoundSubjects434=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects435=== RUN TestService_ReadAuthMiddleware436=== PAUSE TestService_ReadAuthMiddleware437=== RUN TestService_AuthMiddleware_OIDC438=== PAUSE TestService_AuthMiddleware_OIDC439=== RUN TestService_RequireScope_OIDC440=== PAUSE TestService_RequireScope_OIDC441=== RUN TestService_ReadScope_PublicByDefault442=== PAUSE TestService_ReadScope_PublicByDefault443=== RUN TestCacheConfigHandler444=== PAUSE TestCacheConfigHandler445=== RUN TestCacheStatsHandler446=== PAUSE TestCacheStatsHandler447=== RUN TestClientCADerivations448=== PAUSE TestClientCADerivations449=== RUN TestClientErrorHandling450=== PAUSE TestClientErrorHandling451=== RUN TestClientIntegration452=== PAUSE TestClientIntegration453=== RUN TestClientMultipleUploads454=== PAUSE TestClientMultipleUploads455=== RUN TestClientWithDependencies456=== PAUSE TestClientWithDependencies457=== RUN TestClientSharedPathCommittedMidPush458=== PAUSE TestClientSharedPathCommittedMidPush459=== RUN TestPinProtectsFromGC460=== PAUSE TestPinProtectsFromGC461=== RUN TestClientPushesUseOnePush462=== PAUSE TestClientPushesUseOnePush463=== RUN TestClientFallsBackToClosures464=== PAUSE TestClientFallsBackToClosures465=== RUN TestResolveDBConnectionString466=== PAUSE TestResolveDBConnectionString467=== RUN TestLeadElectsOneAndHandsOver468=== PAUSE TestLeadElectsOneAndHandsOver469=== RUN TestLeadIncumbentWinsAfterRestart4702026-09-23 13:18:07.041 UTC [373] ERROR: relation "goose_db_version" does not exist at character 364712026-09-23 13:18:07.041 UTC [373] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4722026/09/23 13:18:07 OK 20241026095416_initial_model.sql (11.1ms)4732026/09/23 13:18:07 OK 20251210153512_drop_unused_gin_index.sql (2.08ms)4742026/09/23 13:18:07 OK 20251218171726_add_pins.sql (3.44ms)4752026/09/23 13:18:07 OK 20260628120000_add_object_size_and_stats.sql (2.74ms)4762026/09/23 13:18:07 OK 20260905000000_add_claims.sql (2.94ms)4772026/09/23 13:18:07 OK 20260920000000_drop_claims.sql (1.88ms)4782026/09/23 13:18:07 OK 20260923120000_add_pushes.sql (1.33ms)4792026/09/23 13:18:07 goose: successfully migrated database to version: 202609231200004802026/09/23 13:18:07 OK 1_commit_pending_closure.sql (1.9ms)4812026/09/23 13:18:07 OK 2_object_stats_trigger.sql (854.63µs)4822026/09/23 13:18:07 OK 3_commit_push.sql (788.47µs)4832026/09/23 13:18:07 goose: up to current file version: 34842026/09/23 13:18:07 INFO lead: acquired remote=192.0.2.1:12344852026/09/23 13:18:07 INFO lead: released remote=192.0.2.1:12344862026/09/23 13:18:07 INFO lead: acquired remote=192.0.2.1:12344872026/09/23 13:18:07 INFO lead: released remote=192.0.2.1:1234488--- PASS: TestLeadIncumbentWinsAfterRestart (0.85s)489=== RUN TestLeadEndsOnShutdown490=== PAUSE TestLeadEndsOnShutdown491=== RUN TestGCAdvisoryLockBlocksConcurrentRun4922026-09-23 13:18:07.820 UTC [384] ERROR: relation "goose_db_version" does not exist at character 364932026-09-23 13:18:07.820 UTC [384] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4942026/09/23 13:18:07 OK 20241026095416_initial_model.sql (9.54ms)4952026/09/23 13:18:07 OK 20251210153512_drop_unused_gin_index.sql (1.22ms)4962026/09/23 13:18:07 OK 20251218171726_add_pins.sql (3.54ms)4972026/09/23 13:18:07 OK 20260628120000_add_object_size_and_stats.sql (3.65ms)4982026/09/23 13:18:07 OK 20260905000000_add_claims.sql (2.91ms)4992026/09/23 13:18:07 OK 20260920000000_drop_claims.sql (1.88ms)5002026/09/23 13:18:07 OK 20260923120000_add_pushes.sql (1.41ms)5012026/09/23 13:18:07 goose: successfully migrated database to version: 202609231200005022026/09/23 13:18:07 OK 1_commit_pending_closure.sql (1.86ms)5032026/09/23 13:18:07 OK 2_object_stats_trigger.sql (789.25µs)5042026/09/23 13:18:07 OK 3_commit_push.sql (877.63µs)5052026/09/23 13:18:07 goose: up to current file version: 3506--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.12s)507=== RUN TestGCBugBareHashReferences508=== PAUSE TestGCBugBareHashReferences509=== RUN TestGCMetrics510=== PAUSE TestGCMetrics511=== RUN TestGCTaskStore_StartNew512=== PAUSE TestGCTaskStore_StartNew513=== RUN TestGCTaskStore_DeduplicateSameParams514=== PAUSE TestGCTaskStore_DeduplicateSameParams515=== RUN TestGCTaskStore_ConflictDifferentParams516=== PAUSE TestGCTaskStore_ConflictDifferentParams517=== RUN TestGCTaskStore_GetEmpty518=== PAUSE TestGCTaskStore_GetEmpty519=== RUN TestGCTaskStore_GetReturnsLatest520=== PAUSE TestGCTaskStore_GetReturnsLatest521=== RUN TestGCTaskStore_CompletedAllowsNewTask522=== PAUSE TestGCTaskStore_CompletedAllowsNewTask523=== RUN TestGCTaskStore_PhaseUpdates524=== PAUSE TestGCTaskStore_PhaseUpdates525=== RUN TestGCTaskStore_Fail526=== PAUSE TestGCTaskStore_Fail527=== RUN TestGracefulShutdownDrainsInflight528=== PAUSE TestGracefulShutdownDrainsInflight529=== RUN TestService_healthCheckHandler530=== PAUSE TestService_healthCheckHandler531=== RUN TestService_readinessHandler532=== PAUSE TestService_readinessHandler533=== RUN TestGenerateLandingPage534=== PAUSE TestGenerateLandingPage535=== RUN TestCacheConfigHandlerMaxNarSize536=== PAUSE TestCacheConfigHandlerMaxNarSize537=== RUN TestCreatePendingClosureRejectsOversizedNAR538=== PAUSE TestCreatePendingClosureRejectsOversizedNAR539=== RUN TestNARDeduplicationMetadataUploadBug540=== PAUSE TestNARDeduplicationMetadataUploadBug541=== RUN TestMetricsInventory542=== PAUSE TestMetricsInventory543=== RUN TestService_NativeMTLS544=== PAUSE TestService_NativeMTLS545=== RUN TestServerTLSConfig546=== PAUSE TestServerTLSConfig547=== RUN TestMultipartCleanup548=== PAUSE TestMultipartCleanup549=== RUN TestObjectStatsTrigger550=== PAUSE TestObjectStatsTrigger551=== RUN TestOrphanedObjectsGC552=== PAUSE TestOrphanedObjectsGC553=== RUN TestOrphanedObjectsGCStressTest554=== PAUSE TestOrphanedObjectsGCStressTest555=== RUN TestResurrectedObjectNotDeleted556=== PAUSE TestResurrectedObjectNotDeleted557=== RUN TestCreatePin_ReservedPins558=== PAUSE TestCreatePin_ReservedPins559=== RUN TestParseSingleRange560=== PAUSE TestParseSingleRange561=== RUN TestProxyHeadersOnlyTrustedOnSocket562=== PAUSE TestProxyHeadersOnlyTrustedOnSocket563=== RUN TestIsValidCachePath564=== PAUSE TestIsValidCachePath565=== RUN TestReadProxyNarinfo566=== PAUSE TestReadProxyNarinfo567=== RUN TestReadProxyNarinfoAlreadyDecompressed568=== PAUSE TestReadProxyNarinfoAlreadyDecompressed569=== RUN TestReadProxyNarStreaming570=== PAUSE TestReadProxyNarStreaming571=== RUN TestReadProxy404572=== PAUSE TestReadProxy404573=== RUN TestReadProxyInvalidPath574=== PAUSE TestReadProxyInvalidPath575=== RUN TestReadProxyHead576=== PAUSE TestReadProxyHead577=== RUN TestReadProxyConditionalGet578=== PAUSE TestReadProxyConditionalGet579=== RUN TestReadProxyRootRedirectsToIndexHTML580=== PAUSE TestReadProxyRootRedirectsToIndexHTML581=== RUN TestReadProxyDisabled582=== PAUSE TestReadProxyDisabled583=== RUN TestReadRedirectNar584=== PAUSE TestReadRedirectNar585=== RUN TestReadRedirectKeepsNarinfoProxied586=== PAUSE TestReadRedirectKeepsNarinfoProxied587=== RUN TestReadProxyRangeRequest588=== PAUSE TestReadProxyRangeRequest589=== RUN TestReadRedirectUsesPublicS3URL590=== PAUSE TestReadRedirectUsesPublicS3URL591=== RUN TestPush_OverlappingRootsStoreOneRowPerKey592=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey593=== RUN TestPush_CompleteCommitsEveryRoot594=== PAUSE TestPush_CompleteCommitsEveryRoot595=== RUN TestPush_CommitFailsWhenSkippedKeyWasCollected596=== PAUSE TestPush_CommitFailsWhenSkippedKeyWasCollected597=== RUN TestPush_RejectsBadRequests598=== PAUSE TestPush_RejectsBadRequests599=== RUN TestPush_SignsNarinfosOfItsPendingObjects600=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects601=== RUN TestRedundantMultipartUpload602=== PAUSE TestRedundantMultipartUpload603=== RUN TestCompleteMultipartUpload_ErrorButObjectExists604=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists605=== RUN TestCompletedNarNotReofferedAcrossClosures606=== PAUSE TestCompletedNarNotReofferedAcrossClosures607=== RUN TestPresignedUploadRegisteredBeforeCommit608=== PAUSE TestPresignedUploadRegisteredBeforeCommit609=== RUN TestService_Rustfstest610=== PAUSE TestService_Rustfstest611=== RUN TestParseSize612=== PAUSE TestParseSize613=== RUN TestSkippedUploadsHandler614=== PAUSE TestSkippedUploadsHandler615=== RUN TestSystemdListenerNotActivated616--- PASS: TestSystemdListenerNotActivated (0.00s)617=== RUN TestWatchdogBeatsWhenHealthy618--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)619=== RUN TestWatchdogSkipsWhenUnhealthy6202026/09/23 13:18:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6212026/09/23 13:18:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6222026/09/23 13:18:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6232026/09/23 13:18:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6242026/09/23 13:18:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6252026/09/23 13:18:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6262026/09/23 13:18:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6272026/09/23 13:18:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6282026/09/23 13:18:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6292026/09/23 13:18:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"630--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)631=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle632=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle633=== RUN TestProxyWriteTimeout634=== PAUSE TestProxyWriteTimeout635=== RUN TestIsValidUploadKey636=== PAUSE TestIsValidUploadKey637=== RUN TestUploadHandlersRejectInvalidKeys638=== PAUSE TestUploadHandlersRejectInvalidKeys639=== RUN TestUploadHandlersRejectOversizedBody640=== PAUSE TestUploadHandlersRejectOversizedBody641=== RUN TestService_cleanupPendingClosuresHandler642=== PAUSE TestService_cleanupPendingClosuresHandler643=== RUN TestService_createPendingClosureHandler644=== PAUSE TestService_createPendingClosureHandler645=== RUN TestService_verifyS3Integrity646=== PAUSE TestService_verifyS3Integrity647=== RUN TestCompleteMultipartUnregistered648=== PAUSE TestCompleteMultipartUnregistered649=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT650=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT651=== CONT TestSkippedUploadsHandler652=== CONT TestService_AuthMiddleware653=== CONT TestCreatePendingClosureRejectsOversizedNAR654=== CONT TestCacheConfigHandlerMaxNarSize655=== CONT TestGenerateLandingPage6562026/09/23 13:18:08 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000657=== CONT TestService_readinessHandler658=== CONT TestService_healthCheckHandler6592026/09/23 13:18:08 INFO Received uploads request method=POST path=/api/pending_closures660=== CONT TestNARDeduplicationMetadataUploadBug661=== CONT TestPush_CommitFailsWhenSkippedKeyWasCollected662=== CONT TestGracefulShutdownDrainsInflight663=== CONT TestParseSize664=== CONT TestGCMetrics665=== CONT TestGCTaskStore_Fail666=== CONT TestPush_CompleteCommitsEveryRoot667=== CONT TestService_Rustfstest668=== CONT TestGCTaskStore_PhaseUpdates669=== CONT TestPresignedUploadRegisteredBeforeCommit670=== CONT TestGCTaskStore_CompletedAllowsNewTask671=== CONT TestCompletedNarNotReofferedAcrossClosures672=== CONT TestGCTaskStore_GetReturnsLatest673=== CONT TestCompleteMultipartUpload_ErrorButObjectExists674=== CONT TestGCTaskStore_GetEmpty675=== CONT TestRedundantMultipartUpload6762026/09/23 13:18:08 INFO Starting HTTP server address=127.0.0.1:44589677=== CONT TestGCTaskStore_ConflictDifferentParams678=== CONT TestPush_SignsNarinfosOfItsPendingObjects679=== CONT TestGCTaskStore_DeduplicateSameParams680=== CONT TestPush_RejectsBadRequests681--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)682=== CONT TestGCTaskStore_StartNew683=== CONT TestGCBugBareHashReferences684=== CONT TestPush_OverlappingRootsStoreOneRowPerKey685--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)686--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)687=== CONT TestReadRedirectUsesPublicS3URL688=== CONT TestReadProxyRangeRequest689=== CONT TestLeadElectsOneAndHandsOver690=== CONT TestResolveDBConnectionString691--- PASS: TestParseSize (0.00s)692--- PASS: TestGCTaskStore_Fail (0.00s)693=== CONT TestLeadEndsOnShutdown694--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)695--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)696--- PASS: TestGCTaskStore_GetEmpty (0.00s)697--- PASS: TestGCTaskStore_StartNew (0.00s)698--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)699--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)700=== RUN TestResolveDBConnectionString/flag_wins701=== PAUSE TestResolveDBConnectionString/flag_wins702=== RUN TestResolveDBConnectionString/file_when_flag_empty7032026/09/23 13:18:08 INFO Shutdown signal received, draining in-flight requests timeout=10s704=== PAUSE TestResolveDBConnectionString/file_when_flag_empty705=== RUN TestResolveDBConnectionString/missing_file_is_an_error706=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error707=== RUN TestResolveDBConnectionString/PGHOST_allows_empty708=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty709=== RUN TestResolveDBConnectionString/nothing_configured710=== PAUSE TestResolveDBConnectionString/nothing_configured711=== CONT TestReadRedirectKeepsNarinfoProxied712--- PASS: TestSkippedUploadsHandler (0.01s)713=== CONT TestClientFallsBackToClosures714--- PASS: TestGenerateLandingPage (0.01s)715=== CONT TestReadRedirectNar716--- PASS: TestGracefulShutdownDrainsInflight (0.08s)717=== CONT TestClientPushesUseOnePush7182026-09-23 13:18:08.238 UTC [451] ERROR: relation "goose_db_version" does not exist at character 367192026-09-23 13:18:08.238 UTC [451] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7202026-09-23 13:18:08.241 UTC [452] ERROR: relation "goose_db_version" does not exist at character 367212026-09-23 13:18:08.241 UTC [452] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7222026-09-23 13:18:08.297 UTC [453] ERROR: relation "goose_db_version" does not exist at character 367232026-09-23 13:18:08.297 UTC [453] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7242026-09-23 13:18:08.304 UTC [454] ERROR: relation "goose_db_version" does not exist at character 367252026-09-23 13:18:08.304 UTC [454] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7262026-09-23 13:18:08.306 UTC [455] ERROR: relation "goose_db_version" does not exist at character 367272026-09-23 13:18:08.306 UTC [455] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7282026-09-23 13:18:08.353 UTC [456] ERROR: relation "goose_db_version" does not exist at character 367292026-09-23 13:18:08.353 UTC [456] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7302026/09/23 13:18:08 OK 20241026095416_initial_model.sql (77.94ms)7312026/09/23 13:18:08 OK 20241026095416_initial_model.sql (77.95ms)7322026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (3.89ms)7332026/09/23 13:18:08 OK 20241026095416_initial_model.sql (47.98ms)7342026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (5.45ms)7352026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (4.16ms)7362026/09/23 13:18:08 OK 20251218171726_add_pins.sql (19.65ms)7372026/09/23 13:18:08 OK 20241026095416_initial_model.sql (60.04ms)7382026/09/23 13:18:08 OK 20251218171726_add_pins.sql (18.59ms)7392026/09/23 13:18:08 OK 20241026095416_initial_model.sql (53.52ms)7402026-09-23 13:18:08.396 UTC [457] ERROR: relation "goose_db_version" does not exist at character 367412026-09-23 13:18:08.396 UTC [457] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7422026/09/23 13:18:08 OK 20251218171726_add_pins.sql (17.04ms)7432026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (7.17ms)7442026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (6.31ms)7452026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (11.03ms)7462026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (10.21ms)7472026/09/23 13:18:08 OK 20241026095416_initial_model.sql (30.34ms)7482026-09-23 13:18:08.406 UTC [458] ERROR: relation "goose_db_version" does not exist at character 367492026-09-23 13:18:08.406 UTC [458] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7502026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (9.41ms)7512026/09/23 13:18:08 OK 20251218171726_add_pins.sql (8.69ms)7522026/09/23 13:18:08 OK 20251218171726_add_pins.sql (8.26ms)7532026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (4.89ms)7542026/09/23 13:18:08 OK 20260905000000_add_claims.sql (7.62ms)7552026/09/23 13:18:08 OK 20260905000000_add_claims.sql (7.97ms)7562026/09/23 13:18:08 OK 20260905000000_add_claims.sql (8.01ms)7572026-09-23 13:18:08.419 UTC [459] ERROR: relation "goose_db_version" does not exist at character 367582026-09-23 13:18:08.419 UTC [459] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7592026-09-23 13:18:08.420 UTC [460] ERROR: relation "goose_db_version" does not exist at character 367602026-09-23 13:18:08.420 UTC [460] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7612026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (16.8ms)7622026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (20.4ms)7632026/09/23 13:18:08 OK 20241026095416_initial_model.sql (22.81ms)7642026/09/23 13:18:08 OK 20251218171726_add_pins.sql (18.76ms)7652026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (19.19ms)7662026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (17.39ms)7672026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (15.77ms)7682026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (2.79ms)7692026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (4.86ms)7702026/09/23 13:18:08 goose: successfully migrated database to version: 202609231200007712026/09/23 13:18:08 OK 20260905000000_add_claims.sql (4.92ms)7722026/09/23 13:18:08 OK 20260905000000_add_claims.sql (6.43ms)7732026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (5.04ms)7742026/09/23 13:18:08 goose: successfully migrated database to version: 202609231200007752026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (4.94ms)7762026/09/23 13:18:08 goose: successfully migrated database to version: 202609231200007772026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (7.64ms)7782026/09/23 13:18:08 OK 1_commit_pending_closure.sql (5.08ms)7792026/09/23 13:18:08 OK 20251218171726_add_pins.sql (6.22ms)7802026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (7.53ms)7812026/09/23 13:18:08 OK 2_object_stats_trigger.sql (4.2ms)7822026/09/23 13:18:08 OK 1_commit_pending_closure.sql (5.91ms)7832026-09-23 13:18:08.444 UTC [461] ERROR: relation "goose_db_version" does not exist at character 367842026-09-23 13:18:08.444 UTC [461] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7852026-09-23 13:18:08.444 UTC [462] ERROR: relation "goose_db_version" does not exist at character 367862026-09-23 13:18:08.444 UTC [462] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7872026-09-23 13:18:08.445 UTC [464] ERROR: relation "goose_db_version" does not exist at character 367882026-09-23 13:18:08.445 UTC [464] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7892026/09/23 13:18:08 OK 20260905000000_add_claims.sql (7.54ms)7902026/09/23 13:18:08 OK 20241026095416_initial_model.sql (16.72ms)7912026-09-23 13:18:08.446 UTC [465] ERROR: relation "goose_db_version" does not exist at character 367922026-09-23 13:18:08.446 UTC [465] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7932026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (5.77ms)7942026/09/23 13:18:08 OK 2_object_stats_trigger.sql (3.9ms)7952026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (8.21ms)7962026/09/23 13:18:08 OK 1_commit_pending_closure.sql (6.3ms)7972026/09/23 13:18:08 OK 3_commit_push.sql (3.81ms)7982026/09/23 13:18:08 goose: up to current file version: 37992026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (5.01ms)8002026/09/23 13:18:08 goose: successfully migrated database to version: 202609231200008012026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (3.68ms)8022026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (3.74ms)8032026/09/23 13:18:08 OK 3_commit_push.sql (2.12ms)8042026/09/23 13:18:08 goose: up to current file version: 38052026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (5.12ms)8062026/09/23 13:18:08 goose: successfully migrated database to version: 202609231200008072026/09/23 13:18:08 OK 20241026095416_initial_model.sql (14.76ms)8082026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (4.39ms)8092026-09-23 13:18:08.454 UTC [466] ERROR: relation "goose_db_version" does not exist at character 368102026-09-23 13:18:08.454 UTC [466] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8112026/09/23 13:18:08 goose: successfully migrated database to version: 202609231200008122026/09/23 13:18:08 OK 20241026095416_initial_model.sql (15.68ms)8132026-09-23 13:18:08.455 UTC [467] ERROR: relation "goose_db_version" does not exist at character 368142026-09-23 13:18:08.455 UTC [467] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8152026/09/23 13:18:08 OK 2_object_stats_trigger.sql (3.11ms)8162026/09/23 13:18:08 OK 20260905000000_add_claims.sql (5.29ms)8172026-09-23 13:18:08.456 UTC [468] ERROR: relation "goose_db_version" does not exist at character 368182026-09-23 13:18:08.456 UTC [468] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8192026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (3.75ms)8202026/09/23 13:18:08 OK 1_commit_pending_closure.sql (4.62ms)8212026/09/23 13:18:08 OK 1_commit_pending_closure.sql (4.49ms)8222026/09/23 13:18:08 OK 3_commit_push.sql (2.21ms)8232026/09/23 13:18:08 goose: up to current file version: 38242026/09/23 13:18:08 OK 20251218171726_add_pins.sql (5.24ms)8252026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (3.86ms)8262026-09-23 13:18:08.458 UTC [469] ERROR: relation "goose_db_version" does not exist at character 368272026-09-23 13:18:08.458 UTC [469] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8282026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (2.89ms)8292026/09/23 13:18:08 OK 1_commit_pending_closure.sql (5.03ms)8302026/09/23 13:18:08 OK 2_object_stats_trigger.sql (2.56ms)8312026-09-23 13:18:08.460 UTC [470] ERROR: relation "goose_db_version" does not exist at character 368322026-09-23 13:18:08.460 UTC [470] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8332026/09/23 13:18:08 OK 2_object_stats_trigger.sql (3.95ms)8342026/09/23 13:18:08 OK 2_object_stats_trigger.sql (2.7ms)8352026-09-23 13:18:08.462 UTC [471] ERROR: relation "goose_db_version" does not exist at character 368362026-09-23 13:18:08.462 UTC [471] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8372026-09-23 13:18:08.462 UTC [472] ERROR: relation "goose_db_version" does not exist at character 368382026-09-23 13:18:08.462 UTC [472] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8392026/09/23 13:18:08 OK 3_commit_push.sql (2.56ms)8402026/09/23 13:18:08 OK 20251218171726_add_pins.sql (4.89ms)8412026/09/23 13:18:08 goose: up to current file version: 38422026/09/23 13:18:08 OK 20251218171726_add_pins.sql (5.82ms)8432026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (4.54ms)8442026/09/23 13:18:08 goose: successfully migrated database to version: 202609231200008452026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (6.3ms)8462026/09/23 13:18:08 OK 3_commit_push.sql (2.56ms)8472026/09/23 13:18:08 goose: up to current file version: 38482026/09/23 13:18:08 OK 3_commit_push.sql (3.42ms)8492026/09/23 13:18:08 goose: up to current file version: 38502026/09/23 13:18:08 OK 20241026095416_initial_model.sql (13.57ms)8512026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (4.41ms)8522026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (4.61ms)8532026/09/23 13:18:08 OK 1_commit_pending_closure.sql (5.42ms)8542026/09/23 13:18:08 OK 20241026095416_initial_model.sql (13.55ms)8552026/09/23 13:18:08 OK 20241026095416_initial_model.sql (15.13ms)8562026/09/23 13:18:08 OK 20260905000000_add_claims.sql (5.52ms)8572026-09-23 13:18:08.471 UTC [473] ERROR: relation "goose_db_version" does not exist at character 368582026-09-23 13:18:08.471 UTC [473] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8592026/09/23 13:18:08 OK 20241026095416_initial_model.sql (15.09ms)8602026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (3.52ms)8612026/09/23 13:18:08 OK 2_object_stats_trigger.sql (3.84ms)8622026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (4.04ms)8632026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (4.11ms)8642026/09/23 13:18:08 OK 20260905000000_add_claims.sql (6.38ms)8652026-09-23 13:18:08.474 UTC [474] ERROR: relation "goose_db_version" does not exist at character 368662026-09-23 13:18:08.474 UTC [474] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8672026-09-23 13:18:08.475 UTC [475] ERROR: relation "goose_db_version" does not exist at character 368682026-09-23 13:18:08.475 UTC [475] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8692026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (5.03ms)8702026/09/23 13:18:08 OK 3_commit_push.sql (2.95ms)8712026/09/23 13:18:08 goose: up to current file version: 38722026/09/23 13:18:08 OK 20241026095416_initial_model.sql (12.91ms)8732026/09/23 13:18:08 OK 20241026095416_initial_model.sql (13.86ms)8742026/09/23 13:18:08 OK 20251218171726_add_pins.sql (6.35ms)8752026/09/23 13:18:08 OK 20251218171726_add_pins.sql (5.37ms)8762026/09/23 13:18:08 OK 20251218171726_add_pins.sql (5.47ms)8772026/09/23 13:18:08 OK 20260905000000_add_claims.sql (6.99ms)8782026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (3.39ms)8792026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (5ms)8802026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (4.6ms)8812026/09/23 13:18:08 goose: successfully migrated database to version: 202609231200008822026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (2.73ms)8832026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (2.9ms)8842026/09/23 13:18:08 OK 20241026095416_initial_model.sql (15.1ms)8852026/09/23 13:18:08 OK 20241026095416_initial_model.sql (13.11ms)8862026/09/23 13:18:08 OK 20241026095416_initial_model.sql (14.7ms)8872026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (4.3ms)8882026/09/23 13:18:08 OK 1_commit_pending_closure.sql (3.85ms)8892026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (4.41ms)8902026/09/23 13:18:08 goose: successfully migrated database to version: 202609231200008912026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (5.25ms)8922026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (5.21ms)8932026/09/23 13:18:08 OK 20251218171726_add_pins.sql (4.62ms)8942026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (6.3ms)8952026/09/23 13:18:08 OK 20251218171726_add_pins.sql (4.77ms)8962026/09/23 13:18:08 OK 20241026095416_initial_model.sql (14.28ms)8972026/09/23 13:18:08 OK 20251218171726_add_pins.sql (6.2ms)8982026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (3.67ms)8992026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (3.68ms)9002026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (3.83ms)9012026/09/23 13:18:08 OK 2_object_stats_trigger.sql (2.54ms)9022026/09/23 13:18:08 OK 20241026095416_initial_model.sql (16.75ms)9032026/09/23 13:18:08 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"904--- PASS: TestService_AuthMiddleware (0.38s)9052026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (3.35ms)9062026/09/23 13:18:08 goose: successfully migrated database to version: 20260923120000907=== CONT TestReadProxyDisabled9082026/09/23 13:18:08 OK 1_commit_pending_closure.sql (3.89ms)9092026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (3.13ms)9102026/09/23 13:18:08 OK 3_commit_push.sql (2.98ms)9112026/09/23 13:18:08 goose: up to current file version: 39122026/09/23 13:18:08 OK 20260905000000_add_claims.sql (5.39ms)9132026/09/23 13:18:08 OK 20260905000000_add_claims.sql (5.45ms)9142026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (3.29ms)9152026/09/23 13:18:08 OK 20260905000000_add_claims.sql (5.36ms)9162026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (5.29ms)9172026/09/23 13:18:08 OK 20251218171726_add_pins.sql (5.11ms)9182026/09/23 13:18:08 OK 20251218171726_add_pins.sql (5.18ms)9192026/09/23 13:18:08 OK 2_object_stats_trigger.sql (2.43ms)9202026/09/23 13:18:08 OK 1_commit_pending_closure.sql (3.88ms)9212026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (5.42ms)9222026/09/23 13:18:08 OK 20251218171726_add_pins.sql (5.23ms)9232026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (5.53ms)9242026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (3.2ms)9252026/09/23 13:18:08 OK 3_commit_push.sql (2.72ms)9262026/09/23 13:18:08 goose: up to current file version: 39272026/09/23 13:18:08 OK 20251218171726_add_pins.sql (5.32ms)9282026/09/23 13:18:08 OK 20241026095416_initial_model.sql (11.56ms)9292026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (4.78ms)9302026/09/23 13:18:08 OK 20251218171726_add_pins.sql (5.11ms)9312026/09/23 13:18:08 OK 20241026095416_initial_model.sql (14.38ms)9322026/09/23 13:18:08 OK 2_object_stats_trigger.sql (3.87ms)9332026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (5.5ms)9342026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (3.44ms)9352026/09/23 13:18:08 goose: successfully migrated database to version: 202609231200009362026/09/23 13:18:08 OK 20260905000000_add_claims.sql (5.12ms)9372026/09/23 13:18:08 OK 20260905000000_add_claims.sql (5.26ms)9382026/09/23 13:18:08 OK 20260905000000_add_claims.sql (5.88ms)9392026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (5.68ms)9402026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (5.81ms)9412026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (5.86ms)9422026/09/23 13:18:08 OK 20241026095416_initial_model.sql (13.85ms)9432026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (3.3ms)9442026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (3.01ms)9452026/09/23 13:18:08 goose: successfully migrated database to version: 202609231200009462026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (4.23ms)9472026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (2.18ms)9482026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (3.44ms)9492026/09/23 13:18:08 OK 1_commit_pending_closure.sql (4.31ms)9502026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (4.36ms)9512026/09/23 13:18:08 goose: successfully migrated database to version: 202609231200009522026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (3.93ms)9532026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (5.02ms)9542026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (5.05ms)9552026/09/23 13:18:08 OK 3_commit_push.sql (2.44ms)9562026/09/23 13:18:08 goose: up to current file version: 39572026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (7.02ms)9582026/09/23 13:18:08 OK 1_commit_pending_closure.sql (4.44ms)9592026/09/23 13:18:08 OK 20260905000000_add_claims.sql (5.31ms)9602026/09/23 13:18:08 OK 20251218171726_add_pins.sql (4.74ms)9612026/09/23 13:18:08 OK 20260905000000_add_claims.sql (5.36ms)9622026/09/23 13:18:08 OK 20260905000000_add_claims.sql (5.01ms)9632026/09/23 13:18:08 OK 20251218171726_add_pins.sql (5.09ms)9642026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (3.31ms)9652026/09/23 13:18:08 goose: successfully migrated database to version: 202609231200009662026/09/23 13:18:08 OK 20260905000000_add_claims.sql (5.58ms)9672026/09/23 13:18:08 OK 2_object_stats_trigger.sql (2.58ms)9682026/09/23 13:18:08 OK 2_object_stats_trigger.sql (2.22ms)9692026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (2.85ms)9702026/09/23 13:18:08 goose: successfully migrated database to version: 202609231200009712026/09/23 13:18:08 OK 1_commit_pending_closure.sql (3.58ms)9722026/09/23 13:18:08 OK 3_commit_push.sql (1.74ms)9732026/09/23 13:18:08 goose: up to current file version: 39742026/09/23 13:18:08 OK 20251218171726_add_pins.sql (4.35ms)9752026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (3.93ms)9762026/09/23 13:18:08 goose: successfully migrated database to version: 202609231200009772026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (3.72ms)9782026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (3.79ms)9792026/09/23 13:18:08 OK 3_commit_push.sql (1.88ms)9802026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (4.14ms)9812026/09/23 13:18:08 goose: up to current file version: 39822026/09/23 13:18:08 OK 2_object_stats_trigger.sql (1.8ms)9832026/09/23 13:18:08 OK 1_commit_pending_closure.sql (2.73ms)9842026/09/23 13:18:08 OK 1_commit_pending_closure.sql (2.11ms)9852026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (4.32ms)9862026/09/23 13:18:08 OK 20260905000000_add_claims.sql (4.39ms)9872026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (3.55ms)9882026/09/23 13:18:08 OK 1_commit_pending_closure.sql (2.14ms)9892026/09/23 13:18:08 OK 2_object_stats_trigger.sql (2.56ms)9902026/09/23 13:18:08 OK 3_commit_push.sql (2.78ms)9912026/09/23 13:18:08 goose: up to current file version: 39922026/09/23 13:18:08 OK 2_object_stats_trigger.sql (2.77ms)9932026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (5.82ms)9942026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (3.55ms)9952026/09/23 13:18:08 goose: successfully migrated database to version: 202609231200009962026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (4.5ms)9972026/09/23 13:18:08 goose: successfully migrated database to version: 202609231200009982026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (4.43ms)9992026/09/23 13:18:08 goose: successfully migrated database to version: 2026092312000010002026/09/23 13:18:08 OK 2_object_stats_trigger.sql (2.94ms)10012026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (4.55ms)10022026/09/23 13:18:08 goose: successfully migrated database to version: 2026092312000010032026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (4.78ms)10042026/09/23 13:18:08 OK 3_commit_push.sql (2.59ms)10052026/09/23 13:18:08 goose: up to current file version: 310062026/09/23 13:18:08 OK 20260905000000_add_claims.sql (5.51ms)10072026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (6.25ms)10082026/09/23 13:18:08 OK 3_commit_push.sql (2.93ms)10092026/09/23 13:18:08 goose: up to current file version: 310102026/09/23 13:18:08 OK 3_commit_push.sql (1.17ms)10112026/09/23 13:18:08 OK 20260905000000_add_claims.sql (2.96ms)10122026/09/23 13:18:08 goose: up to current file version: 310132026/09/23 13:18:08 OK 1_commit_pending_closure.sql (1.89ms)10142026/09/23 13:18:08 OK 1_commit_pending_closure.sql (2.01ms)10152026/09/23 13:18:08 OK 1_commit_pending_closure.sql (3.48ms)10162026/09/23 13:18:08 OK 1_commit_pending_closure.sql (3.02ms)10172026/09/23 13:18:08 OK 2_object_stats_trigger.sql (2.31ms)10182026/09/23 13:18:08 OK 2_object_stats_trigger.sql (2.59ms)10192026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (3.94ms)10202026/09/23 13:18:08 goose: successfully migrated database to version: 2026092312000010212026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (4.26ms)10222026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (3.96ms)10232026/09/23 13:18:08 OK 2_object_stats_trigger.sql (2.44ms)10242026/09/23 13:18:08 OK 2_object_stats_trigger.sql (2.69ms)10252026/09/23 13:18:08 OK 20260905000000_add_claims.sql (6.08ms)10262026/09/23 13:18:08 OK 3_commit_push.sql (2.79ms)10272026/09/23 13:18:08 goose: up to current file version: 310282026/09/23 13:18:08 OK 3_commit_push.sql (2.72ms)10292026/09/23 13:18:08 goose: up to current file version: 310302026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (3.08ms)10312026/09/23 13:18:08 goose: successfully migrated database to version: 2026092312000010322026/09/23 13:18:08 OK 3_commit_push.sql (2.56ms)10332026/09/23 13:18:08 goose: up to current file version: 310342026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (3.04ms)10352026/09/23 13:18:08 goose: successfully migrated database to version: 2026092312000010362026/09/23 13:18:08 OK 1_commit_pending_closure.sql (3.81ms)10372026/09/23 13:18:08 OK 3_commit_push.sql (2.5ms)10382026/09/23 13:18:08 goose: up to current file version: 310392026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (3.77ms)10402026/09/23 13:18:08 OK 2_object_stats_trigger.sql (2.25ms)10412026/09/23 13:18:08 OK 1_commit_pending_closure.sql (2.89ms)10422026/09/23 13:18:08 OK 1_commit_pending_closure.sql (3.6ms)10432026/09/23 13:18:08 OK 3_commit_push.sql (1.72ms)10442026/09/23 13:18:08 goose: up to current file version: 310452026/09/23 13:18:08 OK 2_object_stats_trigger.sql (2.09ms)10462026/09/23 13:18:08 OK 2_object_stats_trigger.sql (2.35ms)10472026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (3.54ms)10482026/09/23 13:18:08 goose: successfully migrated database to version: 2026092312000010492026/09/23 13:18:08 OK 3_commit_push.sql (810.75µs)10502026/09/23 13:18:08 goose: up to current file version: 310512026/09/23 13:18:08 OK 3_commit_push.sql (1.12ms)10522026/09/23 13:18:08 goose: up to current file version: 310532026/09/23 13:18:08 OK 1_commit_pending_closure.sql (2.45ms)10542026/09/23 13:18:08 OK 2_object_stats_trigger.sql (1.74ms)10552026/09/23 13:18:08 OK 3_commit_push.sql (2.31ms)10562026/09/23 13:18:08 goose: up to current file version: 310572026/09/23 13:18:08 WARN readiness check failed error="closed pool"1058--- PASS: TestService_readinessHandler (0.43s)1059=== CONT TestPinProtectsFromGC10602026-09-23 13:18:08.558 UTC [481] ERROR: relation "goose_db_version" does not exist at character 3610612026-09-23 13:18:08.558 UTC [481] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10622026/09/23 13:18:08 INFO Received push request method=POST path=/api/pushes10632026/09/23 13:18:08 OK 20241026095416_initial_model.sql (11.57ms)10642026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (3.06ms)10652026/09/23 13:18:08 OK 20251218171726_add_pins.sql (5.16ms)10662026/09/23 13:18:08 INFO Received complete push request method=POST path=/api/pushes/1/complete1067--- PASS: TestService_healthCheckHandler (0.49s)1068=== CONT TestReadProxyRootRedirectsToIndexHTML10692026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (4.91ms)10702026/09/23 13:18:08 OK 20260905000000_add_claims.sql (3.83ms)10712026/09/23 13:18:08 INFO Received push request method=POST path=/api/pushes10722026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (2.83ms)10732026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (2.31ms)10742026/09/23 13:18:08 goose: successfully migrated database to version: 2026092312000010752026/09/23 13:18:08 OK 1_commit_pending_closure.sql (3.12ms)10762026/09/23 13:18:08 OK 2_object_stats_trigger.sql (2.93ms)10772026/09/23 13:18:08 INFO Received complete push request method=POST path=/api/pushes/2/complete10782026-09-23 13:18:08.614 UTC [485] ERROR: relation "goose_db_version" does not exist at character 3610792026-09-23 13:18:08.614 UTC [485] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10802026/09/23 13:18:08 OK 3_commit_push.sql (1.85ms)10812026/09/23 13:18:08 goose: up to current file version: 310822026-09-23 13:18:08.615 UTC [482] ERROR: Push object missing: aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo10832026-09-23 13:18:08.615 UTC [482] CONTEXT: PL/pgSQL function commit_push(bigint) line 37 at RAISE10842026-09-23 13:18:08.615 UTC [482] STATEMENT: -- name: CommitPush :exec1085 SELECT commit_push($1::bigint)1086 1087--- PASS: TestPush_CommitFailsWhenSkippedKeyWasCollected (0.51s)1088=== CONT TestClientSharedPathCommittedMidPush10892026/09/23 13:18:08 OK 20241026095416_initial_model.sql (9.12ms)10902026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (2.27ms)10912026/09/23 13:18:08 INFO Aborted multipart uploads count=010922026/09/23 13:18:08 OK 20251218171726_add_pins.sql (3.83ms)10932026/09/23 13:18:08 WARN Force mode enabled - objects will be deleted immediately without grace period10942026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (5.19ms)10952026/09/23 13:18:08 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=010962026/09/23 13:18:08 INFO Vacuumed table table=pending_closures10972026/09/23 13:18:08 INFO Vacuumed table table=pending_objects10982026/09/23 13:18:08 OK 20260905000000_add_claims.sql (3.9ms)10992026/09/23 13:18:08 INFO Vacuumed table table=multipart_uploads11002026/09/23 13:18:08 INFO Vacuumed table table=closures11012026/09/23 13:18:08 INFO Vacuumed table table=objects11022026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (3.25ms)11032026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (2.68ms)11042026/09/23 13:18:08 goose: successfully migrated database to version: 202609231200001105--- PASS: TestGCMetrics (0.54s)1106=== CONT TestReadProxyConditionalGet11072026/09/23 13:18:08 OK 1_commit_pending_closure.sql (3.07ms)11082026/09/23 13:18:08 OK 2_object_stats_trigger.sql (2.05ms)11092026/09/23 13:18:08 OK 3_commit_push.sql (1.68ms)11102026/09/23 13:18:08 goose: up to current file version: 311112026-09-23 13:18:08.666 UTC [491] ERROR: relation "goose_db_version" does not exist at character 3611122026-09-23 13:18:08.666 UTC [491] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11132026/09/23 13:18:08 INFO Received push request method=POST path=/api/pushes11142026/09/23 13:18:08 OK 20241026095416_initial_model.sql (12.55ms)11152026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (2.51ms)11162026-09-23 13:18:08.689 UTC [493] ERROR: relation "goose_db_version" does not exist at character 3611172026-09-23 13:18:08.689 UTC [493] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11182026/09/23 13:18:08 OK 20251218171726_add_pins.sql (4.84ms)11192026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (4.89ms)1120=== NAME TestNARDeduplicationMetadataUploadBug1121 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3057646980/001/store/53kpbps0k3dn6vbijz3jr8l7aw1yhigz-file1.txt11222026/09/23 13:18:08 OK 20260905000000_add_claims.sql (11.48ms)11232026/09/23 13:18:08 OK 20241026095416_initial_model.sql (16.03ms)11242026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (1.55ms)11252026/09/23 13:18:08 INFO Received complete push request method=POST path=/api/pushes/1/complete11262026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (3.4ms)11272026/09/23 13:18:08 INFO Received uploads request method=POST path=/api/pending_closures11282026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (2.92ms)11292026/09/23 13:18:08 goose: successfully migrated database to version: 2026092312000011302026/09/23 13:18:08 OK 20251218171726_add_pins.sql (3.52ms)11312026/09/23 13:18:08 OK 1_commit_pending_closure.sql (2.15ms)11322026/09/23 13:18:08 OK 2_object_stats_trigger.sql (937.61µs)11332026/09/23 13:18:08 OK 3_commit_push.sql (791.27µs)11342026/09/23 13:18:08 goose: up to current file version: 311352026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (4.16ms)1136--- PASS: TestPush_CompleteCommitsEveryRoot (0.61s)1137=== CONT TestService_cleanupPendingClosuresHandler11382026-09-23 13:18:08.724 UTC [513] ERROR: relation "goose_db_version" does not exist at character 3611392026-09-23 13:18:08.724 UTC [513] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11402026/09/23 13:18:08 OK 20260905000000_add_claims.sql (3.6ms)11412026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (2.95ms)11422026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (1.89ms)11432026/09/23 13:18:08 goose: successfully migrated database to version: 2026092312000011442026/09/23 13:18:08 OK 1_commit_pending_closure.sql (2.66ms)11452026/09/23 13:18:08 OK 2_object_stats_trigger.sql (3.53ms)11462026/09/23 13:18:08 OK 3_commit_push.sql (1.63ms)11472026/09/23 13:18:08 goose: up to current file version: 311482026/09/23 13:18:08 OK 20241026095416_initial_model.sql (10.48ms)11492026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (2.73ms)11502026/09/23 13:18:08 INFO Received push request method=POST path=/api/pushes11512026/09/23 13:18:08 OK 20251218171726_add_pins.sql (5.47ms)11522026/09/23 13:18:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11532026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (4.84ms)1154--- PASS: TestGCBugBareHashReferences (0.64s)1155=== CONT TestReadProxyHead11562026/09/23 13:18:08 OK 20260905000000_add_claims.sql (3.99ms)11572026/09/23 13:18:08 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NWZlNmE3NTYtNmU1Mi00NGQ3LWEwNmItYzRmZmRhZDM5Y2ZmLjdlM2MyNDYyLTRmODEtNDBhZS1iZDZhLTMyNmFmYTRmODIxYXgxNzkwMTY5NDg4NzI0MzcxNDA011582026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (2.84ms)11592026/09/23 13:18:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11602026/09/23 13:18:08 INFO Signed narinfos id=1 count=111612026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (2.87ms)11622026/09/23 13:18:08 goose: successfully migrated database to version: 202609231200001163--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.65s)1164=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT11652026/09/23 13:18:08 OK 1_commit_pending_closure.sql (2.88ms)11662026/09/23 13:18:08 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NWZlNmE3NTYtNmU1Mi00NGQ3LWEwNmItYzRmZmRhZDM5Y2ZmLjdlM2MyNDYyLTRmODEtNDBhZS1iZDZhLTMyNmFmYTRmODIxYXgxNzkwMTY5NDg4NzI0MzcxNDA0 parts=11167--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.66s)1168=== CONT TestReadProxyInvalidPath11692026/09/23 13:18:08 OK 2_object_stats_trigger.sql (2.28ms)11702026/09/23 13:18:08 OK 3_commit_push.sql (1.69ms)11712026/09/23 13:18:08 goose: up to current file version: 311722026/09/23 13:18:08 INFO Received uploads request method=POST path=/api/pending_closures11732026/09/23 13:18:08 INFO Received uploads request method=POST path=/api/pending_closures11742026/09/23 13:18:08 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11752026/09/23 13:18:08 INFO Uploading 53kpbps0k3dn6vbijz3jr8l7aw1yhigz-file1.txt (160B)11762026-09-23 13:18:08.795 UTC [557] ERROR: relation "goose_db_version" does not exist at character 3611772026-09-23 13:18:08.795 UTC [557] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11782026/09/23 13:18:08 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11792026/09/23 13:18:08 WARN Failed to register uploaded object key=53kpbps0k3dn6vbijz3jr8l7aw1yhigz.ls error="server returned 404: 404 page not found\n"11802026/09/23 13:18:08 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11812026/09/23 13:18:08 INFO Signed narinfos id=1 count=111822026/09/23 13:18:08 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11832026/09/23 13:18:08 INFO Uploading 1 narinfos11842026/09/23 13:18:08 INFO Received uploads request method=POST path=/api/pending_closures1185--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.69s)1186=== CONT TestCompleteMultipartUnregistered11872026/09/23 13:18:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11882026/09/23 13:18:08 WARN Failed to register uploaded object key=53kpbps0k3dn6vbijz3jr8l7aw1yhigz.narinfo error="server returned 404: 404 page not found\n"11892026/09/23 13:18:08 INFO Received uploads request method=POST path=/api/pending_closures11902026/09/23 13:18:08 INFO Completed upload id=111912026/09/23 13:18:08 INFO Upload complete. (70ms)11922026/09/23 13:18:08 OK 20241026095416_initial_model.sql (12.32ms)1193=== NAME TestNARDeduplicationMetadataUploadBug1194 metadata_upload_test.go:54: Retrieved narinfo from S3:1195 StorePath: /build/TestNARDeduplicationMetadataUploadBug3057646980/001/store/53kpbps0k3dn6vbijz3jr8l7aw1yhigz-file1.txt1196 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1197 Compression: zstd1198 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1199 NarSize: 1601200 References: 1201 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1202 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1203 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1204 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12052026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (9.07ms)12062026/09/23 13:18:08 INFO Received uploads request method=POST path=/api/pending_closures12072026/09/23 13:18:08 OK 20251218171726_add_pins.sql (4.52ms)12082026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (4.5ms)12092026/09/23 13:18:08 OK 20260905000000_add_claims.sql (3.54ms)1210=== RUN TestPush_RejectsBadRequests/no_roots1211=== PAUSE TestPush_RejectsBadRequests/no_roots1212=== RUN TestPush_RejectsBadRequests/no_objects12132026-09-23 13:18:08.836 UTC [561] ERROR: relation "goose_db_version" does not exist at character 3612142026-09-23 13:18:08.836 UTC [561] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1215=== PAUSE TestPush_RejectsBadRequests/no_objects1216=== RUN TestPush_RejectsBadRequests/bad_root1217=== PAUSE TestPush_RejectsBadRequests/bad_root1218=== RUN TestPush_RejectsBadRequests/root_not_in_objects1219=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1220=== CONT TestReadProxy40412212026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (3.02ms)12222026-09-23 13:18:08.840 UTC [562] ERROR: relation "goose_db_version" does not exist at character 3612232026-09-23 13:18:08.840 UTC [562] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12242026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (3.84ms)12252026/09/23 13:18:08 goose: successfully migrated database to version: 2026092312000012262026-09-23 13:18:08.845 UTC [564] ERROR: relation "goose_db_version" does not exist at character 3612272026-09-23 13:18:08.845 UTC [564] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12282026/09/23 13:18:08 OK 1_commit_pending_closure.sql (3.92ms)12292026/09/23 13:18:08 OK 2_object_stats_trigger.sql (2.02ms)12302026/09/23 13:18:08 OK 3_commit_push.sql (2.22ms)12312026/09/23 13:18:08 goose: up to current file version: 312322026/09/23 13:18:08 OK 20241026095416_initial_model.sql (11.18ms)1233=== NAME TestNARDeduplicationMetadataUploadBug1234 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3057646980/001/store/y082fab8cw4v5hrd0w0mb9nw3pws88in-file2.txt12352026/09/23 13:18:08 OK 20241026095416_initial_model.sql (12.49ms)12362026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (3.26ms)12372026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (2.4ms)12382026/09/23 13:18:08 OK 20241026095416_initial_model.sql (11.93ms)12392026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (3.79ms)12402026/09/23 13:18:08 OK 20251218171726_add_pins.sql (13.82ms)12412026/09/23 13:18:08 OK 20251218171726_add_pins.sql (12.9ms)12422026/09/23 13:18:08 OK 20251218171726_add_pins.sql (9.42ms)12432026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (5.27ms)12442026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (5.19ms)12452026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (6.43ms)12462026/09/23 13:18:08 INFO lead: acquired remote=192.0.2.1:123412472026/09/23 13:18:08 OK 20260905000000_add_claims.sql (4.27ms)12482026/09/23 13:18:08 OK 20260905000000_add_claims.sql (4.13ms)12492026-09-23 13:18:08.885 UTC [583] ERROR: relation "goose_db_version" does not exist at character 3612502026-09-23 13:18:08.885 UTC [583] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12512026/09/23 13:18:08 OK 20260905000000_add_claims.sql (5.41ms)12522026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (4.43ms)12532026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (4.15ms)12542026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (3.98ms)12552026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (3.21ms)12562026/09/23 13:18:08 goose: successfully migrated database to version: 2026092312000012572026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (3.5ms)12582026/09/23 13:18:08 goose: successfully migrated database to version: 2026092312000012592026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (3.83ms)12602026/09/23 13:18:08 goose: successfully migrated database to version: 2026092312000012612026/09/23 13:18:08 OK 1_commit_pending_closure.sql (3.72ms)12622026/09/23 13:18:08 OK 1_commit_pending_closure.sql (3.45ms)12632026/09/23 13:18:08 OK 1_commit_pending_closure.sql (3.2ms)12642026/09/23 13:18:08 OK 2_object_stats_trigger.sql (2.72ms)12652026/09/23 13:18:08 OK 2_object_stats_trigger.sql (2.21ms)12662026/09/23 13:18:08 OK 2_object_stats_trigger.sql (1.91ms)12672026/09/23 13:18:08 OK 3_commit_push.sql (2.04ms)12682026/09/23 13:18:08 goose: up to current file version: 312692026/09/23 13:18:08 OK 20241026095416_initial_model.sql (9.19ms)12702026/09/23 13:18:08 OK 3_commit_push.sql (1.41ms)12712026/09/23 13:18:08 goose: up to current file version: 312722026/09/23 13:18:08 OK 3_commit_push.sql (2.4ms)12732026/09/23 13:18:08 goose: up to current file version: 312742026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (1.69ms)12752026/09/23 13:18:08 OK 20251218171726_add_pins.sql (3.7ms)12762026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (4.09ms)12772026-09-23 13:18:08.913 UTC [603] ERROR: relation "goose_db_version" does not exist at character 3612782026-09-23 13:18:08.913 UTC [603] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12792026/09/23 13:18:08 OK 20260905000000_add_claims.sql (3.64ms)12802026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (2.38ms)12812026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (1.85ms)12822026/09/23 13:18:08 goose: successfully migrated database to version: 2026092312000012832026/09/23 13:18:08 OK 1_commit_pending_closure.sql (2.09ms)12842026/09/23 13:18:08 OK 2_object_stats_trigger.sql (1.03ms)12852026/09/23 13:18:08 OK 3_commit_push.sql (900.69µs)12862026/09/23 13:18:08 goose: up to current file version: 312872026/09/23 13:18:08 OK 20241026095416_initial_model.sql (10.36ms)12882026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (1.26ms)12892026/09/23 13:18:08 OK 20251218171726_add_pins.sql (3.84ms)12902026/09/23 13:18:08 INFO Received uploads request method=POST path=/api/pending_closures12912026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (3.24ms)12922026/09/23 13:18:08 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1293--- PASS: TestService_Rustfstest (0.83s)1294=== CONT TestService_verifyS3Integrity1295--- PASS: TestReadRedirectUsesPublicS3URL (0.83s)1296=== CONT TestReadProxyNarStreaming12972026/09/23 13:18:08 OK 20260905000000_add_claims.sql (4.01ms)12982026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (2.25ms)12992026/09/23 13:18:08 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13002026/09/23 13:18:08 WARN Failed to register uploaded object key=y082fab8cw4v5hrd0w0mb9nw3pws88in.ls error="server returned 404: 404 page not found\n"13012026/09/23 13:18:08 INFO Signed narinfos id=2 count=113022026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (1.65ms)13032026/09/23 13:18:08 goose: successfully migrated database to version: 2026092312000013042026/09/23 13:18:08 INFO Uploading 1 narinfos13052026/09/23 13:18:08 OK 1_commit_pending_closure.sql (1.95ms)13062026/09/23 13:18:08 OK 2_object_stats_trigger.sql (877.73µs)13072026/09/23 13:18:08 OK 3_commit_push.sql (879.75µs)13082026/09/23 13:18:08 goose: up to current file version: 313092026/09/23 13:18:08 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13102026/09/23 13:18:08 WARN Failed to register uploaded object key=y082fab8cw4v5hrd0w0mb9nw3pws88in.narinfo error="server returned 404: 404 page not found\n"13112026/09/23 13:18:08 INFO Completed upload id=213122026/09/23 13:18:08 INFO Upload complete. (61ms)1313=== NAME TestNARDeduplicationMetadataUploadBug1314 metadata_upload_test.go:76: Retrieved narinfo from S3:1315 StorePath: /build/TestNARDeduplicationMetadataUploadBug3057646980/001/store/y082fab8cw4v5hrd0w0mb9nw3pws88in-file2.txt1316 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1317 Compression: zstd1318 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1319 NarSize: 1601320 References: 1321 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1322 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1323 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1324 {"version":1,"root":{"type":"regular","size":44}}1325--- PASS: TestNARDeduplicationMetadataUploadBug (0.86s)13262026/09/23 13:18:08 INFO Received push request method=POST path=/api/pushes1327=== CONT TestReadProxyNarinfoAlreadyDecompressed13282026/09/23 13:18:09 INFO lead: acquired remote=192.0.2.1:123413292026/09/23 13:18:09 INFO lead: released remote=192.0.2.1:12341330--- PASS: TestLeadEndsOnShutdown (0.90s)1331=== CONT TestReadProxyNarinfo1332--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.90s)1333=== CONT TestIsValidCachePath1334=== RUN TestIsValidCachePath/narinfo1335=== PAUSE TestIsValidCachePath/narinfo1336=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1337=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1338=== RUN TestIsValidCachePath/nar_zst1339=== PAUSE TestIsValidCachePath/nar_zst1340=== RUN TestIsValidCachePath/nar_xz1341=== PAUSE TestIsValidCachePath/nar_xz1342=== RUN TestIsValidCachePath/nar_bz21343=== PAUSE TestIsValidCachePath/nar_bz21344=== RUN TestIsValidCachePath/nar_uncompressed1345=== PAUSE TestIsValidCachePath/nar_uncompressed1346=== RUN TestIsValidCachePath/ls1347=== PAUSE TestIsValidCachePath/ls1348=== RUN TestIsValidCachePath/log1349=== PAUSE TestIsValidCachePath/log1350=== RUN TestIsValidCachePath/realisation1351=== PAUSE TestIsValidCachePath/realisation1352=== RUN TestIsValidCachePath/nix-cache-info1353=== PAUSE TestIsValidCachePath/nix-cache-info1354=== RUN TestIsValidCachePath/index.html1355=== PAUSE TestIsValidCachePath/index.html1356=== RUN TestIsValidCachePath/traversal_parent1357=== PAUSE TestIsValidCachePath/traversal_parent1358=== RUN TestIsValidCachePath/traversal_in_middle1359=== PAUSE TestIsValidCachePath/traversal_in_middle1360=== RUN TestIsValidCachePath/invalid_char_e1361=== PAUSE TestIsValidCachePath/invalid_char_e1362=== RUN TestIsValidCachePath/invalid_char_u1363=== PAUSE TestIsValidCachePath/invalid_char_u1364=== RUN TestIsValidCachePath/random_path1365=== PAUSE TestIsValidCachePath/random_path1366=== RUN TestIsValidCachePath/empty1367=== PAUSE TestIsValidCachePath/empty1368=== RUN TestIsValidCachePath/leading_slash1369=== PAUSE TestIsValidCachePath/leading_slash1370=== RUN TestIsValidCachePath/wrong_extension1371=== PAUSE TestIsValidCachePath/wrong_extension1372=== RUN TestIsValidCachePath/short_hash1373=== PAUSE TestIsValidCachePath/short_hash1374=== CONT TestProxyHeadersOnlyTrustedOnSocket13752026/09/23 13:18:09 INFO lead: released remote=192.0.2.1:123413762026-09-23 13:18:09.045 UTC [635] ERROR: relation "goose_db_version" does not exist at character 3613772026-09-23 13:18:09.045 UTC [635] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13782026-09-23 13:18:09.045 UTC [634] ERROR: relation "goose_db_version" does not exist at character 3613792026-09-23 13:18:09.045 UTC [634] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13802026/09/23 13:18:09 INFO Received uploads request method=POST path=/api/pending_closures13812026-09-23 13:18:09.065 UTC [636] ERROR: relation "goose_db_version" does not exist at character 3613822026-09-23 13:18:09.065 UTC [636] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13832026/09/23 13:18:09 OK 20241026095416_initial_model.sql (13.95ms)13842026/09/23 13:18:09 OK 20241026095416_initial_model.sql (14.31ms)13852026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (3.39ms)13862026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (3.42ms)13872026/09/23 13:18:09 OK 20251218171726_add_pins.sql (4.39ms)13882026/09/23 13:18:09 OK 20251218171726_add_pins.sql (5.13ms)13892026/09/23 13:18:09 INFO lead: acquired remote=192.0.2.1:123413902026-09-23 13:18:09.089 UTC [637] ERROR: relation "goose_db_version" does not exist at character 3613912026-09-23 13:18:09.089 UTC [637] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13922026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (12.53ms)13932026/09/23 13:18:09 INFO lead: released remote=192.0.2.1:12341394--- PASS: TestLeadElectsOneAndHandsOver (0.98s)1395=== CONT TestParseSingleRange1396=== RUN TestParseSingleRange/none1397=== PAUSE TestParseSingleRange/none1398=== RUN TestParseSingleRange/unknown_unit1399=== PAUSE TestParseSingleRange/unknown_unit1400=== RUN TestParseSingleRange/multi-range_ignored1401=== PAUSE TestParseSingleRange/multi-range_ignored1402=== RUN TestParseSingleRange/malformed_no_dash1403=== PAUSE TestParseSingleRange/malformed_no_dash1404=== RUN TestParseSingleRange/malformed_both_empty1405=== PAUSE TestParseSingleRange/malformed_both_empty1406=== RUN TestParseSingleRange/malformed_end_before_start14072026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (13.26ms)1408=== PAUSE TestParseSingleRange/malformed_end_before_start1409=== RUN TestParseSingleRange/closed1410=== PAUSE TestParseSingleRange/closed14112026/09/23 13:18:09 OK 20241026095416_initial_model.sql (19.34ms)1412=== RUN TestParseSingleRange/open-ended1413=== PAUSE TestParseSingleRange/open-ended1414=== RUN TestParseSingleRange/end_clamped_to_size1415=== PAUSE TestParseSingleRange/end_clamped_to_size1416=== RUN TestParseSingleRange/suffix1417=== PAUSE TestParseSingleRange/suffix1418=== RUN TestParseSingleRange/suffix_exceeds_size1419=== PAUSE TestParseSingleRange/suffix_exceeds_size1420=== RUN TestParseSingleRange/single_byte1421=== PAUSE TestParseSingleRange/single_byte1422=== RUN TestParseSingleRange/start_past_EOF1423=== PAUSE TestParseSingleRange/start_past_EOF1424=== RUN TestParseSingleRange/start_far_past_EOF1425=== PAUSE TestParseSingleRange/start_far_past_EOF1426=== CONT TestCreatePin_ReservedPins14272026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (3.31ms)14282026/09/23 13:18:09 OK 20260905000000_add_claims.sql (5.29ms)14292026/09/23 13:18:09 OK 20260905000000_add_claims.sql (4.74ms)14302026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (3.56ms)14312026/09/23 13:18:09 OK 20251218171726_add_pins.sql (4.85ms)14322026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (3.6ms)14332026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (3.47ms)14342026/09/23 13:18:09 goose: successfully migrated database to version: 202609231200001435--- PASS: TestReadRedirectKeepsNarinfoProxied (0.99s)1436=== CONT TestResurrectedObjectNotDeleted14372026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (3.97ms)14382026/09/23 13:18:09 goose: successfully migrated database to version: 2026092312000014392026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (4.38ms)14402026/09/23 13:18:09 OK 1_commit_pending_closure.sql (2.67ms)14412026/09/23 13:18:09 OK 20241026095416_initial_model.sql (11.2ms)14422026/09/23 13:18:09 OK 2_object_stats_trigger.sql (1.76ms)14432026/09/23 13:18:09 OK 1_commit_pending_closure.sql (3.11ms)14442026/09/23 13:18:09 OK 20260905000000_add_claims.sql (3.31ms)14452026/09/23 13:18:09 OK 3_commit_push.sql (863.77µs)14462026/09/23 13:18:09 goose: up to current file version: 314472026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (1.39ms)14482026/09/23 13:18:09 OK 2_object_stats_trigger.sql (1.62ms)14492026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (2.53ms)14502026/09/23 13:18:09 OK 3_commit_push.sql (1.71ms)14512026/09/23 13:18:09 goose: up to current file version: 314522026/09/23 13:18:09 OK 20251218171726_add_pins.sql (2.76ms)14532026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (1.67ms)14542026/09/23 13:18:09 goose: successfully migrated database to version: 2026092312000014552026-09-23 13:18:09.113 UTC [640] ERROR: relation "goose_db_version" does not exist at character 3614562026-09-23 13:18:09.113 UTC [640] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14572026/09/23 13:18:09 OK 1_commit_pending_closure.sql (1.66ms)14582026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (3.02ms)14592026/09/23 13:18:09 OK 2_object_stats_trigger.sql (2.16ms)14602026/09/23 13:18:09 OK 3_commit_push.sql (2.27ms)14612026/09/23 13:18:09 goose: up to current file version: 314622026/09/23 13:18:09 OK 20260905000000_add_claims.sql (4.77ms)14632026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (4.49ms)14642026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (3.11ms)14652026/09/23 13:18:09 goose: successfully migrated database to version: 202609231200001466--- PASS: TestReadRedirectNar (1.01s)1467=== CONT TestOrphanedObjectsGCStressTest14682026/09/23 13:18:09 OK 1_commit_pending_closure.sql (3.43ms)14692026/09/23 13:18:09 OK 20241026095416_initial_model.sql (12.26ms)14702026/09/23 13:18:09 OK 2_object_stats_trigger.sql (2.15ms)14712026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (3ms)14722026/09/23 13:18:09 OK 3_commit_push.sql (2.12ms)14732026/09/23 13:18:09 goose: up to current file version: 314742026/09/23 13:18:09 OK 20251218171726_add_pins.sql (4.2ms)14752026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (4.72ms)14762026/09/23 13:18:09 OK 20260905000000_add_claims.sql (5.05ms)14772026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (3.03ms)14782026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (3.36ms)14792026/09/23 13:18:09 goose: successfully migrated database to version: 2026092312000014802026/09/23 13:18:09 OK 1_commit_pending_closure.sql (3.46ms)14812026/09/23 13:18:09 OK 2_object_stats_trigger.sql (2.21ms)14822026/09/23 13:18:09 OK 3_commit_push.sql (2.02ms)14832026/09/23 13:18:09 goose: up to current file version: 314842026-09-23 13:18:09.180 UTC [645] ERROR: relation "goose_db_version" does not exist at character 3614852026-09-23 13:18:09.180 UTC [645] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14862026/09/23 13:18:09 OK 20241026095416_initial_model.sql (10.65ms)14872026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (1.57ms)14882026/09/23 13:18:09 OK 20251218171726_add_pins.sql (3.55ms)14892026-09-23 13:18:09.205 UTC [664] ERROR: relation "goose_db_version" does not exist at character 3614902026-09-23 13:18:09.205 UTC [664] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14912026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (3.46ms)14922026/09/23 13:18:09 OK 20260905000000_add_claims.sql (3.53ms)14932026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (2.57ms)14942026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (2.92ms)14952026/09/23 13:18:09 goose: successfully migrated database to version: 2026092312000014962026/09/23 13:18:09 OK 1_commit_pending_closure.sql (3.37ms)1497--- PASS: TestReadProxyRangeRequest (1.11s)1498=== CONT TestService_createPendingClosureHandler14992026/09/23 13:18:09 OK 20241026095416_initial_model.sql (10.82ms)15002026/09/23 13:18:09 OK 2_object_stats_trigger.sql (1.88ms)15012026/09/23 13:18:09 OK 3_commit_push.sql (1.3ms)15022026/09/23 13:18:09 goose: up to current file version: 315032026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (1.65ms)15042026/09/23 13:18:09 OK 20251218171726_add_pins.sql (3.47ms)15052026/09/23 13:18:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36115/oidc15062026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (6ms)15072026/09/23 13:18:09 OK 20260905000000_add_claims.sql (4.37ms)1508--- PASS: TestReadProxyDisabled (0.76s)1509=== CONT TestOrphanedObjectsGC15102026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (4.96ms)15112026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (2.91ms)15122026/09/23 13:18:09 goose: successfully migrated database to version: 2026092312000015132026/09/23 13:18:09 OK 1_commit_pending_closure.sql (3.5ms)15142026/09/23 13:18:09 OK 2_object_stats_trigger.sql (2.54ms)15152026/09/23 13:18:09 OK 3_commit_push.sql (2.81ms)15162026/09/23 13:18:09 goose: up to current file version: 31517--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.72s)1518=== CONT TestIsValidUploadKey1519=== RUN TestIsValidUploadKey/narinfo1520=== PAUSE TestIsValidUploadKey/narinfo1521=== RUN TestIsValidUploadKey/nar_zst1522=== PAUSE TestIsValidUploadKey/nar_zst1523=== RUN TestIsValidUploadKey/nar_xz1524=== PAUSE TestIsValidUploadKey/nar_xz1525=== RUN TestIsValidUploadKey/nar_plain1526=== PAUSE TestIsValidUploadKey/nar_plain1527=== RUN TestIsValidUploadKey/listing1528=== PAUSE TestIsValidUploadKey/listing1529=== RUN TestIsValidUploadKey/build_log1530=== PAUSE TestIsValidUploadKey/build_log1531=== RUN TestIsValidUploadKey/build_log_home-manager_file1532=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1533=== RUN TestIsValidUploadKey/build_log_plus_in_name1534=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1535=== RUN TestIsValidUploadKey/build_log_question_mark1536=== PAUSE TestIsValidUploadKey/build_log_question_mark1537=== RUN TestIsValidUploadKey/build_log_equals1538=== PAUSE TestIsValidUploadKey/build_log_equals1539=== RUN TestIsValidUploadKey/realisation1540=== PAUSE TestIsValidUploadKey/realisation1541=== RUN TestIsValidUploadKey/realisation_plus_in_output1542=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1543=== RUN TestIsValidUploadKey/nix-cache-info1544=== PAUSE TestIsValidUploadKey/nix-cache-info1545=== RUN TestIsValidUploadKey/index.html1546=== PAUSE TestIsValidUploadKey/index.html1547=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1548=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1549=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1550=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1551=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1552=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1553=== RUN TestIsValidUploadKey/traversal1554=== PAUSE TestIsValidUploadKey/traversal1555=== RUN TestIsValidUploadKey/traversal_nar1556=== PAUSE TestIsValidUploadKey/traversal_nar1557=== RUN TestIsValidUploadKey/absolute1558=== PAUSE TestIsValidUploadKey/absolute1559=== RUN TestIsValidUploadKey/empty_key1560=== PAUSE TestIsValidUploadKey/empty_key1561=== RUN TestIsValidUploadKey/unknown_type1562=== PAUSE TestIsValidUploadKey/unknown_type1563=== CONT TestObjectStatsTrigger15642026-09-23 13:18:09.326 UTC [793] ERROR: relation "goose_db_version" does not exist at character 3615652026-09-23 13:18:09.326 UTC [793] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15662026-09-23 13:18:09.330 UTC [795] ERROR: relation "goose_db_version" does not exist at character 3615672026-09-23 13:18:09.330 UTC [795] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15682026/09/23 13:18:09 OK 20241026095416_initial_model.sql (12.09ms)15692026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (3.01ms)15702026/09/23 13:18:09 INFO Received uploads request method=POST path=/api/pending_closures15712026/09/23 13:18:09 OK 20241026095416_initial_model.sql (11.4ms)15722026-09-23 13:18:09.350 UTC [830] ERROR: relation "goose_db_version" does not exist at character 3615732026-09-23 13:18:09.350 UTC [830] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15742026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (2.58ms)15752026/09/23 13:18:09 OK 20251218171726_add_pins.sql (4.43ms)1576=== NAME TestPinProtectsFromGC1577 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC2045062214/001/store/3ssgwzhbcdw18pkcw0amf81l4x0ihraz-pinned-file.txt1578 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC2045062214/001/store/19bkb55v1kin29x5l3nd9lhmfcz45n8a-unpinned-file.txt15792026/09/23 13:18:09 INFO Received uploads request method=POST path=/api/pending_closures15802026/09/23 13:18:09 OK 20251218171726_add_pins.sql (4.53ms)15812026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (4.58ms)15822026/09/23 13:18:09 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15832026/09/23 13:18:09 INFO Uploading vd87plg21mvgmxg5lnpzr1v8k5mvkcsg-a (216B)15842026/09/23 13:18:09 INFO Uploading y5bb6didhpsr24bn6ns50qblk6f82sya-shared-dep (136B)15852026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (4.61ms)15862026/09/23 13:18:09 OK 20260905000000_add_claims.sql (4.94ms)15872026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (3.62ms)15882026/09/23 13:18:09 OK 20260905000000_add_claims.sql (5.1ms)15892026/09/23 13:18:09 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15902026/09/23 13:18:09 WARN Failed to register uploaded object key=y5bb6didhpsr24bn6ns50qblk6f82sya.ls error="server returned 404: 404 page not found\n"15912026/09/23 13:18:09 WARN Failed to register uploaded object key=nar/1x824xcq8zabm63p1czpf7l2dgrxy025ba7358wr4gwq30wd1yhv.nar.zst error="server returned 404: 404 page not found\n"15922026/09/23 13:18:09 WARN Failed to register uploaded object key=zs861g4x8ngx48mj6vaykzzbxafsrpc1.ls error="server returned 404: 404 page not found\n"15932026/09/23 13:18:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15942026/09/23 13:18:09 WARN Failed to register uploaded object key=vd87plg21mvgmxg5lnpzr1v8k5mvkcsg.ls error="server returned 404: 404 page not found\n"15952026/09/23 13:18:09 OK 20241026095416_initial_model.sql (12.24ms)15962026/09/23 13:18:09 INFO Signed narinfos id=1 count=215972026/09/23 13:18:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15982026/09/23 13:18:09 INFO Signed narinfos id=2 count=215992026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (3.66ms)16002026/09/23 13:18:09 INFO Uploading 4 narinfos16012026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (4.06ms)16022026/09/23 13:18:09 goose: successfully migrated database to version: 2026092312000016032026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (2.66ms)16042026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (2.26ms)16052026/09/23 13:18:09 goose: successfully migrated database to version: 2026092312000016062026/09/23 13:18:09 OK 1_commit_pending_closure.sql (2.88ms)16072026/09/23 13:18:09 OK 1_commit_pending_closure.sql (2.59ms)16082026/09/23 13:18:09 OK 2_object_stats_trigger.sql (1.96ms)16092026/09/23 13:18:09 OK 20251218171726_add_pins.sql (4.17ms)16102026/09/23 13:18:09 WARN Failed to register uploaded object key=vd87plg21mvgmxg5lnpzr1v8k5mvkcsg.narinfo error="server returned 404: 404 page not found\n"16112026/09/23 13:18:09 WARN Failed to register uploaded object key=zs861g4x8ngx48mj6vaykzzbxafsrpc1.narinfo error="server returned 404: 404 page not found\n"16122026/09/23 13:18:09 OK 2_object_stats_trigger.sql (1.14ms)16132026/09/23 13:18:09 OK 3_commit_push.sql (1.08ms)16142026/09/23 13:18:09 goose: up to current file version: 316152026/09/23 13:18:09 WARN Failed to register uploaded object key=y5bb6didhpsr24bn6ns50qblk6f82sya.narinfo error="server returned 404: 404 page not found\n"16162026/09/23 13:18:09 OK 3_commit_push.sql (1.44ms)16172026/09/23 13:18:09 goose: up to current file version: 316182026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (3.64ms)16192026/09/23 13:18:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16202026/09/23 13:18:09 WARN Failed to register uploaded object key=y5bb6didhpsr24bn6ns50qblk6f82sya.narinfo error="server returned 404: 404 page not found\n"16212026-09-23 13:18:09.386 UTC [867] ERROR: relation "goose_db_version" does not exist at character 3616222026-09-23 13:18:09.386 UTC [867] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1623--- PASS: TestReadProxyConditionalGet (0.73s)1624=== CONT TestUploadHandlersRejectOversizedBody16252026/09/23 13:18:09 OK 20260905000000_add_claims.sql (9.41ms)16262026/09/23 13:18:09 INFO Completed upload id=116272026/09/23 13:18:09 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16282026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (2.71ms)16292026/09/23 13:18:09 INFO Completed upload id=216302026/09/23 13:18:09 INFO Upload complete. (91ms)16312026/09/23 13:18:09 INFO Received uploads request method=POST path=/api/pending_closures1632=== NAME TestClientFallsBackToClosures1633 client_pushes_test.go:112: Retrieved narinfo from S3:1634 StorePath: /build/TestClientFallsBackToClosures1823860364/001/store/y5bb6didhpsr24bn6ns50qblk6f82sya-shared-dep1635 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1636 Compression: zstd1637 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821638 NarSize: 1361639 References: 1640 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n16412026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (2.67ms)16422026/09/23 13:18:09 goose: successfully migrated database to version: 2026092312000016432026/09/23 13:18:09 OK 1_commit_pending_closure.sql (3.13ms)1644 client_pushes_test.go:112: Retrieved narinfo from S3:1645 StorePath: /build/TestClientFallsBackToClosures1823860364/001/store/vd87plg21mvgmxg5lnpzr1v8k5mvkcsg-a1646 URL: nar/1x824xcq8zabm63p1czpf7l2dgrxy025ba7358wr4gwq30wd1yhv.nar.zst1647 Compression: zstd1648 NarHash: sha256:1x824xcq8zabm63p1czpf7l2dgrxy025ba7358wr4gwq30wd1yhv1649 NarSize: 2161650 References: /build/TestClientFallsBackToClosures1823860364/001/store/y5bb6didhpsr24bn6ns50qblk6f82sya-shared-dep1651 CA: text:sha256:0d589nm51zwq3w90d8rvb3n71b2xymina5qki0nwb04s40cbxf4f16522026/09/23 13:18:09 OK 2_object_stats_trigger.sql (2.73ms)16532026/09/23 13:18:09 OK 20241026095416_initial_model.sql (10.17ms)1654 client_pushes_test.go:112: Retrieved narinfo from S3:1655 StorePath: /build/TestClientFallsBackToClosures1823860364/001/store/zs861g4x8ngx48mj6vaykzzbxafsrpc1-b1656 URL: nar/1x824xcq8zabm63p1czpf7l2dgrxy025ba7358wr4gwq30wd1yhv.nar.zst1657 Compression: zstd1658 NarHash: sha256:1x824xcq8zabm63p1czpf7l2dgrxy025ba7358wr4gwq30wd1yhv1659 NarSize: 2161660 References: /build/TestClientFallsBackToClosures1823860364/001/store/y5bb6didhpsr24bn6ns50qblk6f82sya-shared-dep1661 CA: text:sha256:0d589nm51zwq3w90d8rvb3n71b2xymina5qki0nwb04s40cbxf4f16622026/09/23 13:18:09 OK 3_commit_push.sql (4.86ms)16632026/09/23 13:18:09 goose: up to current file version: 316642026/09/23 13:18:09 INFO Received uploads request method=POST path=/api/pending_closures16652026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (5.33ms)16662026/09/23 13:18:09 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16672026/09/23 13:18:09 INFO Uploading av4f6fk464jyv3n306xa12gw4b586q7p-a (208B)16682026/09/23 13:18:09 INFO Uploading mrbmkfd7lfkmi4h6gvz7bqpcn45xk98r-shared-dep (136B)1669--- PASS: TestClientFallsBackToClosures (1.29s)16702026/09/23 13:18:09 INFO Received cleanup request method=DELETE path=/api/pending_closures1671=== CONT TestMultipartCleanup16722026/09/23 13:18:09 OK 20251218171726_add_pins.sql (5.48ms)16732026/09/23 13:18:09 WARN Failed to register uploaded object key=8avgm4rknr59zhl8z53q2n2agl2bhbjr.ls error="server returned 404: 404 page not found\n"16742026/09/23 13:18:09 INFO Aborted multipart uploads count=016752026/09/23 13:18:09 WARN Failed to register uploaded object key=nar/0vnc65rd17rjbwjc82hbcq1l5v3rbkmsdyhlvmfggjmgn4hynl3l.nar.zst error="server returned 404: 404 page not found\n"16762026/09/23 13:18:09 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16772026/09/23 13:18:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16782026/09/23 13:18:09 WARN Failed to register uploaded object key=mrbmkfd7lfkmi4h6gvz7bqpcn45xk98r.ls error="server returned 404: 404 page not found\n"16792026/09/23 13:18:09 INFO Signed narinfos id=1 count=216802026/09/23 13:18:09 WARN Failed to register uploaded object key=av4f6fk464jyv3n306xa12gw4b586q7p.ls error="server returned 404: 404 page not found\n"16812026/09/23 13:18:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16822026/09/23 13:18:09 INFO Received uploads request method=POST path=/api/pending_closures16832026/09/23 13:18:09 INFO Signed narinfos id=2 count=216842026/09/23 13:18:09 INFO Uploading 4 narinfos16852026/09/23 13:18:09 WARN Failed to register uploaded object key=av4f6fk464jyv3n306xa12gw4b586q7p.narinfo error="server returned 404: 404 page not found\n"16862026/09/23 13:18:09 WARN Failed to register uploaded object key=mrbmkfd7lfkmi4h6gvz7bqpcn45xk98r.narinfo error="server returned 404: 404 page not found\n"16872026/09/23 13:18:09 WARN Failed to register uploaded object key=8avgm4rknr59zhl8z53q2n2agl2bhbjr.narinfo error="server returned 404: 404 page not found\n"16882026/09/23 13:18:09 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16892026/09/23 13:18:09 WARN Failed to register uploaded object key=mrbmkfd7lfkmi4h6gvz7bqpcn45xk98r.narinfo error="server returned 404: 404 page not found\n"16902026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (37.93ms)16912026/09/23 13:18:09 INFO Received uploads request method=POST path=/api/pending_closures16922026/09/23 13:18:09 INFO Completed upload id=216932026/09/23 13:18:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16942026/09/23 13:18:09 OK 20260905000000_add_claims.sql (6.53ms)16952026/09/23 13:18:09 INFO Completed upload id=116962026/09/23 13:18:09 INFO Upload complete. (113ms)16972026/09/23 13:18:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16982026/09/23 13:18:09 INFO Uploading 3ssgwzhbcdw18pkcw0amf81l4x0ihraz-pinned-file.txt (128B)1699=== NAME TestClientPushesUseOnePush1700 client_pushes_test.go:97: Retrieved narinfo from S3:1701 StorePath: /build/TestClientPushesUseOnePush47542481/001/store/mrbmkfd7lfkmi4h6gvz7bqpcn45xk98r-shared-dep1702 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1703 Compression: zstd1704 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821705 NarSize: 1361706 References: 1707 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n17082026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (6.19ms)17092026/09/23 13:18:09 INFO Received cleanup request method=DELETE path=/api/pending_closures17102026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (4.07ms)17112026/09/23 13:18:09 goose: successfully migrated database to version: 2026092312000017122026/09/23 13:18:09 INFO Aborted multipart uploads count=11713 client_pushes_test.go:97: Retrieved narinfo from S3:1714 StorePath: /build/TestClientPushesUseOnePush47542481/001/store/av4f6fk464jyv3n306xa12gw4b586q7p-a1715 URL: nar/0vnc65rd17rjbwjc82hbcq1l5v3rbkmsdyhlvmfggjmgn4hynl3l.nar.zst1716 Compression: zstd1717 NarHash: sha256:0vnc65rd17rjbwjc82hbcq1l5v3rbkmsdyhlvmfggjmgn4hynl3l1718 NarSize: 2081719 References: /build/TestClientPushesUseOnePush47542481/001/store/mrbmkfd7lfkmi4h6gvz7bqpcn45xk98r-shared-dep1720 CA: text:sha256:1w60vvx1r2xlqp6a1yfxl5bcfk9w3aqlac211yhs5bw0h2ixkida17212026/09/23 13:18:09 WARN Failed to register uploaded object key=3ssgwzhbcdw18pkcw0amf81l4x0ihraz.ls error="server returned 404: 404 page not found\n"17222026/09/23 13:18:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17232026/09/23 13:18:09 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"17242026/09/23 13:18:09 INFO Signed narinfos id=1 count=117252026/09/23 13:18:09 INFO Uploading 1 narinfos17262026/09/23 13:18:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1727 client_pushes_test.go:97: Retrieved narinfo from S3:1728 StorePath: /build/TestClientPushesUseOnePush47542481/001/store/8avgm4rknr59zhl8z53q2n2agl2bhbjr-b1729 URL: nar/0vnc65rd17rjbwjc82hbcq1l5v3rbkmsdyhlvmfggjmgn4hynl3l.nar.zst1730 Compression: zstd1731 NarHash: sha256:0vnc65rd17rjbwjc82hbcq1l5v3rbkmsdyhlvmfggjmgn4hynl3l1732 NarSize: 2081733 References: /build/TestClientPushesUseOnePush47542481/001/store/mrbmkfd7lfkmi4h6gvz7bqpcn45xk98r-shared-dep1734 CA: text:sha256:1w60vvx1r2xlqp6a1yfxl5bcfk9w3aqlac211yhs5bw0h2ixkida17352026-09-23 13:18:09.474 UTC [557] ERROR: Closure does not exist: id=117362026-09-23 13:18:09.474 UTC [557] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE17372026-09-23 13:18:09.474 UTC [557] STATEMENT: -- name: CommitPendingClosure :exec1738 SELECT commit_pending_closure($1::bigint)1739 17402026/09/23 13:18:09 OK 1_commit_pending_closure.sql (5.85ms)1741--- PASS: TestService_cleanupPendingClosuresHandler (0.75s)1742=== CONT TestUploadHandlersRejectInvalidKeys1743=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1744=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1745=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1746=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1747=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1748=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1749=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1750=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1751=== CONT TestServerTLSConfig1752=== RUN TestServerTLSConfig/no_client_CA1753=== PAUSE TestServerTLSConfig/no_client_CA1754=== RUN TestServerTLSConfig/missing_CA_file1755=== PAUSE TestServerTLSConfig/missing_CA_file1756=== RUN TestServerTLSConfig/not_a_PEM_file1757=== PAUSE TestServerTLSConfig/not_a_PEM_file1758=== CONT TestMetricsInventory1759=== NAME TestClientPushesUseOnePush1760 client_pushes_test.go:100: POST /api/pushes calls = 0, want 11761 client_pushes_test.go:104: POST /api/pending_closures calls = 2, want 017622026/09/23 13:18:09 OK 2_object_stats_trigger.sql (1.9ms)17632026/09/23 13:18:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17642026/09/23 13:18:09 WARN Failed to register uploaded object key=3ssgwzhbcdw18pkcw0amf81l4x0ihraz.narinfo error="server returned 404: 404 page not found\n"17652026/09/23 13:18:09 OK 3_commit_push.sql (2.32ms)17662026/09/23 13:18:09 goose: up to current file version: 31767--- FAIL: TestClientPushesUseOnePush (1.30s)1768=== CONT TestService_NativeMTLS17692026/09/23 13:18:09 INFO Completed upload id=117702026/09/23 13:18:09 INFO Upload complete. (91ms)1771--- PASS: TestReadProxyHead (0.74s)1772=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle17732026/09/23 13:18:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1774--- PASS: TestReadProxyInvalidPath (0.75s)1775=== CONT TestClientWithDependencies1776=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1777=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1778=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1779=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1780=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1781=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1782=== CONT TestCacheConfigHandler1783=== RUN TestCacheConfigHandler/full_config,_no_issuer1784=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1785=== RUN TestCacheConfigHandler/no_cache_url_configured1786=== PAUSE TestCacheConfigHandler/no_cache_url_configured1787=== RUN TestCacheConfigHandler/no_signing_keys1788=== PAUSE TestCacheConfigHandler/no_signing_keys1789=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1790=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1791=== CONT TestProxyWriteTimeout1792=== RUN TestProxyWriteTimeout/narinfo1793=== PAUSE TestProxyWriteTimeout/narinfo1794=== RUN TestProxyWriteTimeout/1_GiB_nar1795=== PAUSE TestProxyWriteTimeout/1_GiB_nar1796=== RUN TestProxyWriteTimeout/10_GiB_nar1797=== PAUSE TestProxyWriteTimeout/10_GiB_nar1798=== RUN TestProxyWriteTimeout/unknown_size1799=== PAUSE TestProxyWriteTimeout/unknown_size1800=== CONT TestClientMultipleUploads18012026/09/23 13:18:09 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NWZlNmE3NTYtNmU1Mi00NGQ3LWEwNmItYzRmZmRhZDM5Y2ZmLmEzYzhkZTEwLTA5NjYtNGJkNy05MWIwLThmY2JlNTBkOWU1ZXgxNzkwMTY5NDg4ODE1MzEzMDkz parts=121802--- PASS: TestRedundantMultipartUpload (1.43s)1803=== CONT TestService_ReadAuthMiddleware18042026/09/23 13:18:09 INFO Received uploads request method=POST path=/api/pending_closures18052026/09/23 13:18:09 INFO Received uploads request method=POST path=/api/pending_closures18062026/09/23 13:18:09 INFO Received uploads request method=POST path=/api/pending_closures18072026-09-23 13:18:09.557 UTC [1007] ERROR: relation "goose_db_version" does not exist at character 3618082026-09-23 13:18:09.557 UTC [1007] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18092026/09/23 13:18:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18102026/09/23 13:18:09 INFO Uploading 19bkb55v1kin29x5l3nd9lhmfcz45n8a-unpinned-file.txt (128B)18112026/09/23 13:18:09 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"18122026/09/23 13:18:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18132026/09/23 13:18:09 INFO Signed narinfos id=2 count=118142026/09/23 13:18:09 WARN Failed to register uploaded object key=19bkb55v1kin29x5l3nd9lhmfcz45n8a.ls error="server returned 404: 404 page not found\n"18152026/09/23 13:18:09 INFO Uploading 1 narinfos1816--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.81s)1817=== CONT TestClientIntegration18182026/09/23 13:18:09 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18192026/09/23 13:18:09 WARN Failed to register uploaded object key=19bkb55v1kin29x5l3nd9lhmfcz45n8a.narinfo error="server returned 404: 404 page not found\n"18202026/09/23 13:18:09 INFO Completed upload id=218212026/09/23 13:18:09 INFO Upload complete. (58ms)18222026-09-23 13:18:09.580 UTC [1043] ERROR: relation "goose_db_version" does not exist at character 3618232026-09-23 13:18:09.580 UTC [1043] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18242026-09-23 13:18:09.581 UTC [1044] ERROR: relation "goose_db_version" does not exist at character 3618252026-09-23 13:18:09.581 UTC [1044] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18262026/09/23 13:18:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18272026/09/23 13:18:09 OK 20241026095416_initial_model.sql (12.31ms)18282026/09/23 13:18:09 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1829--- PASS: TestCompleteMultipartUnregistered (0.79s)1830=== CONT TestService_ReadScope_PublicByDefault18312026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (3.96ms)18322026-09-23 13:18:09.593 UTC [1047] ERROR: relation "goose_db_version" does not exist at character 3618332026-09-23 13:18:09.593 UTC [1047] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18342026/09/23 13:18:09 OK 20251218171726_add_pins.sql (5.96ms)18352026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (5.75ms)18362026/09/23 13:18:09 OK 20241026095416_initial_model.sql (14.56ms)18372026/09/23 13:18:09 OK 20241026095416_initial_model.sql (14.37ms)18382026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (2.78ms)18392026/09/23 13:18:09 OK 20260905000000_add_claims.sql (5.4ms)18402026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (2.8ms)18412026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (4.32ms)18422026/09/23 13:18:09 OK 20251218171726_add_pins.sql (5.98ms)18432026-09-23 13:18:09.611 UTC [1067] ERROR: relation "goose_db_version" does not exist at character 3618442026-09-23 13:18:09.611 UTC [1067] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18452026/09/23 13:18:09 OK 20251218171726_add_pins.sql (5.76ms)18462026/09/23 13:18:09 INFO Received create pin request method=POST path=/api/pins/myapp18472026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (3.47ms)18482026/09/23 13:18:09 goose: successfully migrated database to version: 2026092312000018492026/09/23 13:18:09 OK 20241026095416_initial_model.sql (12.76ms)18502026-09-23 13:18:09.615 UTC [1085] ERROR: relation "goose_db_version" does not exist at character 3618512026-09-23 13:18:09.615 UTC [1085] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18522026/09/23 13:18:09 OK 1_commit_pending_closure.sql (3.76ms)18532026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (6.06ms)18542026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (7.24ms)18552026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (3.91ms)18562026/09/23 13:18:09 OK 2_object_stats_trigger.sql (2.22ms)18572026/09/23 13:18:09 OK 20251218171726_add_pins.sql (4.1ms)18582026-09-23 13:18:09.628 UTC [1087] ERROR: relation "goose_db_version" does not exist at character 3618592026-09-23 13:18:09.628 UTC [1087] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1860--- PASS: TestReadProxy404 (0.79s)1861=== CONT TestClientErrorHandling1862=== RUN TestClientErrorHandling/InvalidStorePath1863=== PAUSE TestClientErrorHandling/InvalidStorePath1864=== RUN TestClientErrorHandling/InvalidAuthToken1865=== PAUSE TestClientErrorHandling/InvalidAuthToken1866=== RUN TestClientErrorHandling/ServerNotAvailable1867=== PAUSE TestClientErrorHandling/ServerNotAvailable1868=== CONT TestClientCADerivations18692026/09/23 13:18:09 OK 3_commit_push.sql (13.49ms)18702026/09/23 13:18:09 goose: up to current file version: 318712026/09/23 13:18:09 OK 20260905000000_add_claims.sql (16.05ms)18722026/09/23 13:18:09 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2045062214/001/store/3ssgwzhbcdw18pkcw0amf81l4x0ihraz-pinned-file.txt narinfo_key=3ssgwzhbcdw18pkcw0amf81l4x0ihraz.narinfo18732026/09/23 13:18:09 OK 20260905000000_add_claims.sql (15.94ms)18742026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (13.68ms)18752026/09/23 13:18:09 OK 20241026095416_initial_model.sql (15.33ms)18762026/09/23 13:18:09 OK 20241026095416_initial_model.sql (16.21ms)18772026/09/23 13:18:09 INFO Starting cleanup of old closures method=DELETE path=/api/closures18782026/09/23 13:18:09 INFO Garbage collection started18792026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (4.58ms)18802026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (3.1ms)18812026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (3.39ms)18822026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (5.82ms)18832026/09/23 13:18:09 OK 20260905000000_add_claims.sql (5.13ms)18842026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (2.96ms)18852026/09/23 13:18:09 goose: successfully migrated database to version: 2026092312000018862026/09/23 13:18:09 INFO Received uploads request method=POST path=/api/pending_closures18872026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (4.26ms)18882026/09/23 13:18:09 goose: successfully migrated database to version: 2026092312000018892026/09/23 13:18:09 OK 1_commit_pending_closure.sql (3.74ms)18902026/09/23 13:18:09 OK 20251218171726_add_pins.sql (6.27ms)18912026/09/23 13:18:09 OK 20251218171726_add_pins.sql (6.51ms)18922026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (5.58ms)18932026/09/23 13:18:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18942026/09/23 13:18:09 INFO Uploading wv7f54204hqb7gg6c1h5ly7gh1dlahwp-shared-dep (136B)18952026/09/23 13:18:09 INFO Aborted multipart uploads count=018962026/09/23 13:18:09 OK 1_commit_pending_closure.sql (4.72ms)18972026/09/23 13:18:09 OK 2_object_stats_trigger.sql (3.69ms)18982026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (4.32ms)18992026/09/23 13:18:09 goose: successfully migrated database to version: 2026092312000019002026/09/23 13:18:09 OK 20241026095416_initial_model.sql (14.69ms)19012026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (7.01ms)19022026/09/23 13:18:09 WARN Force mode enabled - objects will be deleted immediately without grace period19032026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (7.1ms)19042026/09/23 13:18:09 OK 3_commit_push.sql (3.25ms)19052026/09/23 13:18:09 goose: up to current file version: 319062026/09/23 13:18:09 OK 2_object_stats_trigger.sql (3.45ms)19072026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (3.25ms)19082026/09/23 13:18:09 OK 1_commit_pending_closure.sql (3.31ms)19092026/09/23 13:18:09 WARN Failed to register uploaded object key=wv7f54204hqb7gg6c1h5ly7gh1dlahwp.ls error="server returned 404: 404 page not found\n"19102026/09/23 13:18:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign19112026/09/23 13:18:09 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19122026/09/23 13:18:09 INFO Signed narinfos id=2 count=119132026/09/23 13:18:09 INFO Uploading 1 narinfos19142026/09/23 13:18:09 OK 3_commit_push.sql (2.43ms)19152026/09/23 13:18:09 goose: up to current file version: 319162026/09/23 13:18:09 OK 2_object_stats_trigger.sql (2.71ms)19172026/09/23 13:18:09 OK 20260905000000_add_claims.sql (5.79ms)19182026/09/23 13:18:09 OK 20260905000000_add_claims.sql (5.45ms)19192026-09-23 13:18:09.660 UTC [1108] ERROR: relation "goose_db_version" does not exist at character 3619202026-09-23 13:18:09.660 UTC [1108] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19212026/09/23 13:18:09 OK 3_commit_push.sql (2.78ms)19222026/09/23 13:18:09 goose: up to current file version: 319232026/09/23 13:18:09 OK 20251218171726_add_pins.sql (6.02ms)19242026/09/23 13:18:09 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete19252026/09/23 13:18:09 WARN Failed to register uploaded object key=wv7f54204hqb7gg6c1h5ly7gh1dlahwp.narinfo error="server returned 404: 404 page not found\n"19262026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (5.81ms)19272026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (5.96ms)19282026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (4.85ms)19292026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (3.07ms)19302026/09/23 13:18:09 goose: successfully migrated database to version: 2026092312000019312026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (4ms)19322026/09/23 13:18:09 goose: successfully migrated database to version: 2026092312000019332026/09/23 13:18:09 OK 20260905000000_add_claims.sql (5.12ms)19342026-09-23 13:18:09.672 UTC [1109] ERROR: relation "goose_db_version" does not exist at character 3619352026-09-23 13:18:09.672 UTC [1109] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19362026/09/23 13:18:09 OK 1_commit_pending_closure.sql (3.49ms)19372026/09/23 13:18:09 INFO Completed upload id=219382026/09/23 13:18:09 OK 1_commit_pending_closure.sql (4.25ms)19392026/09/23 13:18:09 INFO Upload complete. (65ms)19402026/09/23 13:18:09 INFO Received uploads request method=POST path=/api/pending_closures1941--- PASS: TestReadProxyNarStreaming (0.73s)19422026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (3.82ms)1943=== CONT TestService_RequireScope_OIDC19442026/09/23 13:18:09 OK 2_object_stats_trigger.sql (2.45ms)19452026/09/23 13:18:09 OK 2_object_stats_trigger.sql (2.57ms)19462026/09/23 13:18:09 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)19472026/09/23 13:18:09 INFO Uploading c8f9qvvnc9iax61jlnym7xa506dp4v0w-top (224B)19482026/09/23 13:18:09 INFO Uploading wv7f54204hqb7gg6c1h5ly7gh1dlahwp-shared-dep (136B)19492026/09/23 13:18:09 OK 3_commit_push.sql (6.37ms)19502026/09/23 13:18:09 goose: up to current file version: 319512026/09/23 13:18:09 WARN Failed to register uploaded object key=nar/16s532s9i8gx4b09vbnqd6s00nrg37iznjhaxkzhcdfdqbh2h92i.nar.zst error="server returned 404: 404 page not found\n"19522026/09/23 13:18:09 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19532026/09/23 13:18:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19542026/09/23 13:18:09 WARN Failed to register uploaded object key=wv7f54204hqb7gg6c1h5ly7gh1dlahwp.ls error="server returned 404: 404 page not found\n"19552026/09/23 13:18:09 WARN Failed to register uploaded object key=c8f9qvvnc9iax61jlnym7xa506dp4v0w.ls error="server returned 404: 404 page not found\n"19562026/09/23 13:18:09 INFO Signed narinfos id=1 count=119572026/09/23 13:18:09 OK 3_commit_push.sql (8.06ms)19582026/09/23 13:18:09 goose: up to current file version: 319592026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (8.25ms)19602026/09/23 13:18:09 goose: successfully migrated database to version: 2026092312000019612026/09/23 13:18:09 OK 20241026095416_initial_model.sql (16.13ms)19622026/09/23 13:18:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign19632026/09/23 13:18:09 INFO Signed narinfos id=3 count=119642026/09/23 13:18:09 INFO Uploading 2 narinfos19652026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (2.45ms)19662026/09/23 13:18:09 OK 1_commit_pending_closure.sql (3.31ms)19672026/09/23 13:18:09 OK 2_object_stats_trigger.sql (2.2ms)19682026/09/23 13:18:09 WARN Failed to register uploaded object key=c8f9qvvnc9iax61jlnym7xa506dp4v0w.narinfo error="server returned 404: 404 page not found\n"19692026/09/23 13:18:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19702026/09/23 13:18:09 WARN Failed to register uploaded object key=wv7f54204hqb7gg6c1h5ly7gh1dlahwp.narinfo error="server returned 404: 404 page not found\n"19712026/09/23 13:18:09 OK 20251218171726_add_pins.sql (4.26ms)19722026/09/23 13:18:09 OK 3_commit_push.sql (2.53ms)19732026/09/23 13:18:09 goose: up to current file version: 319742026/09/23 13:18:09 INFO Completed upload id=119752026/09/23 13:18:09 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete19762026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (4.85ms)19772026/09/23 13:18:09 INFO Completed upload id=319782026/09/23 13:18:09 OK 20241026095416_initial_model.sql (12.9ms)19792026/09/23 13:18:09 INFO Upload complete. (179ms)1980=== NAME TestClientSharedPathCommittedMidPush1981 client_integration_test.go:680: Retrieved narinfo from S3:19822026/09/23 13:18:09 OK 20260905000000_add_claims.sql (3.36ms)1983 StorePath: /build/TestClientSharedPathCommittedMidPush2363436076/001/store/wv7f54204hqb7gg6c1h5ly7gh1dlahwp-shared-dep1984 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1985 Compression: zstd1986 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821987 NarSize: 1361988 References: 1989 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n19902026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (2.25ms)19912026/09/23 13:18:09 INFO Received uploads request method=POST path=/api/pending_closures19922026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (2.07ms)19932026/09/23 13:18:09 OK 20251218171726_add_pins.sql (4ms)19942026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (2.29ms)19952026/09/23 13:18:09 goose: successfully migrated database to version: 202609231200001996 client_integration_test.go:680: Retrieved narinfo from S3:1997 StorePath: /build/TestClientSharedPathCommittedMidPush2363436076/001/store/c8f9qvvnc9iax61jlnym7xa506dp4v0w-top1998 URL: nar/16s532s9i8gx4b09vbnqd6s00nrg37iznjhaxkzhcdfdqbh2h92i.nar.zst1999 Compression: zstd2000 NarHash: sha256:16s532s9i8gx4b09vbnqd6s00nrg37iznjhaxkzhcdfdqbh2h92i2001 NarSize: 2242002 References: /build/TestClientSharedPathCommittedMidPush2363436076/001/store/wv7f54204hqb7gg6c1h5ly7gh1dlahwp-shared-dep2003 CA: text:sha256:0sic14abqkr4dcli0s2nd9hjyigsv0ngb2l13mcwbqc3mih73zgj20042026/09/23 13:18:09 OK 1_commit_pending_closure.sql (2.36ms)20052026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (3.47ms)20062026/09/23 13:18:09 OK 2_object_stats_trigger.sql (1.77ms)2007--- PASS: TestClientSharedPathCommittedMidPush (1.09s)2008=== CONT TestService_AuthMiddleware_MTLSBoundSubjects20092026/09/23 13:18:09 OK 3_commit_push.sql (1.45ms)20102026/09/23 13:18:09 goose: up to current file version: 320112026/09/23 13:18:09 OK 20260905000000_add_claims.sql (3.35ms)20122026-09-23 13:18:09.711 UTC [1110] ERROR: relation "goose_db_version" does not exist at character 3620132026-09-23 13:18:09.711 UTC [1110] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20142026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (2.34ms)20152026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (2.03ms)20162026/09/23 13:18:09 goose: successfully migrated database to version: 2026092312000020172026/09/23 13:18:09 OK 1_commit_pending_closure.sql (1.88ms)20182026/09/23 13:18:09 OK 2_object_stats_trigger.sql (901.07µs)20192026/09/23 13:18:09 OK 3_commit_push.sql (860.09µs)20202026/09/23 13:18:09 goose: up to current file version: 320212026/09/23 13:18:09 OK 20241026095416_initial_model.sql (10.93ms)20222026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (2.54ms)20232026/09/23 13:18:09 OK 20251218171726_add_pins.sql (4.23ms)20242026/09/23 13:18:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20252026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (4.47ms)2026--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.77s)2027=== CONT TestCacheStatsHandler20282026/09/23 13:18:09 OK 20260905000000_add_claims.sql (4.09ms)20292026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (3.2ms)20302026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (2.61ms)20312026/09/23 13:18:09 goose: successfully migrated database to version: 2026092312000020322026/09/23 13:18:09 OK 1_commit_pending_closure.sql (2.86ms)20332026/09/23 13:18:09 OK 2_object_stats_trigger.sql (2.11ms)20342026/09/23 13:18:09 OK 3_commit_push.sql (1.67ms)20352026/09/23 13:18:09 goose: up to current file version: 320362026/09/23 13:18:09 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NWZlNmE3NTYtNmU1Mi00NGQ3LWEwNmItYzRmZmRhZDM5Y2ZmLjIzZjVhZWVlLTRiYjktNDZlNi05OTkxLThhNThkNDZmNDc0OXgxNzkwMTY5NDg5MDYyOTY0NzU5 parts=1220372026/09/23 13:18:09 INFO Received uploads request method=POST path=/api/pending_closures2038--- PASS: TestReadProxyNarinfo (0.76s)2039=== CONT TestService_AuthMiddleware_MTLSProxyHeader2040--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.66s)2041=== CONT TestService_AuthMiddleware_OIDC20422026-09-23 13:18:09.778 UTC [1116] ERROR: relation "goose_db_version" does not exist at character 3620432026-09-23 13:18:09.778 UTC [1116] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20442026/09/23 13:18:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37217/oidc20452026/09/23 13:18:09 INFO Starting HTTP server address=127.0.0.1:3385520462026/09/23 13:18:09 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket1325749097/001/proxy.sock20472026/09/23 13:18:09 WARN mTLS auth: subject not in bound subjects subject="CN=someone"20482026/09/23 13:18:09 INFO Shutdown signal received, draining in-flight requests timeout=10s2049--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.78s)2050=== CONT TestResolveDBConnectionString/flag_wins2051=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2052=== CONT TestResolveDBConnectionString/nothing_configured2053=== CONT TestResolveDBConnectionString/missing_file_is_an_error2054=== CONT TestResolveDBConnectionString/file_when_flag_empty2055=== CONT TestPush_RejectsBadRequests/no_roots20562026/09/23 13:18:09 INFO Received push request method=POST path=/api/pushes2057=== CONT TestPush_RejectsBadRequests/bad_root20582026/09/23 13:18:09 INFO Received push request method=POST path=/api/pushes2059=== CONT TestPush_RejectsBadRequests/root_not_in_objects2060--- PASS: TestResolveDBConnectionString (0.00s)2061 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2062 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2063 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2064 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2065 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)20662026/09/23 13:18:09 INFO Received push request method=POST path=/api/pushes2067=== CONT TestPush_RejectsBadRequests/no_objects20682026/09/23 13:18:09 INFO Received push request method=POST path=/api/pushes2069=== CONT TestIsValidCachePath/narinfo2070=== CONT TestIsValidCachePath/index.html2071--- PASS: TestPush_RejectsBadRequests (0.72s)2072 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2073 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2074 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2075 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2076=== CONT TestIsValidCachePath/short_hash2077=== CONT TestIsValidCachePath/wrong_extension2078=== CONT TestIsValidCachePath/leading_slash2079=== CONT TestIsValidCachePath/empty2080=== CONT TestIsValidCachePath/random_path2081=== CONT TestIsValidCachePath/invalid_char_u2082=== CONT TestIsValidCachePath/invalid_char_e2083=== CONT TestIsValidCachePath/traversal_in_middle2084=== CONT TestIsValidCachePath/traversal_parent2085=== CONT TestIsValidCachePath/nar_uncompressed2086=== CONT TestIsValidCachePath/nar_xz2087=== CONT TestIsValidCachePath/nix-cache-info2088=== CONT TestIsValidCachePath/nar_bz22089=== CONT TestIsValidCachePath/realisation2090=== CONT TestIsValidCachePath/log2091=== CONT TestIsValidCachePath/ls2092=== CONT TestIsValidCachePath/nar_zst2093=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2094--- PASS: TestIsValidCachePath (0.00s)2095 --- PASS: TestIsValidCachePath/narinfo (0.00s)2096 --- PASS: TestIsValidCachePath/index.html (0.00s)2097 --- PASS: TestIsValidCachePath/short_hash (0.00s)2098 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2099 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2100 --- PASS: TestIsValidCachePath/empty (0.00s)2101 --- PASS: TestIsValidCachePath/random_path (0.00s)2102 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2103 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2104 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2105 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2106 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2107 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2108 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2109 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2110 --- PASS: TestIsValidCachePath/realisation (0.00s)2111 --- PASS: TestIsValidCachePath/log (0.00s)2112 --- PASS: TestIsValidCachePath/ls (0.00s)2113 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2114 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2115=== CONT TestParseSingleRange/none2116=== CONT TestParseSingleRange/open-ended2117=== CONT TestParseSingleRange/start_far_past_EOF2118=== CONT TestParseSingleRange/suffix2119=== CONT TestParseSingleRange/end_clamped_to_size2120=== CONT TestParseSingleRange/suffix_exceeds_size2121=== CONT TestParseSingleRange/start_past_EOF2122=== CONT TestParseSingleRange/malformed_both_empty2123=== CONT TestParseSingleRange/single_byte2124=== CONT TestParseSingleRange/closed2125=== CONT TestParseSingleRange/malformed_end_before_start2126=== CONT TestParseSingleRange/unknown_unit2127=== CONT TestParseSingleRange/malformed_no_dash2128=== CONT TestParseSingleRange/multi-range_ignored2129--- PASS: TestParseSingleRange (0.00s)2130 --- PASS: TestParseSingleRange/none (0.00s)2131 --- PASS: TestParseSingleRange/open-ended (0.00s)2132 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2133 --- PASS: TestParseSingleRange/suffix (0.00s)2134 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2135 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2136 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2137 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2138 --- PASS: TestParseSingleRange/single_byte (0.00s)2139 --- PASS: TestParseSingleRange/closed (0.00s)2140 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2141 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2142 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2143 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2144=== CONT TestIsValidUploadKey/narinfo2145=== CONT TestIsValidUploadKey/unknown_type2146=== CONT TestIsValidUploadKey/empty_key2147=== CONT TestIsValidUploadKey/absolute2148=== CONT TestIsValidUploadKey/traversal_nar2149=== CONT TestIsValidUploadKey/traversal2150=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2151=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2152=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2153=== CONT TestIsValidUploadKey/index.html2154=== CONT TestIsValidUploadKey/nix-cache-info2155=== CONT TestIsValidUploadKey/build_log2156=== CONT TestIsValidUploadKey/listing2157=== CONT TestIsValidUploadKey/nar_plain2158=== CONT TestIsValidUploadKey/nar_xz2159=== CONT TestIsValidUploadKey/nar_zst2160=== CONT TestIsValidUploadKey/build_log_home-manager_file2161=== CONT TestIsValidUploadKey/build_log_equals2162=== CONT TestIsValidUploadKey/realisation_plus_in_output2163=== CONT TestIsValidUploadKey/build_log_question_mark2164=== CONT TestIsValidUploadKey/realisation2165=== CONT TestIsValidUploadKey/build_log_plus_in_name2166=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info2167--- PASS: TestIsValidUploadKey (0.00s)2168 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2169 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2170 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2171 --- PASS: TestIsValidUploadKey/absolute (0.00s)2172 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2173 --- PASS: TestIsValidUploadKey/traversal (0.00s)2174 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2175 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2176 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2177 --- PASS: TestIsValidUploadKey/index.html (0.00s)2178 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2179 --- PASS: TestIsValidUploadKey/build_log (0.00s)2180 --- PASS: TestIsValidUploadKey/listing (0.00s)2181 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2182 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2183 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2184 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2185 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2186 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2187 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2188 --- PASS: TestIsValidUploadKey/realisation (0.00s)2189 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)21902026/09/23 13:18:09 INFO Received uploads request method=POST path=/2191=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key21922026/09/23 13:18:09 INFO Received complete multipart upload request method=POST path=/2193=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal21942026/09/23 13:18:09 INFO Received uploads request method=POST path=/2195=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key21962026/09/23 13:18:09 INFO Received request for more parts method=POST path=/2197--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2198 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2199 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2200 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2201 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2202=== CONT TestServerTLSConfig/no_client_CA2203=== CONT TestServerTLSConfig/not_a_PEM_file2204=== CONT TestServerTLSConfig/missing_CA_file2205=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure22062026/09/23 13:18:09 INFO Received uploads request method=POST path=/2207--- PASS: TestServerTLSConfig (0.00s)2208 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2209 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2210 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)22112026/09/23 13:18:09 OK 20241026095416_initial_model.sql (13.36ms)22122026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (2.81ms)22132026/09/23 13:18:09 OK 20251218171726_add_pins.sql (4.47ms)22142026-09-23 13:18:09.812 UTC [1120] ERROR: relation "goose_db_version" does not exist at character 3622152026-09-23 13:18:09.812 UTC [1120] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22162026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (4.93ms)22172026/09/23 13:18:09 OK 20260905000000_add_claims.sql (4.17ms)22182026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (3.54ms)22192026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (3.99ms)22202026/09/23 13:18:09 goose: successfully migrated database to version: 2026092312000022212026/09/23 13:18:09 OK 20241026095416_initial_model.sql (11.24ms)22222026/09/23 13:18:09 OK 1_commit_pending_closure.sql (2.84ms)22232026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (2.01ms)22242026/09/23 13:18:09 OK 2_object_stats_trigger.sql (1.72ms)22252026/09/23 13:18:09 OK 3_commit_push.sql (2.17ms)22262026/09/23 13:18:09 goose: up to current file version: 322272026/09/23 13:18:09 OK 20251218171726_add_pins.sql (3.98ms)22282026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (4.44ms)22292026/09/23 13:18:09 OK 20260905000000_add_claims.sql (4.48ms)22302026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (3.02ms)22312026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (1.9ms)22322026/09/23 13:18:09 goose: successfully migrated database to version: 2026092312000022332026/09/23 13:18:09 OK 1_commit_pending_closure.sql (1.95ms)22342026/09/23 13:18:09 OK 2_object_stats_trigger.sql (899.21µs)22352026/09/23 13:18:09 OK 3_commit_push.sql (876.95µs)22362026/09/23 13:18:09 goose: up to current file version: 322372026-09-23 13:18:09.855 UTC [1121] ERROR: relation "goose_db_version" does not exist at character 3622382026-09-23 13:18:09.855 UTC [1121] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22392026-09-23 13:18:09.861 UTC [1122] ERROR: relation "goose_db_version" does not exist at character 3622402026-09-23 13:18:09.861 UTC [1122] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22412026/09/23 13:18:09 OK 20241026095416_initial_model.sql (9.85ms)22422026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (1.37ms)2243--- PASS: TestResurrectedObjectNotDeleted (0.77s)2244=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart22452026/09/23 13:18:09 INFO Received complete multipart upload request method=POST path=/22462026/09/23 13:18:09 OK 20251218171726_add_pins.sql (3.95ms)22472026/09/23 13:18:09 OK 20241026095416_initial_model.sql (10.51ms)22482026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (1.4ms)22492026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (3.15ms)22502026/09/23 13:18:09 OK 20251218171726_add_pins.sql (3.11ms)22512026/09/23 13:18:09 OK 20260905000000_add_claims.sql (3.36ms)22522026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (3.21ms)22532026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (3.46ms)22542026/09/23 13:18:09 INFO Received uploads request method=POST path=/api/pending_closures22552026/09/23 13:18:09 INFO Received uploads request method=POST path=/api/pending_closures22562026/09/23 13:18:09 INFO Received uploads request method=POST path=/api/pending_closures22572026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (2.28ms)22582026/09/23 13:18:09 goose: successfully migrated database to version: 2026092312000022592026/09/23 13:18:09 OK 20260905000000_add_claims.sql (3ms)22602026/09/23 13:18:09 OK 1_commit_pending_closure.sql (1.99ms)22612026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (2.05ms)22622026/09/23 13:18:09 OK 2_object_stats_trigger.sql (887.61µs)22632026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (1.55ms)22642026/09/23 13:18:09 goose: successfully migrated database to version: 2026092312000022652026/09/23 13:18:09 OK 3_commit_push.sql (886.47µs)22662026/09/23 13:18:09 goose: up to current file version: 322672026/09/23 13:18:09 OK 1_commit_pending_closure.sql (1.95ms)22682026/09/23 13:18:09 OK 2_object_stats_trigger.sql (1.2ms)22692026/09/23 13:18:09 OK 3_commit_push.sql (1.21ms)22702026/09/23 13:18:09 goose: up to current file version: 322712026/09/23 13:18:09 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux22722026/09/23 13:18:09 WARN Refused reserved pin name=worker-x86_64-linux22732026/09/23 13:18:09 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux22742026/09/23 13:18:09 INFO Received create pin request method=POST path=/api/pins/my-app22752026/09/23 13:18:09 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux2276--- PASS: TestCreatePin_ReservedPins (0.84s)2277=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts22782026/09/23 13:18:09 INFO Received request for more parts method=POST path=/2279=== CONT TestCacheConfigHandler/full_config,_no_issuer2280=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2281=== CONT TestCacheConfigHandler/no_signing_keys2282=== CONT TestCacheConfigHandler/no_cache_url_configured2283--- PASS: TestCacheConfigHandler (0.00s)2284 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2285 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2286 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2287 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2288=== CONT TestProxyWriteTimeout/narinfo2289=== CONT TestProxyWriteTimeout/10_GiB_nar2290=== CONT TestProxyWriteTimeout/1_GiB_nar2291=== CONT TestProxyWriteTimeout/unknown_size2292--- PASS: TestProxyWriteTimeout (0.00s)2293 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2294 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2295 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2296 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2297=== CONT TestClientErrorHandling/InvalidStorePath22982026/09/23 13:18:10 INFO Received uploads request method=POST path=/api/pending_closures2299--- PASS: TestObjectStatsTrigger (0.70s)2300=== CONT TestClientErrorHandling/ServerNotAvailable23012026-09-23 13:18:10.025 UTC [1126] ERROR: relation "goose_db_version" does not exist at character 3623022026-09-23 13:18:10.025 UTC [1126] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23032026/09/23 13:18:10 WARN mTLS auth: subject not in bound subjects subject="CN=reader"23042026/09/23 13:18:10 WARN mTLS auth: subject not in bound subjects subject="CN=reader"2305--- PASS: TestService_NativeMTLS (0.56s)2306=== CONT TestClientErrorHandling/InvalidAuthToken23072026/09/23 13:18:10 OK 20241026095416_initial_model.sql (10.41ms)23082026/09/23 13:18:10 OK 20251210153512_drop_unused_gin_index.sql (1.45ms)23092026/09/23 13:18:10 OK 20251218171726_add_pins.sql (3.7ms)23102026/09/23 13:18:10 OK 20260628120000_add_object_size_and_stats.sql (3.99ms)23112026/09/23 13:18:10 OK 20260905000000_add_claims.sql (3.79ms)23122026/09/23 13:18:10 OK 20260920000000_drop_claims.sql (3.42ms)23132026/09/23 13:18:10 OK 20260923120000_add_pushes.sql (3.28ms)23142026/09/23 13:18:10 goose: successfully migrated database to version: 2026092312000023152026/09/23 13:18:10 OK 1_commit_pending_closure.sql (3.29ms)23162026/09/23 13:18:10 OK 2_object_stats_trigger.sql (2.11ms)23172026/09/23 13:18:10 OK 3_commit_push.sql (2.4ms)23182026/09/23 13:18:10 goose: up to current file version: 323192026/09/23 13:18:10 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/present2320--- PASS: TestMetricsInventory (0.62s)23212026/09/23 13:18:10 INFO Received uploads request method=POST path=/api/pending_closures23222026-09-23 13:18:10.110 UTC [1163] ERROR: relation "goose_db_version" does not exist at character 3623232026-09-23 13:18:10.110 UTC [1163] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23242026/09/23 13:18:10 OK 20241026095416_initial_model.sql (10.28ms)23252026/09/23 13:18:10 OK 20251210153512_drop_unused_gin_index.sql (1.61ms)23262026/09/23 13:18:10 INFO Received cleanup request method=DELETE path=/api/pending_closures23272026/09/23 13:18:10 OK 20251218171726_add_pins.sql (3.85ms)23282026/09/23 13:18:10 INFO Aborted multipart uploads count=123292026/09/23 13:18:10 OK 20260628120000_add_object_size_and_stats.sql (4.01ms)23302026/09/23 13:18:10 OK 20260905000000_add_claims.sql (3.11ms)2331--- PASS: TestMultipartCleanup (0.73s)23322026/09/23 13:18:10 OK 20260920000000_drop_claims.sql (2.05ms)23332026/09/23 13:18:10 OK 20260923120000_add_pushes.sql (1.81ms)23342026/09/23 13:18:10 goose: successfully migrated database to version: 2026092312000023352026/09/23 13:18:10 OK 1_commit_pending_closure.sql (2.32ms)23362026/09/23 13:18:10 OK 2_object_stats_trigger.sql (1.15ms)23372026/09/23 13:18:10 OK 3_commit_push.sql (1.09ms)23382026/09/23 13:18:10 goose: up to current file version: 32339--- PASS: TestService_ReadAuthMiddleware (0.64s)23402026/09/23 13:18:10 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=183.120976ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2341=== NAME TestClientMultipleUploads2342 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads1398066164/001/store/lqszf99m3b7hnqx3ha5kgwx65dzjjrv8-test-file-0.txt23432026/09/23 13:18:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2344=== NAME TestClientWithDependencies2345 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies390960360/001/store/14jc5zidvfjqkfd0dxngh4kc7z45cm4r-test-script23462026/09/23 13:18:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2347=== NAME TestClientMultipleUploads2348 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads1398066164/001/store/x57cwfxxhi8g8h04pm97a9jbbmnk0z4h-test-file-1.txt2349--- PASS: TestService_ReadScope_PublicByDefault (0.65s)23502026/09/23 13:18:10 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NWZlNmE3NTYtNmU1Mi00NGQ3LWEwNmItYzRmZmRhZDM5Y2ZmLjYwMGVmYmVmLTZkNzYtNGE1Ny1hYzQ4LTQxYmYzYzA4MjU2MXgxNzkwMTY5NDg5NzEyODE0MzY2 parts=1023512026/09/23 13:18:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete23522026/09/23 13:18:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43459/oidc23532026/09/23 13:18:10 INFO Completed upload id=123542026/09/23 13:18:10 INFO Received uploads request method=POST path=/api/pending_closures23552026/09/23 13:18:10 INFO Received uploads request method=POST path=/api/pending_closures2356=== NAME TestClientWithDependencies2357 client_integration_test.go:615: Found 1 dependencies (including self)23582026/09/23 13:18:10 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo23592026/09/23 13:18:10 WARN Found objects in DB but missing from S3, will re-upload count=12360--- PASS: TestService_verifyS3Integrity (1.31s)2361=== NAME TestClientIntegration2362 client_integration_test.go:286: Created store path: /build/TestClientIntegration1517546928/002/store/pli35qczs6c1jg1cb4rggxmmk3l59mf1-test-file.txt2363=== NAME TestClientMultipleUploads2364 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads1398066164/001/store/wfr59bx1zm53hys0qyb5x2j006vlw4kg-test-file-2.txt23652026/09/23 13:18:10 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"23662026/09/23 13:18:10 WARN mTLS auth: bound subjects configured but subject DN unavailable23672026/09/23 13:18:10 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2368--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.59s)2369=== NAME TestOrphanedObjectsGC2370 orphaned_objects_gc_test.go:290: GC Test Summary:2371 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2372 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2373 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2374 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2375 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2376--- PASS: TestOrphanedObjectsGC (1.06s)23772026-09-23 13:18:10.314 UTC [1362] ERROR: relation "goose_db_version" does not exist at character 3623782026-09-23 13:18:10.314 UTC [1362] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23792026/09/23 13:18:10 INFO Received uploads request method=POST path=/api/pending_closures23802026/09/23 13:18:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23812026/09/23 13:18:10 INFO Uploading pli35qczs6c1jg1cb4rggxmmk3l59mf1-test-file.txt (152B)23822026/09/23 13:18:10 OK 20241026095416_initial_model.sql (14.05ms)23832026/09/23 13:18:10 WARN Failed to register uploaded object key=pli35qczs6c1jg1cb4rggxmmk3l59mf1.ls error="server returned 404: 404 page not found\n"23842026/09/23 13:18:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign23852026/09/23 13:18:10 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"23862026/09/23 13:18:10 INFO Signed narinfos id=1 count=12387--- PASS: TestCacheStatsHandler (0.60s)23882026/09/23 13:18:10 INFO Uploading 1 narinfos23892026/09/23 13:18:10 OK 20251210153512_drop_unused_gin_index.sql (1.87ms)23902026/09/23 13:18:10 INFO Received uploads request method=POST path=/api/pending_closures23912026/09/23 13:18:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete23922026/09/23 13:18:10 WARN Failed to register uploaded object key=pli35qczs6c1jg1cb4rggxmmk3l59mf1.narinfo error="server returned 404: 404 page not found\n"23932026/09/23 13:18:10 OK 20251218171726_add_pins.sql (4.06ms)23942026/09/23 13:18:10 OK 20260628120000_add_object_size_and_stats.sql (4.22ms)23952026/09/23 13:18:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23962026/09/23 13:18:10 INFO Uploading 14jc5zidvfjqkfd0dxngh4kc7z45cm4r-test-script (136B)23972026/09/23 13:18:10 INFO Completed upload id=123982026/09/23 13:18:10 INFO Upload complete. (60ms)23992026/09/23 13:18:10 INFO Received uploads request method=POST path=/api/pending_closures24002026/09/23 13:18:10 OK 20260905000000_add_claims.sql (3.89ms)24012026/09/23 13:18:10 OK 20260920000000_drop_claims.sql (3.42ms)24022026/09/23 13:18:10 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"24032026/09/23 13:18:10 WARN Failed to register uploaded object key=log/yigvd45xbxz281x4s6zr90nsk9ly9hx8-test-script.drv error="server returned 404: 404 page not found\n"24042026/09/23 13:18:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign24052026/09/23 13:18:10 WARN Failed to register uploaded object key=14jc5zidvfjqkfd0dxngh4kc7z45cm4r.ls error="server returned 404: 404 page not found\n"24062026/09/23 13:18:10 INFO Received uploads request method=POST path=/api/pending_closures24072026/09/23 13:18:10 INFO Signed narinfos id=1 count=124082026/09/23 13:18:10 OK 20260923120000_add_pushes.sql (2.47ms)24092026/09/23 13:18:10 goose: successfully migrated database to version: 2026092312000024102026/09/23 13:18:10 INFO Uploading 1 narinfos2411--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.59s)24122026/09/23 13:18:10 INFO Received uploads request method=POST path=/api/pending_closures24132026/09/23 13:18:10 OK 1_commit_pending_closure.sql (2.37ms)24142026/09/23 13:18:10 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)24152026/09/23 13:18:10 INFO Uploading x57cwfxxhi8g8h04pm97a9jbbmnk0z4h-test-file-1.txt (160B)24162026/09/23 13:18:10 INFO Uploading wfr59bx1zm53hys0qyb5x2j006vlw4kg-test-file-2.txt (160B)24172026/09/23 13:18:10 INFO Uploading lqszf99m3b7hnqx3ha5kgwx65dzjjrv8-test-file-0.txt (160B)24182026/09/23 13:18:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete24192026/09/23 13:18:10 WARN Failed to register uploaded object key=14jc5zidvfjqkfd0dxngh4kc7z45cm4r.narinfo error="server returned 404: 404 page not found\n"24202026/09/23 13:18:10 OK 2_object_stats_trigger.sql (1.62ms)24212026/09/23 13:18:10 WARN Failed to register uploaded object key=x57cwfxxhi8g8h04pm97a9jbbmnk0z4h.ls error="server returned 404: 404 page not found\n"24222026/09/23 13:18:10 WARN Failed to register uploaded object key=wfr59bx1zm53hys0qyb5x2j006vlw4kg.ls error="server returned 404: 404 page not found\n"24232026/09/23 13:18:10 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"24242026/09/23 13:18:10 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"24252026/09/23 13:18:10 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"24262026/09/23 13:18:10 OK 3_commit_push.sql (1.31ms)24272026/09/23 13:18:10 goose: up to current file version: 324282026/09/23 13:18:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign24292026/09/23 13:18:10 WARN Failed to register uploaded object key=lqszf99m3b7hnqx3ha5kgwx65dzjjrv8.ls error="server returned 404: 404 page not found\n"24302026/09/23 13:18:10 INFO Completed upload id=124312026/09/23 13:18:10 INFO Upload complete. (83ms)24322026/09/23 13:18:10 INFO Signed narinfos id=1 count=124332026/09/23 13:18:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign24342026/09/23 13:18:10 INFO Signed narinfos id=2 count=12435=== NAME TestClientCADerivations24362026/09/23 13:18:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign2437 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3565772350/001/store/lbyifjkrbykk5jcw6xbcga59mv8039mx-ca-test24382026/09/23 13:18:10 INFO Signed narinfos id=3 count=124392026/09/23 13:18:10 INFO Uploading 3 narinfos24402026/09/23 13:18:10 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=425.613695ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2441=== NAME TestClientWithDependencies2442 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies390960360/001/store) requires matching store prefix24432026/09/23 13:18:10 WARN Failed to register uploaded object key=wfr59bx1zm53hys0qyb5x2j006vlw4kg.narinfo error="server returned 404: 404 page not found\n"24442026/09/23 13:18:10 WARN Failed to register uploaded object key=lqszf99m3b7hnqx3ha5kgwx65dzjjrv8.narinfo error="server returned 404: 404 page not found\n"2445--- PASS: TestClientWithDependencies (0.86s)24462026/09/23 13:18:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete24472026/09/23 13:18:10 WARN Failed to register uploaded object key=x57cwfxxhi8g8h04pm97a9jbbmnk0z4h.narinfo error="server returned 404: 404 page not found\n"24482026/09/23 13:18:10 INFO All 1 paths already cached2449=== NAME TestClientIntegration2450 client_integration_test.go:312: Retrieved narinfo from S3:2451 StorePath: /build/TestClientIntegration1517546928/002/store/pli35qczs6c1jg1cb4rggxmmk3l59mf1-test-file.txt2452 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2453 Compression: zstd2454 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12455 NarSize: 1522456 References: 2457 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk124582026/09/23 13:18:10 INFO Completed upload id=124592026/09/23 13:18:10 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete24602026/09/23 13:18:10 INFO Completed upload id=224612026/09/23 13:18:10 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete2462 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2463 client_integration_test.go:313: Decompressed .ls content (64 bytes):2464 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2465 client_integration_test.go:316: Testing garbage collection...24662026/09/23 13:18:10 INFO Completed upload id=324672026/09/23 13:18:10 INFO Upload complete. (81ms)2468=== NAME TestClientMultipleUploads2469 client_integration_test.go:369: Uploaded 3 paths in 117.095443ms24702026/09/23 13:18:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2471--- PASS: TestClientMultipleUploads (0.87s)2472=== NAME TestClientCADerivations2473 client_ca_test.go:139: Found 1 dependencies (including self)24742026/09/23 13:18:10 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NWZlNmE3NTYtNmU1Mi00NGQ3LWEwNmItYzRmZmRhZDM5Y2ZmLmFhYTY2NzRkLTg3NWMtNDFmNi05NDA1LTgzZTYzNjYzYjAzY3gxNzkwMTY5NDg5ODk4NDUzNjM5 parts=1024752026/09/23 13:18:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete24762026/09/23 13:18:10 INFO Completed upload id=124772026/09/23 13:18:10 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000024782026/09/23 13:18:10 INFO Received uploads request method=POST path=/api/pending_closures24792026/09/23 13:18:10 INFO Starting cleanup of old closures method=DELETE path=/api/closures2480=== RUN TestService_RequireScope_OIDC/builder_may_write2481=== PAUSE TestService_RequireScope_OIDC/builder_may_write2482=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2483=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2484=== RUN TestService_RequireScope_OIDC/ops_may_admin2485=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2486=== RUN TestService_RequireScope_OIDC/ops_may_not_write2487=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2488=== RUN TestService_RequireScope_OIDC/reader_may_not_write2489=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2490=== RUN TestService_RequireScope_OIDC/static_token_may_admin2491=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2492=== RUN TestService_RequireScope_OIDC/static_token_may_write2493=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2494=== RUN TestService_RequireScope_OIDC/reader_may_read2495=== PAUSE TestService_RequireScope_OIDC/reader_may_read2496=== RUN TestService_RequireScope_OIDC/writer_implies_read2497=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2498=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2499=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2500=== CONT TestService_RequireScope_OIDC/builder_may_write2501=== CONT TestService_RequireScope_OIDC/static_token_may_write2502=== CONT TestService_RequireScope_OIDC/reader_may_read2503=== CONT TestService_RequireScope_OIDC/reader_may_not_write2504=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2505=== CONT TestService_RequireScope_OIDC/writer_implies_read2506=== CONT TestService_RequireScope_OIDC/ops_may_admin2507=== CONT TestService_RequireScope_OIDC/ops_may_not_write2508=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2509=== CONT TestService_RequireScope_OIDC/static_token_may_admin2510--- PASS: TestService_RequireScope_OIDC (0.75s)2511 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2512 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2513 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2514 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2515 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2516 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2517 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2518 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2519 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2520 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)25212026/09/23 13:18:10 INFO Aborted multipart uploads count=025222026/09/23 13:18:10 INFO Starting cleanup of old closures method=DELETE path=/api/closures25232026/09/23 13:18:10 INFO Garbage collection started25242026/09/23 13:18:10 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=025252026/09/23 13:18:10 INFO Aborted multipart uploads count=025262026/09/23 13:18:10 INFO Vacuumed table table=pending_closures25272026/09/23 13:18:10 INFO Vacuumed table table=pending_objects25282026/09/23 13:18:10 WARN Force mode enabled - objects will be deleted immediately without grace period25292026/09/23 13:18:10 INFO Vacuumed table table=multipart_uploads25302026/09/23 13:18:10 INFO Vacuumed table table=closures25312026/09/23 13:18:10 INFO Vacuumed table table=objects2532=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2533=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2534=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2535=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2536=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2537=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2538=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2539=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2540=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2541=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected2542=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured25432026/09/23 13:18:10 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]2544=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected25452026/09/23 13:18:10 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000002546--- PASS: TestService_createPendingClosureHandler (1.25s)25472026/09/23 13:18:10 WARN Authentication failed token_preview=eyJhbGciOi...aGY_ulKMJQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2548--- PASS: TestService_AuthMiddleware_OIDC (0.70s)2549 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2550 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2551 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2552 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)25532026/09/23 13:18:10 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"25542026/09/23 13:18:10 INFO Received uploads request method=POST path=/api/pending_closures25552026/09/23 13:18:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)25562026/09/23 13:18:10 INFO Uploading lbyifjkrbykk5jcw6xbcga59mv8039mx-ca-test (144B)25572026/09/23 13:18:10 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"25582026/09/23 13:18:10 WARN Failed to register uploaded object key=lbyifjkrbykk5jcw6xbcga59mv8039mx.ls error="server returned 404: 404 page not found\n"25592026/09/23 13:18:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign25602026/09/23 13:18:10 WARN Failed to register uploaded object key=log/5lf2ig6345vf0flwzyvkd0jxgk8rki0i-ca-test.drv error="server returned 404: 404 page not found\n"25612026/09/23 13:18:10 INFO Signed narinfos id=1 count=125622026/09/23 13:18:10 INFO Uploading 1 narinfos25632026/09/23 13:18:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete25642026/09/23 13:18:10 WARN Failed to register uploaded object key=lbyifjkrbykk5jcw6xbcga59mv8039mx.narinfo error="server returned 404: 404 page not found\n"25652026/09/23 13:18:10 INFO Completed upload id=125662026/09/23 13:18:10 INFO Upload complete. (97ms)25672026/09/23 13:18:10 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2568=== NAME TestClientCADerivations2569 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3565772350/001/store/lbyifjkrbykk5jcw6xbcga59mv8039mx-ca-test2570 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2571 Compression: zstd2572 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2573 NarSize: 1442574 References: 2575 Deriver: /build/TestClientCADerivations3565772350/001/store/5lf2ig6345vf0flwzyvkd0jxgk8rki0i-ca-test.drv2576 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2577 client_ca_test.go:185: Checking for realisation files in S3...2578 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2579 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache2580 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2581 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2582 error: binary cache 's3://bucket58?endpoint=http://localhost:36367®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3565772350/001/store'2583 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12584--- PASS: TestClientCADerivations (1.01s)25852026/09/23 13:18:10 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=739.171314ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present25862026/09/23 13:18:11 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=025872026/09/23 13:18:11 INFO Vacuumed table table=pending_closures25882026/09/23 13:18:11 INFO Vacuumed table table=pending_objects25892026/09/23 13:18:11 INFO Vacuumed table table=multipart_uploads25902026/09/23 13:18:11 INFO Vacuumed table table=closures25912026/09/23 13:18:11 INFO Vacuumed table table=objects2592--- PASS: TestUploadHandlersRejectOversizedBody (0.14s)2593 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.08s)2594 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.13s)2595 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.36s)2596=== NAME TestOrphanedObjectsGCStressTest2597 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2598 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion25992026/09/23 13:18:11 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.700454717s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present26002026/09/23 13:18:11 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02601=== NAME TestPinProtectsFromGC2602 client_integration_test.go:794: Pin successfully protected closure from garbage collection2603--- PASS: TestPinProtectsFromGC (3.11s)26042026/09/23 13:18:11 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=026052026/09/23 13:18:11 INFO Vacuumed table table=pending_closures26062026/09/23 13:18:11 INFO Vacuumed table table=pending_objects26072026/09/23 13:18:11 INFO Vacuumed table table=multipart_uploads26082026/09/23 13:18:11 INFO Vacuumed table table=closures26092026/09/23 13:18:11 INFO Vacuumed table table=objects2610=== NAME TestOrphanedObjectsGCStressTest2611 orphaned_objects_gc_test.go:509: Stress test completed successfully:2612 orphaned_objects_gc_test.go:510: - Active objects preserved: 202613 orphaned_objects_gc_test.go:511: - Objects deleted: 2102614 orphaned_objects_gc_test.go:512: - Total GC'd: 2102615--- PASS: TestOrphanedObjectsGCStressTest (2.67s)26162026/09/23 13:18:12 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02617=== NAME TestClientIntegration2618 client_integration_test.go:323: Objects in database after GC:2619 client_integration_test.go:323: Successfully deleted all objects with GC --force2620--- PASS: TestClientIntegration (2.86s)26212026/09/23 13:18:13 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26222026/09/23 13:18:13 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=194.004843ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26232026/09/23 13:18:13 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=369.626648ms 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:18:13 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=774.863953ms 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:18:14 WARN Rate limiter enabled after throttle name=s3-test rate=526262026/09/23 13:18:14 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.59s)26312026/09/23 13:18:14 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.527594766s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26322026/09/23 13:18:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"26332026/09/23 13:18:16 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26342026/09/23 13:18:16 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=212.021233ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26352026/09/23 13:18:16 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=382.787918ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26362026/09/23 13:18:16 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=794.740762ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26372026/09/23 13:18:17 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.64994969s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2638--- PASS: TestClientErrorHandling (0.00s)2639 --- PASS: TestClientErrorHandling/InvalidStorePath (0.49s)2640 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.51s)2641 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.39s)2642FAIL2643{"timestamp":"2026-09-23T13:18:19.40527364Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:45994","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(209)"}26442026-09-23 13:18:19.744 UTC [128] LOG: received smart shutdown request26452026-09-23 13:18:19.749 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 126462026-09-23 13:18:19.767 UTC [133] LOG: shutting down26472026-09-23 13:18:19.768 UTC [133] LOG: checkpoint starting: shutdown immediate26482026-09-23 13:18:20.964 UTC [133] LOG: checkpoint complete: wrote 11455 buffers (69.9%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 18 recycled; write=0.216 s, sync=0.944 s, total=1.197 s; sync files=21875, longest=0.002 s, average=0.001 s; distance=297527 kB, estimate=297527 kB; lsn=0/139F3938, redo lsn=0/139F393826492026-09-23 13:18:21.073 UTC [128] LOG: database system is shut down