niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #269
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestCaseHackSuffix8=== PAUSE TestCaseHackSuffix9=== RUN TestFilterOversizedClosures10=== PAUSE TestFilterOversizedClosures11=== RUN TestUploadMultipart_PartsInParallel12=== PAUSE TestUploadMultipart_PartsInParallel13=== RUN TestPartSizeForNAR14=== PAUSE TestPartSizeForNAR15=== RUN TestUploadMultipart_SupersededByPeer16=== PAUSE TestUploadMultipart_SupersededByPeer17=== RUN TestDumpPathCaseHackMatchesNix18--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)19=== RUN TestDumpPathCaseHackCollision20--- PASS: TestDumpPathCaseHackCollision (0.00s)21=== RUN TestDumpPathMatchesNix22=== PAUSE TestDumpPathMatchesNix23=== RUN TestDumpPathSingleFile24=== PAUSE TestDumpPathSingleFile25=== RUN TestDumpPathWriterError26=== PAUSE TestDumpPathWriterError27=== RUN TestEncodeNixBase3228=== PAUSE TestEncodeNixBase3229=== RUN TestEncodeNixBase32WithRealHash30=== PAUSE TestEncodeNixBase32WithRealHash31=== RUN TestConvertHashToNix3232=== PAUSE TestConvertHashToNix3233=== RUN TestGetStorePathHash34=== PAUSE TestGetStorePathHash35=== RUN TestPathInfoHashCompatibility36=== PAUSE TestPathInfoHashCompatibility37=== RUN TestParsePathInfoJSON38=== PAUSE TestParsePathInfoJSON39=== RUN TestParsePathInfoJSONMultiplePaths40=== PAUSE TestParsePathInfoJSONMultiplePaths41=== RUN TestPathInfoCACompatibility42=== PAUSE TestPathInfoCACompatibility43=== RUN TestRateLimiterFeedback44=== PAUSE TestRateLimiterFeedback45=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess47=== RUN TestResolveStorePath48=== PAUSE TestResolveStorePath49=== RUN TestDoWithRetry_BodyReplayedViaGetBody50=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody51=== RUN TestShellSplit52=== PAUSE TestShellSplit53=== RUN TestShellSplitErrors54=== PAUSE TestShellSplitErrors55=== RUN TestStreamPushReportsEveryPath56=== PAUSE TestStreamPushReportsEveryPath57=== RUN TestStreamPushBatchesUnderLoad58=== PAUSE TestStreamPushBatchesUnderLoad59=== RUN TestStreamPushIsolatesFailures60=== PAUSE TestStreamPushIsolatesFailures61=== RUN TestStreamPushGivesUpOnDeadServer62=== PAUSE TestStreamPushGivesUpOnDeadServer63=== RUN TestStreamPushRequestLine64=== PAUSE TestStreamPushRequestLine65=== RUN TestStreamPushReportsSignatures66=== PAUSE TestStreamPushReportsSignatures67=== RUN TestClientSignaturesByStorePath68=== PAUSE TestClientSignaturesByStorePath69=== RUN TestSetClientTLS70=== PAUSE TestSetClientTLS71=== RUN TestSetClientTLSDoesNotMutateDefaultTransport72=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport73=== RUN TestSetClientTLSErrors74=== PAUSE TestSetClientTLSErrors75=== RUN TestStaticToken76=== PAUSE TestStaticToken77=== RUN TestFileTokenReadsAndCaches78=== PAUSE TestFileTokenReadsAndCaches79=== RUN TestFileTokenMissing80=== PAUSE TestFileTokenMissing81=== RUN TestFileTokenEmpty82=== PAUSE TestFileTokenEmpty83=== RUN TestScriptTokenNoExpiryRerunsEveryCall84=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall85=== RUN TestScriptTokenCachesUntilRefresh86=== PAUSE TestScriptTokenCachesUntilRefresh87=== RUN TestScriptTokenEmptyToken88=== PAUSE TestScriptTokenEmptyToken89=== RUN TestScriptTokenBadJSON90=== PAUSE TestScriptTokenBadJSON91=== RUN TestScriptTokenScriptFails92=== PAUSE TestScriptTokenScriptFails93=== RUN TestScriptTokenEmptyCommand94=== PAUSE TestScriptTokenEmptyCommand95=== CONT TestDoServerRequestAttachesToken96=== CONT TestShellSplit97--- PASS: TestShellSplit (0.00s)98=== CONT TestGetStorePathHash99=== CONT TestUploadMultipart_SupersededByPeer100=== CONT TestEncodeNixBase32101=== CONT TestDumpPathWriterError102=== RUN TestUploadMultipart_SupersededByPeer/exists103=== PAUSE TestUploadMultipart_SupersededByPeer/exists104=== RUN TestUploadMultipart_SupersededByPeer/missing105=== RUN TestEncodeNixBase32/test_string_hash106=== CONT TestDumpPathSingleFile107=== PAUSE TestUploadMultipart_SupersededByPeer/missing108=== CONT TestEncodeNixBase32WithRealHash109=== CONT TestDumpPathMatchesNix110=== CONT TestDoWithRetry_BodyReplayedViaGetBody111=== CONT TestSetClientTLSErrors112=== CONT TestResolveStorePath113=== CONT TestScriptTokenNoExpiryRerunsEveryCall114=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess115=== CONT TestScriptTokenEmptyToken116=== CONT TestFileTokenEmpty1172026/09/23 13:29:38 WARN Rate limiter enabled after throttle name=server-test rate=51182026/09/23 13:29:38 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:423771192026/09/23 13:29:38 WARN Rate limiter enabled after throttle name=server-test rate=5120=== CONT TestRateLimiterFeedback121=== RUN TestRateLimiterFeedback/429_enables_limiter122=== CONT TestPathInfoCACompatibility123=== CONT TestFileTokenMissing124=== CONT TestParsePathInfoJSONMultiplePaths125=== CONT TestFileTokenReadsAndCaches126=== CONT TestScriptTokenCachesUntilRefresh127=== CONT TestParsePathInfoJSON128=== CONT TestPathInfoHashCompatibility129=== CONT TestScriptTokenEmptyCommand130=== CONT TestStaticToken131=== RUN TestGetStorePathHash/valid_store_path132=== PAUSE TestEncodeNixBase32/test_string_hash133=== CONT TestScriptTokenScriptFails134--- PASS: TestEncodeNixBase32WithRealHash (0.00s)135=== CONT TestConvertHashToNix32136=== PAUSE TestRateLimiterFeedback/429_enables_limiter137=== RUN TestPathInfoCACompatibility/null_ca_field138--- PASS: TestDoServerRequestAttachesToken (0.00s)139--- PASS: TestFileTokenMissing (0.00s)140--- PASS: TestFileTokenEmpty (0.00s)141--- PASS: TestFileTokenReadsAndCaches (0.00s)142=== RUN TestParsePathInfoJSON/Nix_format143=== PAUSE TestParsePathInfoJSON/Nix_format144=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths145=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths146=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths147=== RUN TestParsePathInfoJSON/Lix_format148=== PAUSE TestParsePathInfoJSON/Lix_format149=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)150--- PASS: TestScriptTokenEmptyCommand (0.00s)1512026/09/23 13:29:38 WARN Rate limiter backed off name=server-test rate=5152=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths1532026/09/23 13:29:38 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:42377154=== CONT TestSetClientTLSDoesNotMutateDefaultTransport155=== PAUSE TestGetStorePathHash/valid_store_path156=== RUN TestParsePathInfoJSON/empty_input157=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)158=== CONT TestUploadMultipart_PartsInParallel159=== CONT TestPartSizeForNAR160=== RUN TestPartSizeForNAR/zero_stays_at_minimum161--- PASS: TestStaticToken (0.00s)162=== RUN TestEncodeNixBase32/empty_input163=== RUN TestConvertHashToNix32/SRI_format_to_Nix32164=== RUN TestRateLimiterFeedback/503_enables_limiter165=== RUN TestSetClientTLSErrors/missing_cert_file166=== PAUSE TestPathInfoCACompatibility/null_ca_field167=== CONT TestScriptTokenBadJSON168=== CONT TestFilterOversizedClosures169=== CONT TestStreamPushRequestLine170=== CONT TestStreamPushReportsSignatures171=== CONT TestClientSignaturesByStorePath172=== CONT TestCaseHackSuffix173=== CONT TestRegisterUploadedObjectReusesConnections174=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon175=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon176=== RUN TestGetStorePathHash/basename_without_hyphen_should_error177=== PAUSE TestParsePathInfoJSON/empty_input178=== CONT TestSetClientTLS179=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum180--- PASS: TestResolveStorePath (0.01s)1812026/09/23 13:29:38 ERROR Upload failed error=boom count=1182--- PASS: TestScriptTokenEmptyToken (0.01s)183--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)184--- PASS: TestScriptTokenScriptFails (0.00s)185--- PASS: TestClientSignaturesByStorePath (0.00s)186--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)187=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32188=== PAUSE TestEncodeNixBase32/empty_input189=== PAUSE TestRateLimiterFeedback/503_enables_limiter190=== PAUSE TestSetClientTLSErrors/missing_cert_file191=== RUN TestPathInfoCACompatibility/old_string_format_-_text192=== RUN TestFilterOversizedClosures/no_limit_keeps_everything193=== CONT TestStreamPushBatchesUnderLoad194=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI195=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error196=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error197=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error198=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error199=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error200=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter201=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter202=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter203=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter204=== RUN TestSetClientTLSErrors/missing_key_file205=== PAUSE TestSetClientTLSErrors/missing_key_file206=== RUN TestSetClientTLSErrors/missing_ca_file207=== PAUSE TestSetClientTLSErrors/missing_ca_file208=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text209=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive210=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive211=== RUN TestPathInfoCACompatibility/new_structured_format_-_text212=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text213=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method214=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method215=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything216=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped217=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped218=== RUN TestFilterOversizedClosures/all_closures_skipped219=== PAUSE TestFilterOversizedClosures/all_closures_skipped220=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI221=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512222=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512223=== RUN TestPartSizeForNAR/small_stays_at_minimum224=== PAUSE TestPartSizeForNAR/small_stays_at_minimum225=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum226=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum227=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts228=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts229=== RUN TestPartSizeForNAR/1_TiB230=== PAUSE TestPartSizeForNAR/1_TiB231=== RUN TestPartSizeForNAR/5_TiB_S3_max_object232=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object233=== RUN TestPartSizeForNAR/capped_at_5_GiB234=== PAUSE TestPartSizeForNAR/capped_at_5_GiB235=== CONT TestStreamPushReportsEveryPath236=== CONT TestShellSplitErrors237=== CONT TestGetStorePathHash/valid_store_path238=== CONT TestEncodeNixBase32/test_string_hash2392026/09/23 13:29:38 ERROR Upload failed error=boom count=1240=== CONT TestRateLimiterFeedback/429_enables_limiter241=== CONT TestPathInfoCACompatibility/null_ca_field242=== CONT TestFilterOversizedClosures/no_limit_keeps_everything243=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)244=== CONT TestStreamPushIsolatesFailures245=== RUN TestConvertHashToNix32/already_Nix32_format246=== RUN TestSetClientTLS/rejects_connection_without_client_cert247=== CONT TestPartSizeForNAR/zero_stays_at_minimum248=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error249=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error250=== CONT TestGetStorePathHash/basename_without_hyphen_should_error251=== RUN TestParsePathInfoJSON/whitespace_only2522026/09/23 13:29:38 ERROR Upload failed error="bad path" count=3253=== PAUSE TestParsePathInfoJSON/whitespace_only254=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter255=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter256=== RUN TestParsePathInfoJSON/invalid_JSON257=== PAUSE TestParsePathInfoJSON/invalid_JSON258=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths259=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method2602026/09/23 13:29:38 WARN Rate limiter enabled after throttle name=server-test rate=5261=== CONT TestPathInfoCACompatibility/new_structured_format_-_text2622026/09/23 13:29:38 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:44407263=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive264=== CONT TestPathInfoCACompatibility/old_string_format_-_text265=== CONT TestFilterOversizedClosures/all_closures_skipped2662026/09/23 13:29:38 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50267=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2682026/09/23 13:29:38 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=2000269=== CONT TestPartSizeForNAR/capped_at_5_GiB270=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512271=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI272=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon273=== CONT TestPartSizeForNAR/5_TiB_S3_max_object274=== CONT TestPartSizeForNAR/1_TiB275=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts276=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum277=== CONT TestPartSizeForNAR/small_stays_at_minimum278=== CONT TestParsePathInfoJSON/Nix_format279=== CONT TestParsePathInfoJSON/invalid_JSON280=== CONT TestParsePathInfoJSON/whitespace_only281=== CONT TestParsePathInfoJSON/empty_input282=== CONT TestParsePathInfoJSON/Lix_format283--- PASS: TestDumpPathSingleFile (0.06s)284--- PASS: TestShellSplitErrors (0.00s)2852026/09/23 13:29:38 WARN Rate limiter backed off name=server-test rate=5286=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths287--- PASS: TestStreamPushReportsSignatures (0.05s)288=== CONT TestUploadMultipart_SupersededByPeer/missing289=== PAUSE TestConvertHashToNix32/already_Nix32_format290=== CONT TestStreamPushGivesUpOnDeadServer291=== CONT TestUploadMultipart_SupersededByPeer/exists292=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert293=== CONT TestEncodeNixBase32/empty_input294=== RUN TestSetClientTLSErrors/invalid_ca_file295=== CONT TestRateLimiterFeedback/503_enables_limiter296=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA297=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA298=== RUN TestSetClientTLS/preserves_debug_logging_transport299=== PAUSE TestSetClientTLS/preserves_debug_logging_transport300=== CONT TestSetClientTLS/rejects_connection_without_client_cert3012026/09/23 13:29:38 ERROR Upload failed error="connection refused" count=203022026/09/23 13:29:38 ERROR Server seems unavailable, giving up on batch untried=17303--- PASS: TestGetStorePathHash (0.06s)304 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)305 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)306 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)307 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)308--- PASS: TestEncodeNixBase32 (0.06s)309 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)310 --- PASS: TestEncodeNixBase32/empty_input (0.00s)311--- PASS: TestStreamPushReportsEveryPath (0.00s)312--- PASS: TestStreamPushIsolatesFailures (0.00s)313=== PAUSE TestSetClientTLSErrors/invalid_ca_file314=== CONT TestSetClientTLSErrors/missing_cert_file315--- PASS: TestScriptTokenBadJSON (0.06s)3162026/09/23 13:29:38 WARN Rate limiter enabled after throttle name=server-test rate=5317=== CONT TestSetClientTLS/preserves_debug_logging_transport3182026/09/23 13:29:38 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:43971319=== CONT TestSetClientTLSErrors/invalid_ca_file3202026/09/23 13:29:38 WARN Rate limiter backed off name=server-test rate=5321=== CONT TestSetClientTLSErrors/missing_ca_file322--- PASS: TestFilterOversizedClosures (0.05s)323 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)324 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)325 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)326--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)327=== RUN TestConvertHashToNix32/invalid_format328=== PAUSE TestConvertHashToNix32/invalid_format329=== CONT TestConvertHashToNix32/SRI_format_to_Nix32330=== CONT TestSetClientTLSErrors/missing_key_file331=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA332--- PASS: TestPathInfoHashCompatibility (0.06s)333 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)334 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)335 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)336 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)337--- PASS: TestParsePathInfoJSON (0.06s)338 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)339 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)340 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)341 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)342 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)343--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)344 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)345 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)346=== CONT TestConvertHashToNix32/invalid_format347--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)348 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)349 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)350=== CONT TestConvertHashToNix32/already_Nix32_format351--- PASS: TestRateLimiterFeedback (0.06s)352 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)353 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)354 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)355 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)356--- PASS: TestPathInfoCACompatibility (0.06s)357 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)358 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)359 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)360 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)361 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)362--- PASS: TestPartSizeForNAR (0.05s)363 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)364 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)365 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)366 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)367 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)368 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)369 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)370--- PASS: TestConvertHashToNix32 (0.06s)371 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)372 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)373 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)374--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.07s)375--- PASS: TestScriptTokenCachesUntilRefresh (0.06s)376--- PASS: TestSetClientTLSErrors (0.06s)377 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)378 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)379 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)380 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)3812026/09/23 13:29:38 http: TLS handshake error from 127.0.0.1:42350: remote error: tls: bad certificate382--- PASS: TestSetClientTLS (0.01s)383 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)384 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)385 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)386--- PASS: TestStreamPushRequestLine (0.07s)387--- PASS: TestRegisterUploadedObjectReusesConnections (0.08s)388--- PASS: TestDumpPathWriterError (0.10s)389--- PASS: TestCaseHackSuffix (0.09s)390--- PASS: TestDumpPathMatchesNix (0.15s)391--- PASS: TestStreamPushBatchesUnderLoad (0.10s)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/postgres1026098732/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/postgres1026098732/data -l logfile start422423/build/postgres1026098732:5432 - no response4242026-09-23 13:29:40.154 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-09-23 13:29:40.154 UTC [129] LOG: listening on Unix socket "/build/postgres1026098732/.s.PGSQL.5432"4262026-09-23 13:29:40.160 UTC [136] LOG: database system was shut down at 2026-09-23 13:29:39 UTC4272026-09-23 13:29:40.163 UTC [129] LOG: database system is ready to accept connections428/build/postgres1026098732:5432 - accepting connections429{"timestamp":"2026-09-23T13:29:40.458333841Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"3b7cd46f-ab3a-4883-8064-f756f2f477e7","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":463,"threadName":"rustfs-worker","threadId":"ThreadId(397)"}430=== RUN TestService_AuthMiddleware431=== PAUSE TestService_AuthMiddleware432=== RUN TestService_AuthMiddleware_MTLSProxyHeader433=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader434=== RUN TestService_AuthMiddleware_MTLSBoundSubjects435=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects436=== RUN TestService_ReadAuthMiddleware437=== PAUSE TestService_ReadAuthMiddleware438=== RUN TestService_AuthMiddleware_OIDC439=== PAUSE TestService_AuthMiddleware_OIDC440=== RUN TestService_RequireScope_OIDC441=== PAUSE TestService_RequireScope_OIDC442=== RUN TestService_ReadScope_PublicByDefault443=== PAUSE TestService_ReadScope_PublicByDefault444=== RUN TestCacheConfigHandler445=== PAUSE TestCacheConfigHandler446=== RUN TestCacheStatsHandler447=== PAUSE TestCacheStatsHandler448=== RUN TestClientCADerivations449=== PAUSE TestClientCADerivations450=== RUN TestClientErrorHandling451=== PAUSE TestClientErrorHandling452=== RUN TestClientIntegration453=== PAUSE TestClientIntegration454=== RUN TestClientMultipleUploads455=== PAUSE TestClientMultipleUploads456=== RUN TestClientWithDependencies457=== PAUSE TestClientWithDependencies458=== RUN TestClientSharedPathCommittedMidPush459=== PAUSE TestClientSharedPathCommittedMidPush460=== RUN TestPinProtectsFromGC461=== PAUSE TestPinProtectsFromGC462=== RUN TestClientPushesUseOnePush463=== PAUSE TestClientPushesUseOnePush464=== RUN TestClientFallsBackToClosures465=== PAUSE TestClientFallsBackToClosures466=== RUN TestResolveDBConnectionString467=== PAUSE TestResolveDBConnectionString468=== RUN TestLeadElectsOneAndHandsOver469=== PAUSE TestLeadElectsOneAndHandsOver470=== RUN TestLeadIncumbentWinsAfterRestart4712026-09-23 13:29:40.637 UTC [565] ERROR: relation "goose_db_version" does not exist at character 364722026-09-23 13:29:40.637 UTC [565] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4732026/09/23 13:29:40 OK 20241026095416_initial_model.sql (7.25ms)4742026/09/23 13:29:40 OK 20251210153512_drop_unused_gin_index.sql (1.37ms)4752026/09/23 13:29:40 OK 20251218171726_add_pins.sql (2.12ms)4762026/09/23 13:29:40 OK 20260628120000_add_object_size_and_stats.sql (1.89ms)4772026/09/23 13:29:40 OK 20260905000000_add_claims.sql (2.13ms)4782026/09/23 13:29:40 OK 20260920000000_drop_claims.sql (1.5ms)4792026/09/23 13:29:40 OK 20260923120000_add_pushes.sql (1.07ms)4802026/09/23 13:29:40 goose: successfully migrated database to version: 202609231200004812026/09/23 13:29:40 OK 1_commit_pending_closure.sql (1.32ms)4822026/09/23 13:29:40 OK 2_object_stats_trigger.sql (693.45µs)4832026/09/23 13:29:40 OK 3_commit_push.sql (727.6µs)4842026/09/23 13:29:40 goose: up to current file version: 34852026/09/23 13:29:40 INFO lead: acquired remote=192.0.2.1:12344862026/09/23 13:29:41 INFO lead: released remote=192.0.2.1:12344872026/09/23 13:29:41 INFO lead: acquired remote=192.0.2.1:12344882026/09/23 13:29:41 INFO lead: released remote=192.0.2.1:1234489--- PASS: TestLeadIncumbentWinsAfterRestart (0.78s)490=== RUN TestLeadEndsOnShutdown491=== PAUSE TestLeadEndsOnShutdown492=== RUN TestGCAdvisoryLockBlocksConcurrentRun4932026-09-23 13:29:41.396 UTC [574] ERROR: relation "goose_db_version" does not exist at character 364942026-09-23 13:29:41.396 UTC [574] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4952026/09/23 13:29:41 OK 20241026095416_initial_model.sql (6.6ms)4962026/09/23 13:29:41 OK 20251210153512_drop_unused_gin_index.sql (1.86ms)4972026/09/23 13:29:41 OK 20251218171726_add_pins.sql (2.6ms)4982026/09/23 13:29:41 OK 20260628120000_add_object_size_and_stats.sql (2.69ms)4992026/09/23 13:29:41 OK 20260905000000_add_claims.sql (2.35ms)5002026/09/23 13:29:41 OK 20260920000000_drop_claims.sql (1.48ms)5012026/09/23 13:29:41 OK 20260923120000_add_pushes.sql (1.18ms)5022026/09/23 13:29:41 goose: successfully migrated database to version: 202609231200005032026/09/23 13:29:41 OK 1_commit_pending_closure.sql (1.38ms)5042026/09/23 13:29:41 OK 2_object_stats_trigger.sql (808.03µs)5052026/09/23 13:29:41 OK 3_commit_push.sql (766.14µs)5062026/09/23 13:29:41 goose: up to current file version: 3507--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.12s)508=== RUN TestGCBugBareHashReferences509=== PAUSE TestGCBugBareHashReferences510=== RUN TestGCMetrics511=== PAUSE TestGCMetrics512=== RUN TestGCTaskStore_StartNew513=== PAUSE TestGCTaskStore_StartNew514=== RUN TestGCTaskStore_DeduplicateSameParams515=== PAUSE TestGCTaskStore_DeduplicateSameParams516=== RUN TestGCTaskStore_ConflictDifferentParams517=== PAUSE TestGCTaskStore_ConflictDifferentParams518=== RUN TestGCTaskStore_GetEmpty519=== PAUSE TestGCTaskStore_GetEmpty520=== RUN TestGCTaskStore_GetReturnsLatest521=== PAUSE TestGCTaskStore_GetReturnsLatest522=== RUN TestGCTaskStore_CompletedAllowsNewTask523=== PAUSE TestGCTaskStore_CompletedAllowsNewTask524=== RUN TestGCTaskStore_PhaseUpdates525=== PAUSE TestGCTaskStore_PhaseUpdates526=== RUN TestGCTaskStore_Fail527=== PAUSE TestGCTaskStore_Fail528=== RUN TestGracefulShutdownDrainsInflight529=== PAUSE TestGracefulShutdownDrainsInflight530=== RUN TestService_healthCheckHandler531=== PAUSE TestService_healthCheckHandler532=== RUN TestService_readinessHandler533=== PAUSE TestService_readinessHandler534=== RUN TestGenerateLandingPage535=== PAUSE TestGenerateLandingPage536=== RUN TestCacheConfigHandlerMaxNarSize537=== PAUSE TestCacheConfigHandlerMaxNarSize538=== RUN TestCreatePendingClosureRejectsOversizedNAR539=== PAUSE TestCreatePendingClosureRejectsOversizedNAR540=== RUN TestNARDeduplicationMetadataUploadBug541=== PAUSE TestNARDeduplicationMetadataUploadBug542=== RUN TestMetricsInventory543=== PAUSE TestMetricsInventory544=== RUN TestService_NativeMTLS545=== PAUSE TestService_NativeMTLS546=== RUN TestServerTLSConfig547=== PAUSE TestServerTLSConfig548=== RUN TestMultipartCleanup549=== PAUSE TestMultipartCleanup550=== RUN TestObjectStatsTrigger551=== PAUSE TestObjectStatsTrigger552=== RUN TestOrphanedObjectsGC553=== PAUSE TestOrphanedObjectsGC554=== RUN TestOrphanedObjectsGCStressTest555=== PAUSE TestOrphanedObjectsGCStressTest556=== RUN TestResurrectedObjectNotDeleted557=== PAUSE TestResurrectedObjectNotDeleted558=== RUN TestCreatePin_ReservedPins559=== PAUSE TestCreatePin_ReservedPins560=== RUN TestParseSingleRange561=== PAUSE TestParseSingleRange562=== RUN TestProxyHeadersOnlyTrustedOnSocket563=== PAUSE TestProxyHeadersOnlyTrustedOnSocket564=== RUN TestIsValidCachePath565=== PAUSE TestIsValidCachePath566=== RUN TestReadProxyNarinfo567=== PAUSE TestReadProxyNarinfo568=== RUN TestReadProxyNarinfoAlreadyDecompressed569=== PAUSE TestReadProxyNarinfoAlreadyDecompressed570=== RUN TestReadProxyNarStreaming571=== PAUSE TestReadProxyNarStreaming572=== RUN TestReadProxy404573=== PAUSE TestReadProxy404574=== RUN TestReadProxyInvalidPath575=== PAUSE TestReadProxyInvalidPath576=== RUN TestReadProxyHead577=== PAUSE TestReadProxyHead578=== RUN TestReadProxyConditionalGet579=== PAUSE TestReadProxyConditionalGet580=== RUN TestReadProxyRootRedirectsToIndexHTML581=== PAUSE TestReadProxyRootRedirectsToIndexHTML582=== RUN TestReadProxyDisabled583=== PAUSE TestReadProxyDisabled584=== RUN TestReadRedirectNar585=== PAUSE TestReadRedirectNar586=== RUN TestReadRedirectKeepsNarinfoProxied587=== PAUSE TestReadRedirectKeepsNarinfoProxied588=== RUN TestReadProxyRangeRequest589=== PAUSE TestReadProxyRangeRequest590=== RUN TestReadRedirectUsesPublicS3URL591=== PAUSE TestReadRedirectUsesPublicS3URL592=== RUN TestPush_OverlappingRootsStoreOneRowPerKey593=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey594=== RUN TestPush_CompleteCommitsEveryRoot595=== PAUSE TestPush_CompleteCommitsEveryRoot596=== RUN TestPush_CommitFailsWhenSkippedKeyWasCollected597=== PAUSE TestPush_CommitFailsWhenSkippedKeyWasCollected598=== RUN TestPush_RejectsBadRequests599=== PAUSE TestPush_RejectsBadRequests600=== RUN TestPush_SignsNarinfosOfItsPendingObjects601=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects602=== RUN TestRedundantMultipartUpload603=== PAUSE TestRedundantMultipartUpload604=== RUN TestCompleteMultipartUpload_ErrorButObjectExists605=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists606=== RUN TestCompletedNarNotReofferedAcrossClosures607=== PAUSE TestCompletedNarNotReofferedAcrossClosures608=== RUN TestPresignedUploadRegisteredBeforeCommit609=== PAUSE TestPresignedUploadRegisteredBeforeCommit610=== RUN TestService_Rustfstest611=== PAUSE TestService_Rustfstest612=== RUN TestParseSize613=== PAUSE TestParseSize614=== RUN TestSkippedUploadsHandler615=== PAUSE TestSkippedUploadsHandler616=== RUN TestSystemdListenerNotActivated617--- PASS: TestSystemdListenerNotActivated (0.00s)618=== RUN TestWatchdogBeatsWhenHealthy619--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)620=== RUN TestWatchdogSkipsWhenUnhealthy6212026/09/23 13:29:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6222026/09/23 13:29:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6232026/09/23 13:29:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6242026/09/23 13:29:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6252026/09/23 13:29:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6262026/09/23 13:29:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6272026/09/23 13:29:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6282026/09/23 13:29:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6292026/09/23 13:29:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6302026/09/23 13:29:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"631--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)632=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle633=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle634=== RUN TestProxyWriteTimeout635=== PAUSE TestProxyWriteTimeout636=== RUN TestIsValidUploadKey637=== PAUSE TestIsValidUploadKey638=== RUN TestUploadHandlersRejectInvalidKeys639=== PAUSE TestUploadHandlersRejectInvalidKeys640=== RUN TestUploadHandlersRejectOversizedBody641=== PAUSE TestUploadHandlersRejectOversizedBody642=== RUN TestService_cleanupPendingClosuresHandler643=== PAUSE TestService_cleanupPendingClosuresHandler644=== RUN TestService_createPendingClosureHandler645=== PAUSE TestService_createPendingClosureHandler646=== RUN TestService_verifyS3Integrity647=== PAUSE TestService_verifyS3Integrity648=== RUN TestCompleteMultipartUnregistered649=== PAUSE TestCompleteMultipartUnregistered650=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT651=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT652=== CONT TestService_AuthMiddleware653=== CONT TestOrphanedObjectsGC654=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT655=== CONT TestCompleteMultipartUnregistered656=== CONT TestService_verifyS3Integrity657=== CONT TestService_createPendingClosureHandler658=== CONT TestService_cleanupPendingClosuresHandler659=== CONT TestUploadHandlersRejectOversizedBody660=== CONT TestUploadHandlersRejectInvalidKeys661=== CONT TestIsValidUploadKey662=== RUN TestIsValidUploadKey/narinfo663=== CONT TestProxyWriteTimeout664=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle665=== CONT TestSkippedUploadsHandler666=== CONT TestParseSize667=== CONT TestService_Rustfstest668=== CONT TestPresignedUploadRegisteredBeforeCommit669=== CONT TestCompletedNarNotReofferedAcrossClosures670=== CONT TestCompleteMultipartUpload_ErrorButObjectExists671=== CONT TestRedundantMultipartUpload672=== CONT TestPush_SignsNarinfosOfItsPendingObjects673=== CONT TestPush_RejectsBadRequests674=== CONT TestPush_CommitFailsWhenSkippedKeyWasCollected675=== CONT TestPush_CompleteCommitsEveryRoot676=== CONT TestPush_OverlappingRootsStoreOneRowPerKey677=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info678=== PAUSE TestIsValidUploadKey/narinfo679=== RUN TestIsValidUploadKey/nar_zst680=== RUN TestProxyWriteTimeout/narinfo681--- PASS: TestParseSize (0.00s)6822026/09/23 13:29:41 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000683=== CONT TestReadRedirectUsesPublicS3URL684--- PASS: TestSkippedUploadsHandler (0.01s)685=== CONT TestReadProxyRangeRequest686=== PAUSE TestIsValidUploadKey/nar_zst687=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info688=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal689=== RUN TestIsValidUploadKey/nar_xz690=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal691=== PAUSE TestIsValidUploadKey/nar_xz692=== RUN TestIsValidUploadKey/nar_plain693=== PAUSE TestIsValidUploadKey/nar_plain694=== RUN TestIsValidUploadKey/listing695=== PAUSE TestIsValidUploadKey/listing696=== RUN TestIsValidUploadKey/build_log697=== PAUSE TestIsValidUploadKey/build_log698=== RUN TestIsValidUploadKey/build_log_home-manager_file699=== PAUSE TestIsValidUploadKey/build_log_home-manager_file700=== RUN TestIsValidUploadKey/build_log_plus_in_name701=== PAUSE TestIsValidUploadKey/build_log_plus_in_name702=== RUN TestIsValidUploadKey/build_log_question_mark703=== PAUSE TestIsValidUploadKey/build_log_question_mark704=== RUN TestIsValidUploadKey/build_log_equals705=== PAUSE TestIsValidUploadKey/build_log_equals706=== PAUSE TestProxyWriteTimeout/narinfo707=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key708=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key709=== RUN TestIsValidUploadKey/realisation710=== PAUSE TestIsValidUploadKey/realisation711=== RUN TestProxyWriteTimeout/1_GiB_nar712=== PAUSE TestProxyWriteTimeout/1_GiB_nar713=== RUN TestProxyWriteTimeout/10_GiB_nar714=== PAUSE TestProxyWriteTimeout/10_GiB_nar715=== RUN TestProxyWriteTimeout/unknown_size716=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key717=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key718=== RUN TestIsValidUploadKey/realisation_plus_in_output719=== PAUSE TestIsValidUploadKey/realisation_plus_in_output720=== RUN TestIsValidUploadKey/nix-cache-info721=== PAUSE TestIsValidUploadKey/nix-cache-info722=== RUN TestIsValidUploadKey/index.html723=== PAUSE TestIsValidUploadKey/index.html724=== PAUSE TestProxyWriteTimeout/unknown_size725=== CONT TestReadRedirectKeepsNarinfoProxied726=== RUN TestIsValidUploadKey/narinfo_key,_nar_type727=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type728=== CONT TestReadRedirectNar729=== RUN TestIsValidUploadKey/nar_key,_narinfo_type730=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type731=== RUN TestIsValidUploadKey/listing_key,_narinfo_type732=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type733=== RUN TestIsValidUploadKey/traversal734=== PAUSE TestIsValidUploadKey/traversal735=== RUN TestIsValidUploadKey/traversal_nar736=== PAUSE TestIsValidUploadKey/traversal_nar737=== RUN TestIsValidUploadKey/absolute738=== PAUSE TestIsValidUploadKey/absolute739=== RUN TestIsValidUploadKey/empty_key740=== PAUSE TestIsValidUploadKey/empty_key741=== RUN TestIsValidUploadKey/unknown_type742=== PAUSE TestIsValidUploadKey/unknown_type743=== CONT TestReadProxyDisabled744=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure745=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure746=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart747=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart748=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts749=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts750=== CONT TestReadProxyRootRedirectsToIndexHTML7512026-09-23 13:29:41.849 UTC [642] ERROR: relation "goose_db_version" does not exist at character 367522026-09-23 13:29:41.849 UTC [642] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7532026-09-23 13:29:41.998 UTC [643] ERROR: relation "goose_db_version" does not exist at character 367542026-09-23 13:29:41.998 UTC [643] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7552026-09-23 13:29:41.999 UTC [644] ERROR: relation "goose_db_version" does not exist at character 367562026-09-23 13:29:41.999 UTC [644] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7572026-09-23 13:29:42.010 UTC [645] ERROR: relation "goose_db_version" does not exist at character 367582026-09-23 13:29:42.010 UTC [645] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7592026/09/23 13:29:42 OK 20241026095416_initial_model.sql (72.77ms)7602026-09-23 13:29:42.031 UTC [646] ERROR: relation "goose_db_version" does not exist at character 367612026-09-23 13:29:42.031 UTC [646] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7622026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (5ms)7632026-09-23 13:29:42.036 UTC [649] ERROR: relation "goose_db_version" does not exist at character 367642026-09-23 13:29:42.036 UTC [649] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7652026-09-23 13:29:42.047 UTC [650] ERROR: relation "goose_db_version" does not exist at character 367662026-09-23 13:29:42.047 UTC [650] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7672026/09/23 13:29:42 OK 20251218171726_add_pins.sql (22.91ms)7682026/09/23 13:29:42 OK 20241026095416_initial_model.sql (33.57ms)7692026/09/23 13:29:42 OK 20241026095416_initial_model.sql (33.2ms)7702026-09-23 13:29:42.075 UTC [651] ERROR: relation "goose_db_version" does not exist at character 367712026-09-23 13:29:42.075 UTC [651] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7722026/09/23 13:29:42 OK 20241026095416_initial_model.sql (52.31ms)7732026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (12.21ms)7742026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (23.58ms)7752026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (16.04ms)7762026/09/23 13:29:42 OK 20241026095416_initial_model.sql (40.77ms)7772026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (4.61ms)7782026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (5.12ms)7792026/09/23 13:29:42 OK 20251218171726_add_pins.sql (9.68ms)7802026/09/23 13:29:42 OK 20260905000000_add_claims.sql (11.28ms)7812026/09/23 13:29:42 OK 20251218171726_add_pins.sql (6.89ms)7822026/09/23 13:29:42 OK 20251218171726_add_pins.sql (12.91ms)7832026/09/23 13:29:42 OK 20241026095416_initial_model.sql (33.94ms)7842026/09/23 13:29:42 OK 20251218171726_add_pins.sql (11.44ms)7852026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (4.38ms)7862026-09-23 13:29:42.100 UTC [652] ERROR: relation "goose_db_version" does not exist at character 367872026-09-23 13:29:42.100 UTC [652] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7882026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (8.1ms)7892026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (10.51ms)7902026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (8.9ms)7912026/09/23 13:29:42 OK 20241026095416_initial_model.sql (26ms)7922026-09-23 13:29:42.104 UTC [653] ERROR: relation "goose_db_version" does not exist at character 367932026-09-23 13:29:42.104 UTC [653] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7942026-09-23 13:29:42.105 UTC [654] ERROR: relation "goose_db_version" does not exist at character 367952026-09-23 13:29:42.105 UTC [654] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7962026/09/23 13:29:42 OK 20251218171726_add_pins.sql (7.36ms)7972026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (7.97ms)7982026/09/23 13:29:42 goose: successfully migrated database to version: 202609231200007992026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (14.55ms)8002026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (5.64ms)8012026/09/23 13:29:42 OK 20260905000000_add_claims.sql (7.54ms)8022026/09/23 13:29:42 OK 20260905000000_add_claims.sql (6.75ms)8032026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (12.92ms)8042026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (3.39ms)8052026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (4.73ms)8062026-09-23 13:29:42.114 UTC [655] ERROR: relation "goose_db_version" does not exist at character 368072026-09-23 13:29:42.114 UTC [655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8082026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (16.83ms)8092026/09/23 13:29:42 OK 20241026095416_initial_model.sql (29.92ms)8102026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (13.63ms)8112026/09/23 13:29:42 OK 20260905000000_add_claims.sql (18.62ms)8122026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (14.08ms)8132026/09/23 13:29:42 goose: successfully migrated database to version: 202609231200008142026/09/23 13:29:42 OK 20260905000000_add_claims.sql (17.51ms)8152026/09/23 13:29:42 goose: successfully migrated database to version: 202609231200008162026/09/23 13:29:42 OK 20251218171726_add_pins.sql (18.52ms)8172026/09/23 13:29:42 OK 1_commit_pending_closure.sql (18.77ms)8182026/09/23 13:29:42 OK 20241026095416_initial_model.sql (16.79ms)8192026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (5.5ms)8202026/09/23 13:29:42 OK 20260905000000_add_claims.sql (6.74ms)8212026/09/23 13:29:42 OK 2_object_stats_trigger.sql (3.5ms)8222026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (2.64ms)8232026/09/23 13:29:42 OK 1_commit_pending_closure.sql (5.07ms)8242026/09/23 13:29:42 OK 1_commit_pending_closure.sql (5ms)8252026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (3.24ms)8262026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (6.55ms)8272026/09/23 13:29:42 OK 3_commit_push.sql (2.76ms)8282026/09/23 13:29:42 goose: up to current file version: 38292026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (7.16ms)8302026/09/23 13:29:42 OK 2_object_stats_trigger.sql (3.06ms)8312026/09/23 13:29:42 OK 20251218171726_add_pins.sql (6.88ms)8322026/09/23 13:29:42 OK 2_object_stats_trigger.sql (3.27ms)8332026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (3.95ms)8342026/09/23 13:29:42 goose: successfully migrated database to version: 202609231200008352026/09/23 13:29:42 OK 20251218171726_add_pins.sql (5.86ms)8362026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (9.67ms)8372026-09-23 13:29:42.139 UTC [657] ERROR: relation "goose_db_version" does not exist at character 368382026-09-23 13:29:42.139 UTC [657] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8392026-09-23 13:29:42.139 UTC [656] ERROR: relation "goose_db_version" does not exist at character 368402026-09-23 13:29:42.139 UTC [656] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8412026-09-23 13:29:42.140 UTC [658] ERROR: relation "goose_db_version" does not exist at character 368422026-09-23 13:29:42.140 UTC [658] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8432026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (5.51ms)8442026/09/23 13:29:42 goose: successfully migrated database to version: 202609231200008452026/09/23 13:29:42 OK 3_commit_push.sql (3.71ms)8462026/09/23 13:29:42 goose: up to current file version: 38472026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (5.2ms)8482026/09/23 13:29:42 goose: successfully migrated database to version: 202609231200008492026/09/23 13:29:42 OK 3_commit_push.sql (3.85ms)8502026/09/23 13:29:42 goose: up to current file version: 38512026/09/23 13:29:42 OK 20241026095416_initial_model.sql (13.82ms)8522026/09/23 13:29:42 OK 1_commit_pending_closure.sql (5.84ms)8532026/09/23 13:29:42 OK 20241026095416_initial_model.sql (15.14ms)8542026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (7.62ms)8552026/09/23 13:29:42 OK 20241026095416_initial_model.sql (15.13ms)8562026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (6ms)8572026/09/23 13:29:42 OK 20260905000000_add_claims.sql (6.64ms)8582026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (2.04ms)8592026/09/23 13:29:42 OK 1_commit_pending_closure.sql (4.33ms)8602026/09/23 13:29:42 OK 2_object_stats_trigger.sql (1.83ms)8612026/09/23 13:29:42 OK 1_commit_pending_closure.sql (5.53ms)8622026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (2.67ms)8632026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (2.81ms)8642026-09-23 13:29:42.147 UTC [659] ERROR: relation "goose_db_version" does not exist at character 368652026-09-23 13:29:42.147 UTC [659] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8662026/09/23 13:29:42 OK 20260905000000_add_claims.sql (3.79ms)8672026/09/23 13:29:42 OK 2_object_stats_trigger.sql (2.85ms)8682026/09/23 13:29:42 OK 3_commit_push.sql (2.16ms)8692026/09/23 13:29:42 goose: up to current file version: 38702026/09/23 13:29:42 OK 20260905000000_add_claims.sql (3.7ms)8712026/09/23 13:29:42 OK 20251218171726_add_pins.sql (3.86ms)8722026/09/23 13:29:42 OK 2_object_stats_trigger.sql (3.03ms)8732026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (4.27ms)8742026/09/23 13:29:42 OK 3_commit_push.sql (1.9ms)8752026/09/23 13:29:42 goose: up to current file version: 38762026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (2.66ms)8772026/09/23 13:29:42 OK 20251218171726_add_pins.sql (3.86ms)8782026/09/23 13:29:42 OK 20251218171726_add_pins.sql (3.95ms)8792026/09/23 13:29:42 OK 3_commit_push.sql (1.81ms)8802026/09/23 13:29:42 goose: up to current file version: 38812026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (3.4ms)8822026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (3.1ms)8832026/09/23 13:29:42 goose: successfully migrated database to version: 202609231200008842026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (4.47ms)8852026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (2.82ms)8862026/09/23 13:29:42 goose: successfully migrated database to version: 202609231200008872026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (3.08ms)8882026/09/23 13:29:42 goose: successfully migrated database to version: 202609231200008892026-09-23 13:29:42.156 UTC [660] ERROR: relation "goose_db_version" does not exist at character 368902026-09-23 13:29:42.156 UTC [660] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8912026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (5.13ms)8922026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (5.03ms)8932026/09/23 13:29:42 OK 1_commit_pending_closure.sql (4.47ms)8942026/09/23 13:29:42 OK 20260905000000_add_claims.sql (3.51ms)8952026-09-23 13:29:42.158 UTC [661] ERROR: relation "goose_db_version" does not exist at character 368962026-09-23 13:29:42.158 UTC [661] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8972026/09/23 13:29:42 OK 1_commit_pending_closure.sql (3.1ms)8982026/09/23 13:29:42 OK 20241026095416_initial_model.sql (10.84ms)8992026/09/23 13:29:42 OK 1_commit_pending_closure.sql (4.18ms)9002026/09/23 13:29:42 OK 2_object_stats_trigger.sql (2.05ms)9012026/09/23 13:29:42 OK 20241026095416_initial_model.sql (10.74ms)9022026/09/23 13:29:42 OK 20241026095416_initial_model.sql (13.1ms)9032026/09/23 13:29:42 OK 20260905000000_add_claims.sql (3.45ms)9042026/09/23 13:29:42 OK 20260905000000_add_claims.sql (3.59ms)9052026/09/23 13:29:42 OK 2_object_stats_trigger.sql (1.17ms)9062026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (1.38ms)9072026/09/23 13:29:42 OK 2_object_stats_trigger.sql (1.46ms)9082026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (2.76ms)9092026-09-23 13:29:42.161 UTC [662] ERROR: relation "goose_db_version" does not exist at character 369102026-09-23 13:29:42.161 UTC [662] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9112026/09/23 13:29:42 OK 3_commit_push.sql (1.83ms)9122026/09/23 13:29:42 goose: up to current file version: 39132026-09-23 13:29:42.162 UTC [663] ERROR: relation "goose_db_version" does not exist at character 369142026-09-23 13:29:42.162 UTC [663] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9152026/09/23 13:29:42 OK 3_commit_push.sql (2.06ms)9162026/09/23 13:29:42 goose: up to current file version: 39172026/09/23 13:29:42 OK 3_commit_push.sql (2.28ms)9182026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (2.73ms)9192026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (1.99ms)9202026/09/23 13:29:42 goose: successfully migrated database to version: 202609231200009212026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (2.64ms)9222026/09/23 13:29:42 goose: up to current file version: 39232026/09/23 13:29:42 OK 20251218171726_add_pins.sql (2.82ms)9242026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (3.12ms)9252026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (3.11ms)9262026-09-23 13:29:42.164 UTC [664] ERROR: relation "goose_db_version" does not exist at character 369272026-09-23 13:29:42.164 UTC [664] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9282026-09-23 13:29:42.165 UTC [665] ERROR: relation "goose_db_version" does not exist at character 369292026-09-23 13:29:42.165 UTC [665] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9302026/09/23 13:29:42 INFO Received uploads request method=POST path=/api/pending_closures9312026/09/23 13:29:42 INFO Received uploads request method=POST path=/api/pending_closures9322026/09/23 13:29:42 INFO Received uploads request method=POST path=/api/pending_closures9332026-09-23 13:29:42.166 UTC [666] ERROR: relation "goose_db_version" does not exist at character 369342026-09-23 13:29:42.166 UTC [666] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9352026/09/23 13:29:42 OK 1_commit_pending_closure.sql (2.8ms)9362026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (2.55ms)9372026/09/23 13:29:42 goose: successfully migrated database to version: 202609231200009382026/09/23 13:29:42 OK 20251218171726_add_pins.sql (3.42ms)9392026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (3.43ms)9402026/09/23 13:29:42 goose: successfully migrated database to version: 202609231200009412026/09/23 13:29:42 OK 20251218171726_add_pins.sql (3.96ms)9422026/09/23 13:29:42 OK 2_object_stats_trigger.sql (1.59ms)9432026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (4.31ms)9442026/09/23 13:29:42 OK 20241026095416_initial_model.sql (10.43ms)9452026/09/23 13:29:42 OK 3_commit_push.sql (2.54ms)9462026-09-23 13:29:42.170 UTC [667] ERROR: relation "goose_db_version" does not exist at character 369472026-09-23 13:29:42.170 UTC [667] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9482026/09/23 13:29:42 goose: up to current file version: 39492026/09/23 13:29:42 OK 1_commit_pending_closure.sql (4.09ms)9502026/09/23 13:29:42 OK 1_commit_pending_closure.sql (3.24ms)9512026/09/23 13:29:42 OK 20260905000000_add_claims.sql (3.08ms)9522026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (2ms)9532026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (5.3ms)9542026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (5.02ms)9552026/09/23 13:29:42 OK 2_object_stats_trigger.sql (2.82ms)9562026/09/23 13:29:42 OK 2_object_stats_trigger.sql (2.98ms)9572026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (3.16ms)9582026/09/23 13:29:42 OK 20251218171726_add_pins.sql (3.39ms)9592026/09/23 13:29:42 OK 3_commit_push.sql (2.33ms)9602026/09/23 13:29:42 goose: up to current file version: 39612026/09/23 13:29:42 OK 3_commit_push.sql (2.28ms)9622026/09/23 13:29:42 goose: up to current file version: 39632026/09/23 13:29:42 OK 20241026095416_initial_model.sql (10.52ms)9642026/09/23 13:29:42 OK 20260905000000_add_claims.sql (4.62ms)9652026/09/23 13:29:42 OK 20260905000000_add_claims.sql (4.81ms)9662026/09/23 13:29:42 OK 20241026095416_initial_model.sql (13.28ms)9672026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (2.79ms)9682026/09/23 13:29:42 goose: successfully migrated database to version: 202609231200009692026/09/23 13:29:42 OK 20241026095416_initial_model.sql (10.6ms)9702026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (2.07ms)9712026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (4.53ms)9722026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (2.18ms)9732026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (2.98ms)9742026/09/23 13:29:42 OK 1_commit_pending_closure.sql (2.71ms)9752026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (1.94ms)9762026/09/23 13:29:42 OK 20241026095416_initial_model.sql (10.02ms)9772026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (3.93ms)9782026/09/23 13:29:42 OK 2_object_stats_trigger.sql (1.46ms)9792026/09/23 13:29:42 OK 20241026095416_initial_model.sql (10.12ms)9802026/09/23 13:29:42 OK 20251218171726_add_pins.sql (3.23ms)9812026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (2.8ms)9822026/09/23 13:29:42 goose: successfully migrated database to version: 202609231200009832026/09/23 13:29:42 OK 20241026095416_initial_model.sql (10.48ms)9842026/09/23 13:29:42 OK 20241026095416_initial_model.sql (10.52ms)9852026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (2.12ms)9862026/09/23 13:29:42 OK 20260905000000_add_claims.sql (4.23ms)9872026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (2.07ms)9882026/09/23 13:29:42 OK 20251218171726_add_pins.sql (4.17ms)9892026/09/23 13:29:42 OK 20251218171726_add_pins.sql (3.43ms)9902026/09/23 13:29:42 OK 3_commit_push.sql (2.03ms)9912026/09/23 13:29:42 goose: up to current file version: 39922026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (2.65ms)9932026/09/23 13:29:42 goose: successfully migrated database to version: 202609231200009942026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (989.74µs)9952026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (1.28ms)9962026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (2.86ms)9972026/09/23 13:29:42 OK 1_commit_pending_closure.sql (2.72ms)9982026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (2.62ms)9992026/09/23 13:29:42 OK 20251218171726_add_pins.sql (3.6ms)10002026/09/23 13:29:42 OK 20251218171726_add_pins.sql (3.31ms)10012026/09/23 13:29:42 OK 1_commit_pending_closure.sql (3.44ms)10022026/09/23 13:29:42 OK 2_object_stats_trigger.sql (1.92ms)10032026/09/23 13:29:42 OK 20260905000000_add_claims.sql (2.95ms)10042026/09/23 13:29:42 OK 20251218171726_add_pins.sql (3.12ms)10052026/09/23 13:29:42 OK 20251218171726_add_pins.sql (3.85ms)10062026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (1.55ms)10072026/09/23 13:29:42 goose: successfully migrated database to version: 2026092312000010082026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (4.21ms)10092026/09/23 13:29:42 OK 20241026095416_initial_model.sql (10.12ms)10102026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (3.82ms)10112026/09/23 13:29:42 INFO Received uploads request method=POST path=/api/pending_closures10122026/09/23 13:29:42 OK 3_commit_push.sql (1.35ms)10132026/09/23 13:29:42 goose: up to current file version: 310142026/09/23 13:29:42 OK 2_object_stats_trigger.sql (2.63ms)10152026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (2.23ms)10162026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (3.12ms)10172026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (3.25ms)10182026/09/23 13:29:42 OK 1_commit_pending_closure.sql (3.05ms)10192026/09/23 13:29:42 OK 20260905000000_add_claims.sql (2.86ms)10202026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (4.34ms)10212026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (3.57ms)10222026/09/23 13:29:42 OK 20260905000000_add_claims.sql (3.01ms)10232026/09/23 13:29:42 OK 3_commit_push.sql (1.04ms)10242026/09/23 13:29:42 goose: up to current file version: 310252026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (3.54ms)10262026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (1.82ms)10272026/09/23 13:29:42 goose: successfully migrated database to version: 2026092312000010282026/09/23 13:29:42 OK 2_object_stats_trigger.sql (2.61ms)10292026/09/23 13:29:42 OK 20251218171726_add_pins.sql (3.38ms)10302026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (2.88ms)10312026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (3.32ms)10322026/09/23 13:29:42 OK 20260905000000_add_claims.sql (3.06ms)10332026/09/23 13:29:42 OK 20260905000000_add_claims.sql (3.52ms)10342026/09/23 13:29:42 OK 20260905000000_add_claims.sql (3.3ms)10352026/09/23 13:29:42 OK 20260905000000_add_claims.sql (3.16ms)10362026/09/23 13:29:42 OK 3_commit_push.sql (1.04ms)10372026/09/23 13:29:42 goose: up to current file version: 310382026/09/23 13:29:42 OK 1_commit_pending_closure.sql (2.15ms)10392026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (2.25ms)10402026/09/23 13:29:42 goose: successfully migrated database to version: 2026092312000010412026/09/23 13:29:42 OK 2_object_stats_trigger.sql (1.59ms)10422026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (2.79ms)10432026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (2.3ms)10442026/09/23 13:29:42 goose: successfully migrated database to version: 2026092312000010452026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (2.51ms)10462026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (2.55ms)10472026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (2.84ms)10482026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (2.81ms)10492026/09/23 13:29:42 OK 3_commit_push.sql (1.01ms)10502026/09/23 13:29:42 goose: up to current file version: 310512026/09/23 13:29:42 OK 1_commit_pending_closure.sql (1.35ms)10522026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (1.1ms)10532026/09/23 13:29:42 goose: successfully migrated database to version: 2026092312000010542026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (1.13ms)10552026/09/23 13:29:42 goose: successfully migrated database to version: 2026092312000010562026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (1.31ms)10572026/09/23 13:29:42 goose: successfully migrated database to version: 2026092312000010582026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (1.45ms)10592026/09/23 13:29:42 goose: successfully migrated database to version: 2026092312000010602026/09/23 13:29:42 OK 1_commit_pending_closure.sql (1.81ms)10612026/09/23 13:29:42 OK 2_object_stats_trigger.sql (1.07ms)10622026/09/23 13:29:42 OK 20260905000000_add_claims.sql (2.33ms)10632026/09/23 13:29:42 OK 1_commit_pending_closure.sql (1.35ms)10642026/09/23 13:29:42 OK 1_commit_pending_closure.sql (1.55ms)10652026/09/23 13:29:42 OK 3_commit_push.sql (977.83µs)10662026/09/23 13:29:42 goose: up to current file version: 310672026/09/23 13:29:42 OK 2_object_stats_trigger.sql (1.05ms)10682026/09/23 13:29:42 OK 1_commit_pending_closure.sql (1.61ms)10692026/09/23 13:29:42 OK 1_commit_pending_closure.sql (1.43ms)10702026/09/23 13:29:42 OK 2_object_stats_trigger.sql (951.2µs)10712026/09/23 13:29:42 OK 2_object_stats_trigger.sql (870.04µs)10722026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (1.9ms)10732026/09/23 13:29:42 OK 3_commit_push.sql (803.05µs)10742026/09/23 13:29:42 goose: up to current file version: 310752026/09/23 13:29:42 OK 2_object_stats_trigger.sql (987.29µs)10762026/09/23 13:29:42 OK 3_commit_push.sql (893.93µs)10772026/09/23 13:29:42 goose: up to current file version: 310782026/09/23 13:29:42 OK 2_object_stats_trigger.sql (1.07ms)10792026/09/23 13:29:42 OK 3_commit_push.sql (1.01ms)10802026/09/23 13:29:42 goose: up to current file version: 310812026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (1.12ms)10822026/09/23 13:29:42 goose: successfully migrated database to version: 2026092312000010832026/09/23 13:29:42 OK 3_commit_push.sql (814.8µs)10842026/09/23 13:29:42 goose: up to current file version: 310852026/09/23 13:29:42 OK 3_commit_push.sql (944.05µs)10862026/09/23 13:29:42 goose: up to current file version: 310872026/09/23 13:29:42 OK 1_commit_pending_closure.sql (1.89ms)10882026/09/23 13:29:42 OK 2_object_stats_trigger.sql (729.05µs)10892026/09/23 13:29:42 OK 3_commit_push.sql (528.04µs)10902026/09/23 13:29:42 goose: up to current file version: 310912026/09/23 13:29:42 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1092--- PASS: TestService_AuthMiddleware (0.52s)1093=== CONT TestReadProxyConditionalGet1094--- PASS: TestService_Rustfstest (0.54s)1095=== CONT TestReadProxyHead10962026/09/23 13:29:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10972026/09/23 13:29:42 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1098--- PASS: TestCompleteMultipartUnregistered (0.61s)1099=== CONT TestReadProxyInvalidPath11002026/09/23 13:29:42 INFO Received uploads request method=POST path=/api/pending_closures11012026-09-23 13:29:42.316 UTC [675] ERROR: relation "goose_db_version" does not exist at character 3611022026-09-23 13:29:42.316 UTC [675] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11032026-09-23 13:29:42.322 UTC [676] ERROR: relation "goose_db_version" does not exist at character 3611042026-09-23 13:29:42.322 UTC [676] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11052026/09/23 13:29:42 OK 20241026095416_initial_model.sql (10.82ms)11062026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (1.6ms)11072026/09/23 13:29:42 OK 20251218171726_add_pins.sql (2.67ms)11082026/09/23 13:29:42 OK 20241026095416_initial_model.sql (6.9ms)11092026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (1.78ms)11102026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (2.96ms)11112026/09/23 13:29:42 OK 20251218171726_add_pins.sql (2.58ms)11122026/09/23 13:29:42 OK 20260905000000_add_claims.sql (2.66ms)11132026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (1.55ms)11142026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (3.06ms)11152026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (1.51ms)11162026/09/23 13:29:42 goose: successfully migrated database to version: 202609231200001117--- PASS: TestReadProxyRangeRequest (0.65s)1118=== CONT TestReadProxy40411192026/09/23 13:29:42 OK 1_commit_pending_closure.sql (2.28ms)11202026/09/23 13:29:42 OK 20260905000000_add_claims.sql (3.34ms)11212026/09/23 13:29:42 OK 2_object_stats_trigger.sql (1.72ms)11222026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (2.45ms)11232026/09/23 13:29:42 OK 3_commit_push.sql (1.75ms)11242026/09/23 13:29:42 goose: up to current file version: 311252026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (1.83ms)11262026/09/23 13:29:42 goose: successfully migrated database to version: 2026092312000011272026/09/23 13:29:42 OK 1_commit_pending_closure.sql (2.01ms)11282026/09/23 13:29:42 OK 2_object_stats_trigger.sql (1.14ms)11292026/09/23 13:29:42 OK 3_commit_push.sql (1.54ms)11302026/09/23 13:29:42 goose: up to current file version: 311312026/09/23 13:29:42 INFO Received uploads request method=POST path=/api/pending_closures1132--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.69s)1133=== CONT TestReadProxyNarStreaming11342026-09-23 13:29:42.381 UTC [680] ERROR: relation "goose_db_version" does not exist at character 3611352026-09-23 13:29:42.381 UTC [680] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11362026/09/23 13:29:42 INFO Received uploads request method=POST path=/api/pending_closures11372026/09/23 13:29:42 OK 20241026095416_initial_model.sql (8.44ms)11382026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (1.73ms)11392026/09/23 13:29:42 OK 20251218171726_add_pins.sql (3.26ms)11402026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (3.2ms)11412026/09/23 13:29:42 OK 20260905000000_add_claims.sql (3.1ms)11422026/09/23 13:29:42 INFO Received uploads request method=POST path=/api/pending_closures11432026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (2.98ms)11442026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (2.04ms)11452026/09/23 13:29:42 goose: successfully migrated database to version: 2026092312000011462026/09/23 13:29:42 OK 1_commit_pending_closure.sql (2.04ms)11472026/09/23 13:29:42 OK 2_object_stats_trigger.sql (1.17ms)11482026/09/23 13:29:42 OK 3_commit_push.sql (1.44ms)11492026/09/23 13:29:42 goose: up to current file version: 311502026/09/23 13:29:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11512026-09-23 13:29:42.429 UTC [683] ERROR: relation "goose_db_version" does not exist at character 3611522026-09-23 13:29:42.429 UTC [683] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1153--- PASS: TestReadRedirectUsesPublicS3URL (0.75s)1154=== CONT TestReadProxyNarinfoAlreadyDecompressed11552026/09/23 13:29:42 INFO Received push request method=POST path=/api/pushes11562026/09/23 13:29:42 OK 20241026095416_initial_model.sql (7.9ms)11572026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (1.42ms)11582026/09/23 13:29:42 OK 20251218171726_add_pins.sql (2.75ms)11592026-09-23 13:29:42.456 UTC [686] ERROR: relation "goose_db_version" does not exist at character 3611602026-09-23 13:29:42.456 UTC [686] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11612026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (3.69ms)11622026/09/23 13:29:42 OK 20260905000000_add_claims.sql (3.34ms)11632026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (2.86ms)11642026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (1.69ms)11652026/09/23 13:29:42 goose: successfully migrated database to version: 2026092312000011662026/09/23 13:29:42 OK 20241026095416_initial_model.sql (7.66ms)11672026/09/23 13:29:42 OK 1_commit_pending_closure.sql (2.93ms)11682026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (1.76ms)1169--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.77s)1170=== CONT TestReadProxyNarinfo11712026/09/23 13:29:42 OK 2_object_stats_trigger.sql (1.36ms)11722026/09/23 13:29:42 OK 20251218171726_add_pins.sql (3ms)11732026/09/23 13:29:42 OK 3_commit_push.sql (2ms)11742026/09/23 13:29:42 goose: up to current file version: 311752026/09/23 13:29:42 INFO Received push request method=POST path=/api/pushes11762026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (2.95ms)11772026/09/23 13:29:42 OK 20260905000000_add_claims.sql (2.79ms)11782026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (2.25ms)11792026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (1.86ms)11802026/09/23 13:29:42 goose: successfully migrated database to version: 2026092312000011812026/09/23 13:29:42 OK 1_commit_pending_closure.sql (2.75ms)11822026/09/23 13:29:42 OK 2_object_stats_trigger.sql (1.48ms)11832026/09/23 13:29:42 OK 3_commit_push.sql (1.32ms)11842026/09/23 13:29:42 goose: up to current file version: 311852026/09/23 13:29:42 INFO Received complete push request method=POST path=/api/pushes/1/complete11862026/09/23 13:29:42 INFO Received cleanup request method=DELETE path=/api/pending_closures1187--- PASS: TestPush_CompleteCommitsEveryRoot (0.80s)1188=== CONT TestIsValidCachePath1189=== RUN TestIsValidCachePath/narinfo1190=== PAUSE TestIsValidCachePath/narinfo1191=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1192=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1193=== RUN TestIsValidCachePath/nar_zst1194=== PAUSE TestIsValidCachePath/nar_zst1195=== RUN TestIsValidCachePath/nar_xz1196=== PAUSE TestIsValidCachePath/nar_xz1197=== RUN TestIsValidCachePath/nar_bz21198=== PAUSE TestIsValidCachePath/nar_bz21199=== RUN TestIsValidCachePath/nar_uncompressed1200=== PAUSE TestIsValidCachePath/nar_uncompressed1201=== RUN TestIsValidCachePath/ls1202=== PAUSE TestIsValidCachePath/ls1203=== RUN TestIsValidCachePath/log1204=== PAUSE TestIsValidCachePath/log1205=== RUN TestIsValidCachePath/realisation1206=== PAUSE TestIsValidCachePath/realisation1207=== RUN TestIsValidCachePath/nix-cache-info1208=== PAUSE TestIsValidCachePath/nix-cache-info1209=== RUN TestIsValidCachePath/index.html1210=== PAUSE TestIsValidCachePath/index.html1211=== RUN TestIsValidCachePath/traversal_parent1212=== PAUSE TestIsValidCachePath/traversal_parent1213=== RUN TestIsValidCachePath/traversal_in_middle1214=== PAUSE TestIsValidCachePath/traversal_in_middle1215=== RUN TestIsValidCachePath/invalid_char_e1216=== PAUSE TestIsValidCachePath/invalid_char_e1217=== RUN TestIsValidCachePath/invalid_char_u1218=== PAUSE TestIsValidCachePath/invalid_char_u1219=== RUN TestIsValidCachePath/random_path1220=== PAUSE TestIsValidCachePath/random_path1221=== RUN TestIsValidCachePath/empty1222=== PAUSE TestIsValidCachePath/empty1223=== RUN TestIsValidCachePath/leading_slash1224=== PAUSE TestIsValidCachePath/leading_slash1225=== RUN TestIsValidCachePath/wrong_extension1226=== PAUSE TestIsValidCachePath/wrong_extension1227=== RUN TestIsValidCachePath/short_hash1228=== PAUSE TestIsValidCachePath/short_hash1229=== CONT TestProxyHeadersOnlyTrustedOnSocket12302026/09/23 13:29:42 INFO Aborted multipart uploads count=012312026/09/23 13:29:42 INFO Received uploads request method=POST path=/api/pending_closures12322026-09-23 13:29:42.518 UTC [695] ERROR: relation "goose_db_version" does not exist at character 3612332026-09-23 13:29:42.518 UTC [695] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12342026/09/23 13:29:42 INFO Received cleanup request method=DELETE path=/api/pending_closures12352026/09/23 13:29:42 INFO Aborted multipart uploads count=112362026/09/23 13:29:42 OK 20241026095416_initial_model.sql (8.7ms)12372026/09/23 13:29:42 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12382026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (2.38ms)12392026-09-23 13:29:42.534 UTC [657] ERROR: Closure does not exist: id=112402026-09-23 13:29:42.534 UTC [657] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE12412026-09-23 13:29:42.534 UTC [657] STATEMENT: -- name: CommitPendingClosure :exec1242 SELECT commit_pending_closure($1::bigint)1243 1244--- PASS: TestService_cleanupPendingClosuresHandler (0.85s)1245=== CONT TestParseSingleRange1246=== RUN TestParseSingleRange/none1247=== PAUSE TestParseSingleRange/none1248=== RUN TestParseSingleRange/unknown_unit1249=== PAUSE TestParseSingleRange/unknown_unit1250=== RUN TestParseSingleRange/multi-range_ignored1251=== PAUSE TestParseSingleRange/multi-range_ignored1252=== RUN TestParseSingleRange/malformed_no_dash1253=== PAUSE TestParseSingleRange/malformed_no_dash1254=== RUN TestParseSingleRange/malformed_both_empty1255=== PAUSE TestParseSingleRange/malformed_both_empty1256=== RUN TestParseSingleRange/malformed_end_before_start1257=== PAUSE TestParseSingleRange/malformed_end_before_start1258=== RUN TestParseSingleRange/closed1259=== PAUSE TestParseSingleRange/closed1260=== RUN TestParseSingleRange/open-ended1261=== PAUSE TestParseSingleRange/open-ended1262=== RUN TestParseSingleRange/end_clamped_to_size1263=== PAUSE TestParseSingleRange/end_clamped_to_size1264=== RUN TestParseSingleRange/suffix1265=== PAUSE TestParseSingleRange/suffix1266=== RUN TestParseSingleRange/suffix_exceeds_size1267=== PAUSE TestParseSingleRange/suffix_exceeds_size1268=== RUN TestParseSingleRange/single_byte1269=== PAUSE TestParseSingleRange/single_byte1270=== RUN TestParseSingleRange/start_past_EOF1271=== PAUSE TestParseSingleRange/start_past_EOF1272=== RUN TestParseSingleRange/start_far_past_EOF1273=== PAUSE TestParseSingleRange/start_far_past_EOF1274=== CONT TestCreatePin_ReservedPins1275--- PASS: TestReadProxyDisabled (0.78s)1276=== CONT TestResurrectedObjectNotDeleted12772026/09/23 13:29:42 OK 20251218171726_add_pins.sql (2.55ms)12782026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (3.91ms)12792026/09/23 13:29:42 OK 20260905000000_add_claims.sql (3.12ms)12802026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (2.67ms)12812026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (1.84ms)12822026/09/23 13:29:42 goose: successfully migrated database to version: 2026092312000012832026/09/23 13:29:42 OK 1_commit_pending_closure.sql (3.27ms)12842026/09/23 13:29:42 OK 2_object_stats_trigger.sql (1.24ms)12852026/09/23 13:29:42 OK 3_commit_push.sql (1.07ms)12862026/09/23 13:29:42 goose: up to current file version: 312872026-09-23 13:29:42.564 UTC [699] ERROR: relation "goose_db_version" does not exist at character 3612882026-09-23 13:29:42.564 UTC [699] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12892026/09/23 13:29:42 INFO Received push request method=POST path=/api/pushes12902026/09/23 13:29:42 OK 20241026095416_initial_model.sql (8.24ms)12912026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (2.04ms)12922026/09/23 13:29:42 OK 20251218171726_add_pins.sql (3.11ms)12932026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (11.39ms)12942026/09/23 13:29:42 OK 20260905000000_add_claims.sql (3.29ms)12952026/09/23 13:29:42 INFO Received complete push request method=POST path=/api/pushes/1/complete12962026/09/23 13:29:42 INFO Received uploads request method=POST path=/api/pending_closures12972026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (2.34ms)12982026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (1.99ms)12992026/09/23 13:29:42 goose: successfully migrated database to version: 2026092312000013002026/09/23 13:29:42 INFO Received push request method=POST path=/api/pushes13012026/09/23 13:29:42 OK 1_commit_pending_closure.sql (2.48ms)13022026/09/23 13:29:42 OK 2_object_stats_trigger.sql (863.93µs)13032026-09-23 13:29:42.608 UTC [710] ERROR: relation "goose_db_version" does not exist at character 3613042026-09-23 13:29:42.608 UTC [710] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13052026/09/23 13:29:42 OK 3_commit_push.sql (2.45ms)13062026/09/23 13:29:42 goose: up to current file version: 31307=== NAME TestOrphanedObjectsGC1308 orphaned_objects_gc_test.go:290: GC Test Summary:1309 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1310 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1311 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1312 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1313 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1314--- PASS: TestOrphanedObjectsGC (0.93s)1315=== CONT TestOrphanedObjectsGCStressTest13162026/09/23 13:29:42 INFO Received complete push request method=POST path=/api/pushes/2/complete13172026-09-23 13:29:42.616 UTC [709] ERROR: Push object missing: aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo13182026-09-23 13:29:42.616 UTC [709] CONTEXT: PL/pgSQL function commit_push(bigint) line 37 at RAISE13192026-09-23 13:29:42.616 UTC [709] STATEMENT: -- name: CommitPush :exec1320 SELECT commit_push($1::bigint)1321 1322--- PASS: TestPush_CommitFailsWhenSkippedKeyWasCollected (0.91s)1323=== CONT TestClientIntegration13242026/09/23 13:29:42 OK 20241026095416_initial_model.sql (8.73ms)13252026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (1.03ms)13262026/09/23 13:29:42 OK 20251218171726_add_pins.sql (2.54ms)13272026/09/23 13:29:42 INFO Received uploads request method=POST path=/api/pending_closures13282026-09-23 13:29:42.628 UTC [715] ERROR: relation "goose_db_version" does not exist at character 3613292026-09-23 13:29:42.628 UTC [715] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13302026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (2.83ms)13312026/09/23 13:29:42 OK 20260905000000_add_claims.sql (3.09ms)13322026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (3.19ms)13332026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (2.56ms)13342026/09/23 13:29:42 goose: successfully migrated database to version: 2026092312000013352026/09/23 13:29:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13362026/09/23 13:29:42 OK 1_commit_pending_closure.sql (3.94ms)13372026/09/23 13:29:42 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MDUzMGYyMGQtZGQ2MS00MzRmLWFkY2ItMDEwZGE0NjY5YTM5LjFhY2M5YTc1LWQ1MzMtNGY4My04MDI5LTc5Y2E1YmJiOTc4ZHgxNzkwMTcwMTgyNjEwNzQ4MDc213382026/09/23 13:29:42 OK 20241026095416_initial_model.sql (9.02ms)13392026/09/23 13:29:42 OK 2_object_stats_trigger.sql (2.41ms)13402026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (1.83ms)13412026/09/23 13:29:42 OK 3_commit_push.sql (1.6ms)13422026/09/23 13:29:42 goose: up to current file version: 313432026/09/23 13:29:42 OK 20251218171726_add_pins.sql (2.62ms)13442026/09/23 13:29:42 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MDUzMGYyMGQtZGQ2MS00MzRmLWFkY2ItMDEwZGE0NjY5YTM5LjFhY2M5YTc1LWQ1MzMtNGY4My04MDI5LTc5Y2E1YmJiOTc4ZHgxNzkwMTcwMTgyNjEwNzQ4MDc2 parts=11345--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.90s)1346=== CONT TestGCBugBareHashReferences13472026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (3.28ms)1348=== RUN TestPush_RejectsBadRequests/bad_root1349=== PAUSE TestPush_RejectsBadRequests/bad_root1350=== RUN TestPush_RejectsBadRequests/root_not_in_objects13512026/09/23 13:29:42 OK 20260905000000_add_claims.sql (2.94ms)1352=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1353=== RUN TestPush_RejectsBadRequests/no_roots1354=== PAUSE TestPush_RejectsBadRequests/no_roots1355=== RUN TestPush_RejectsBadRequests/no_objects1356=== PAUSE TestPush_RejectsBadRequests/no_objects1357=== CONT TestLeadEndsOnShutdown13582026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (2.4ms)13592026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (1.97ms)13602026/09/23 13:29:42 goose: successfully migrated database to version: 2026092312000013612026/09/23 13:29:42 OK 1_commit_pending_closure.sql (2.12ms)13622026/09/23 13:29:42 OK 2_object_stats_trigger.sql (1.66ms)13632026/09/23 13:29:42 OK 3_commit_push.sql (1.58ms)13642026/09/23 13:29:42 goose: up to current file version: 313652026/09/23 13:29:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13662026/09/23 13:29:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1367--- PASS: TestReadRedirectNar (0.94s)1368=== CONT TestLeadElectsOneAndHandsOver13692026/09/23 13:29:42 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MDUzMGYyMGQtZGQ2MS00MzRmLWFkY2ItMDEwZGE0NjY5YTM5LjE1ZmM5YjRjLTBlNmUtNDM1My04OWM3LWU1MjNhYWUwOTA3ZngxNzkwMTcwMTgyMTc5MTMxMTcw parts=1013702026/09/23 13:29:42 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13712026/09/23 13:29:42 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MDUzMGYyMGQtZGQ2MS00MzRmLWFkY2ItMDEwZGE0NjY5YTM5LmFmYmRjZTZhLWJlNjQtNDExMS1hZTRiLTkzZDNjMWJiMTk4Y3gxNzkwMTcwMTgyMTk5MjA0NTgz parts=1013722026/09/23 13:29:42 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13732026/09/23 13:29:42 INFO Completed upload id=113742026/09/23 13:29:42 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013752026/09/23 13:29:42 INFO Received uploads request method=POST path=/api/pending_closures13762026/09/23 13:29:42 INFO Completed upload id=113772026/09/23 13:29:42 INFO Starting cleanup of old closures method=DELETE path=/api/closures13782026/09/23 13:29:42 INFO Received uploads request method=POST path=/api/pending_closures13792026-09-23 13:29:42.712 UTC [734] ERROR: relation "goose_db_version" does not exist at character 3613802026-09-23 13:29:42.712 UTC [734] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1381--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.90s)1382=== CONT TestResolveDBConnectionString1383=== RUN TestResolveDBConnectionString/flag_wins1384=== PAUSE TestResolveDBConnectionString/flag_wins1385=== RUN TestResolveDBConnectionString/file_when_flag_empty13862026-09-23 13:29:42.716 UTC [735] ERROR: relation "goose_db_version" does not exist at character 3613872026-09-23 13:29:42.716 UTC [735] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1388=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1389=== RUN TestResolveDBConnectionString/missing_file_is_an_error1390=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1391=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1392=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1393=== RUN TestResolveDBConnectionString/nothing_configured1394=== PAUSE TestResolveDBConnectionString/nothing_configured1395=== CONT TestClientFallsBackToClosures13962026/09/23 13:29:42 INFO Aborted multipart uploads count=013972026/09/23 13:29:42 INFO Received uploads request method=POST path=/api/pending_closures13982026/09/23 13:29:42 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo13992026/09/23 13:29:42 WARN Found objects in DB but missing from S3, will re-upload count=11400--- PASS: TestService_verifyS3Integrity (1.04s)1401=== CONT TestClientPushesUseOnePush14022026/09/23 13:29:42 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=014032026/09/23 13:29:42 INFO Vacuumed table table=pending_closures14042026/09/23 13:29:42 OK 20241026095416_initial_model.sql (10.06ms)14052026/09/23 13:29:42 OK 20241026095416_initial_model.sql (11.28ms)14062026/09/23 13:29:42 INFO Vacuumed table table=pending_objects14072026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (2.4ms)14082026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (2.28ms)1409--- PASS: TestReadRedirectKeepsNarinfoProxied (0.99s)14102026/09/23 13:29:42 INFO Vacuumed table table=multipart_uploads1411=== CONT TestGCMetrics14122026/09/23 13:29:42 OK 20251218171726_add_pins.sql (3.17ms)14132026/09/23 13:29:42 OK 20251218171726_add_pins.sql (4.52ms)14142026/09/23 13:29:42 INFO Vacuumed table table=closures14152026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (4.69ms)14162026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (4.84ms)14172026/09/23 13:29:42 INFO Vacuumed table table=objects14182026/09/23 13:29:42 OK 20260905000000_add_claims.sql (3.87ms)14192026/09/23 13:29:42 OK 20260905000000_add_claims.sql (5.35ms)14202026-09-23 13:29:42.760 UTC [743] ERROR: relation "goose_db_version" does not exist at character 3614212026-09-23 13:29:42.760 UTC [743] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14222026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (3.2ms)14232026/09/23 13:29:42 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001424--- PASS: TestService_createPendingClosureHandler (1.07s)1425=== CONT TestPinProtectsFromGC14262026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (3.15ms)14272026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (1.86ms)14282026/09/23 13:29:42 goose: successfully migrated database to version: 2026092312000014292026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (2.21ms)14302026/09/23 13:29:42 goose: successfully migrated database to version: 2026092312000014312026/09/23 13:29:42 OK 1_commit_pending_closure.sql (2.69ms)14322026/09/23 13:29:42 OK 1_commit_pending_closure.sql (2.77ms)14332026/09/23 13:29:42 OK 2_object_stats_trigger.sql (2.28ms)14342026/09/23 13:29:42 OK 2_object_stats_trigger.sql (1.74ms)14352026-09-23 13:29:42.770 UTC [745] ERROR: relation "goose_db_version" does not exist at character 3614362026-09-23 13:29:42.770 UTC [745] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14372026/09/23 13:29:42 OK 3_commit_push.sql (2.08ms)14382026/09/23 13:29:42 goose: up to current file version: 314392026/09/23 13:29:42 OK 3_commit_push.sql (1.95ms)14402026/09/23 13:29:42 goose: up to current file version: 314412026/09/23 13:29:42 INFO Received push request method=POST path=/api/pushes14422026/09/23 13:29:42 OK 20241026095416_initial_model.sql (10.13ms)14432026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (1.89ms)14442026/09/23 13:29:42 OK 20251218171726_add_pins.sql (3.43ms)14452026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (4.53ms)14462026-09-23 13:29:42.794 UTC [747] ERROR: relation "goose_db_version" does not exist at character 3614472026-09-23 13:29:42.794 UTC [747] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14482026/09/23 13:29:42 OK 20241026095416_initial_model.sql (17.28ms)14492026/09/23 13:29:42 OK 20260905000000_add_claims.sql (14.2ms)14502026/09/23 13:29:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14512026/09/23 13:29:42 INFO Signed narinfos id=1 count=114522026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (10.53ms)1453--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (1.10s)1454=== CONT TestObjectStatsTrigger14552026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (7.62ms)14562026/09/23 13:29:42 INFO Received uploads request method=POST path=/api/pending_closures14572026/09/23 13:29:42 OK 20251218171726_add_pins.sql (5.76ms)14582026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (8.37ms)14592026/09/23 13:29:42 goose: successfully migrated database to version: 2026092312000014602026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (12.2ms)14612026/09/23 13:29:42 OK 20241026095416_initial_model.sql (17.85ms)14622026/09/23 13:29:42 OK 1_commit_pending_closure.sql (13.14ms)14632026/09/23 13:29:42 OK 20260905000000_add_claims.sql (13.88ms)14642026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (13.97ms)14652026/09/23 13:29:42 OK 2_object_stats_trigger.sql (12.39ms)14662026/09/23 13:29:42 OK 20251218171726_add_pins.sql (13.71ms)14672026/09/23 13:29:42 OK 3_commit_push.sql (10.41ms)14682026/09/23 13:29:42 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst14692026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (15.49ms)14702026/09/23 13:29:42 INFO Received uploads request method=POST path=/api/pending_closures14712026/09/23 13:29:42 goose: up to current file version: 314722026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (3.97ms)1473--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.11s)1474=== CONT TestClientSharedPathCommittedMidPush14752026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (3.21ms)14762026-09-23 13:29:42.858 UTC [751] ERROR: relation "goose_db_version" does not exist at character 3614772026-09-23 13:29:42.858 UTC [751] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14782026/09/23 13:29:42 goose: successfully migrated database to version: 2026092312000014792026-09-23 13:29:42.858 UTC [750] ERROR: relation "goose_db_version" does not exist at character 3614802026-09-23 13:29:42.858 UTC [750] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14812026/09/23 13:29:42 OK 1_commit_pending_closure.sql (3.73ms)14822026/09/23 13:29:42 OK 20260905000000_add_claims.sql (4.97ms)14832026/09/23 13:29:42 OK 2_object_stats_trigger.sql (2.17ms)14842026-09-23 13:29:42.864 UTC [753] ERROR: relation "goose_db_version" does not exist at character 3614852026-09-23 13:29:42.864 UTC [753] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14862026-09-23 13:29:42.865 UTC [754] ERROR: relation "goose_db_version" does not exist at character 3614872026-09-23 13:29:42.865 UTC [754] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14882026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (3.27ms)14892026/09/23 13:29:42 OK 3_commit_push.sql (1.33ms)14902026/09/23 13:29:42 goose: up to current file version: 314912026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (2.55ms)14922026/09/23 13:29:42 goose: successfully migrated database to version: 2026092312000014932026/09/23 13:29:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39155/oidc14942026/09/23 13:29:42 OK 1_commit_pending_closure.sql (2.71ms)14952026/09/23 13:29:42 OK 20241026095416_initial_model.sql (8.42ms)14962026/09/23 13:29:42 OK 2_object_stats_trigger.sql (1.87ms)14972026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (1.73ms)14982026/09/23 13:29:42 OK 3_commit_push.sql (1.78ms)14992026/09/23 13:29:42 goose: up to current file version: 315002026/09/23 13:29:42 OK 20241026095416_initial_model.sql (11.73ms)15012026/09/23 13:29:42 OK 20251218171726_add_pins.sql (3.48ms)1502--- PASS: TestReadProxyConditionalGet (0.67s)1503=== CONT TestMultipartCleanup15042026/09/23 13:29:42 OK 20241026095416_initial_model.sql (8.92ms)15052026/09/23 13:29:42 OK 20241026095416_initial_model.sql (9.06ms)15062026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (1.7ms)15072026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (3.59ms)15082026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (2.9ms)15092026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (1.79ms)15102026/09/23 13:29:42 OK 20251218171726_add_pins.sql (3.67ms)15112026/09/23 13:29:42 OK 20251218171726_add_pins.sql (3.62ms)15122026/09/23 13:29:42 OK 20251218171726_add_pins.sql (4.72ms)15132026/09/23 13:29:42 OK 20260905000000_add_claims.sql (4.54ms)15142026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (2.71ms)15152026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (4.22ms)15162026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (4.34ms)15172026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (4.31ms)15182026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (2.59ms)15192026/09/23 13:29:42 goose: successfully migrated database to version: 2026092312000015202026/09/23 13:29:42 OK 20260905000000_add_claims.sql (3.39ms)15212026/09/23 13:29:42 OK 20260905000000_add_claims.sql (3.19ms)15222026/09/23 13:29:42 OK 1_commit_pending_closure.sql (2.63ms)15232026/09/23 13:29:42 OK 20260905000000_add_claims.sql (4.03ms)15242026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (2.4ms)15252026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (2.58ms)15262026/09/23 13:29:42 OK 2_object_stats_trigger.sql (2.1ms)15272026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (2.72ms)15282026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (10.1ms)15292026/09/23 13:29:42 goose: successfully migrated database to version: 2026092312000015302026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (10.81ms)15312026/09/23 13:29:42 goose: successfully migrated database to version: 2026092312000015322026/09/23 13:29:42 OK 3_commit_push.sql (11.51ms)15332026/09/23 13:29:42 goose: up to current file version: 31534--- PASS: TestReadProxyHead (0.68s)15352026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (11.83ms)1536=== CONT TestClientWithDependencies15372026/09/23 13:29:42 goose: successfully migrated database to version: 2026092312000015382026/09/23 13:29:42 OK 1_commit_pending_closure.sql (4.12ms)15392026/09/23 13:29:42 OK 1_commit_pending_closure.sql (2.58ms)15402026/09/23 13:29:42 OK 2_object_stats_trigger.sql (2.7ms)15412026/09/23 13:29:42 OK 1_commit_pending_closure.sql (3.51ms)15422026/09/23 13:29:42 OK 2_object_stats_trigger.sql (3.02ms)15432026/09/23 13:29:42 OK 3_commit_push.sql (4ms)15442026/09/23 13:29:42 goose: up to current file version: 315452026/09/23 13:29:42 OK 2_object_stats_trigger.sql (3.84ms)15462026/09/23 13:29:42 OK 3_commit_push.sql (2.45ms)15472026/09/23 13:29:42 goose: up to current file version: 315482026/09/23 13:29:42 OK 3_commit_push.sql (1.79ms)15492026/09/23 13:29:42 goose: up to current file version: 31550--- PASS: TestReadProxyInvalidPath (0.63s)1551=== CONT TestServerTLSConfig1552=== RUN TestServerTLSConfig/no_client_CA1553=== PAUSE TestServerTLSConfig/no_client_CA1554=== RUN TestServerTLSConfig/missing_CA_file1555=== PAUSE TestServerTLSConfig/missing_CA_file1556=== RUN TestServerTLSConfig/not_a_PEM_file1557=== PAUSE TestServerTLSConfig/not_a_PEM_file1558=== CONT TestClientMultipleUploads15592026-09-23 13:29:42.951 UTC [764] ERROR: relation "goose_db_version" does not exist at character 3615602026-09-23 13:29:42.951 UTC [764] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15612026-09-23 13:29:42.960 UTC [765] ERROR: relation "goose_db_version" does not exist at character 3615622026-09-23 13:29:42.960 UTC [765] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1563--- PASS: TestReadProxy404 (0.62s)1564=== CONT TestService_NativeMTLS15652026/09/23 13:29:42 OK 20241026095416_initial_model.sql (9.41ms)15662026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (1.81ms)15672026-09-23 13:29:42.973 UTC [767] ERROR: relation "goose_db_version" does not exist at character 3615682026-09-23 13:29:42.973 UTC [767] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15692026/09/23 13:29:42 OK 20251218171726_add_pins.sql (11.01ms)15702026/09/23 13:29:42 OK 20241026095416_initial_model.sql (17.36ms)15712026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (3.69ms)15722026/09/23 13:29:42 OK 20251210153512_drop_unused_gin_index.sql (2.23ms)15732026/09/23 13:29:42 OK 20260905000000_add_claims.sql (3.76ms)15742026/09/23 13:29:42 OK 20251218171726_add_pins.sql (4.02ms)15752026/09/23 13:29:42 OK 20260920000000_drop_claims.sql (3.13ms)15762026/09/23 13:29:42 OK 20260923120000_add_pushes.sql (2.83ms)15772026/09/23 13:29:42 goose: successfully migrated database to version: 2026092312000015782026/09/23 13:29:42 OK 20260628120000_add_object_size_and_stats.sql (6.08ms)15792026-09-23 13:29:42.997 UTC [769] ERROR: relation "goose_db_version" does not exist at character 3615802026-09-23 13:29:42.997 UTC [769] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15812026/09/23 13:29:42 OK 20241026095416_initial_model.sql (12.25ms)15822026/09/23 13:29:42 OK 1_commit_pending_closure.sql (3.36ms)15832026/09/23 13:29:43 OK 20260905000000_add_claims.sql (3.46ms)15842026/09/23 13:29:43 OK 20251210153512_drop_unused_gin_index.sql (3.58ms)15852026/09/23 13:29:43 OK 2_object_stats_trigger.sql (2.18ms)1586--- PASS: TestReadProxyNarStreaming (0.62s)1587=== CONT TestService_ReadScope_PublicByDefault15882026/09/23 13:29:43 OK 20260920000000_drop_claims.sql (2.52ms)15892026/09/23 13:29:43 OK 3_commit_push.sql (1.79ms)15902026/09/23 13:29:43 goose: up to current file version: 315912026/09/23 13:29:43 OK 20251218171726_add_pins.sql (3.56ms)15922026/09/23 13:29:43 OK 20260923120000_add_pushes.sql (1.97ms)15932026/09/23 13:29:43 goose: successfully migrated database to version: 2026092312000015942026/09/23 13:29:43 OK 20260628120000_add_object_size_and_stats.sql (5.34ms)15952026/09/23 13:29:43 OK 1_commit_pending_closure.sql (4.27ms)15962026/09/23 13:29:43 OK 2_object_stats_trigger.sql (1.73ms)15972026/09/23 13:29:43 OK 20241026095416_initial_model.sql (10.15ms)15982026/09/23 13:29:43 OK 3_commit_push.sql (2.13ms)15992026/09/23 13:29:43 goose: up to current file version: 316002026/09/23 13:29:43 OK 20260905000000_add_claims.sql (4.35ms)16012026/09/23 13:29:43 OK 20251210153512_drop_unused_gin_index.sql (2.1ms)16022026/09/23 13:29:43 OK 20260920000000_drop_claims.sql (2.48ms)16032026/09/23 13:29:43 OK 20251218171726_add_pins.sql (2.98ms)16042026-09-23 13:29:43.019 UTC [772] ERROR: relation "goose_db_version" does not exist at character 3616052026-09-23 13:29:43.019 UTC [772] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16062026/09/23 13:29:43 OK 20260923120000_add_pushes.sql (2.59ms)16072026/09/23 13:29:43 goose: successfully migrated database to version: 2026092312000016082026/09/23 13:29:43 OK 20260628120000_add_object_size_and_stats.sql (3.4ms)16092026/09/23 13:29:43 OK 1_commit_pending_closure.sql (3.03ms)16102026/09/23 13:29:43 OK 2_object_stats_trigger.sql (2.34ms)16112026/09/23 13:29:43 OK 20260905000000_add_claims.sql (4.06ms)16122026/09/23 13:29:43 OK 3_commit_push.sql (1.34ms)16132026/09/23 13:29:43 goose: up to current file version: 316142026/09/23 13:29:43 OK 20260920000000_drop_claims.sql (1.67ms)16152026/09/23 13:29:43 OK 20260923120000_add_pushes.sql (2.22ms)16162026/09/23 13:29:43 goose: successfully migrated database to version: 2026092312000016172026/09/23 13:29:43 OK 1_commit_pending_closure.sql (2.43ms)16182026/09/23 13:29:43 OK 20241026095416_initial_model.sql (9.55ms)16192026/09/23 13:29:43 OK 2_object_stats_trigger.sql (2.22ms)16202026-09-23 13:29:43.036 UTC [773] ERROR: relation "goose_db_version" does not exist at character 3616212026-09-23 13:29:43.036 UTC [773] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1622--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.60s)1623=== CONT TestMetricsInventory16242026/09/23 13:29:43 OK 20251210153512_drop_unused_gin_index.sql (2.41ms)16252026/09/23 13:29:43 OK 3_commit_push.sql (2.03ms)16262026/09/23 13:29:43 goose: up to current file version: 316272026/09/23 13:29:43 OK 20251218171726_add_pins.sql (2.84ms)16282026/09/23 13:29:43 OK 20260628120000_add_object_size_and_stats.sql (3.36ms)16292026/09/23 13:29:43 OK 20260905000000_add_claims.sql (2.93ms)16302026/09/23 13:29:43 OK 20260920000000_drop_claims.sql (3.44ms)16312026/09/23 13:29:43 OK 20241026095416_initial_model.sql (8.72ms)16322026/09/23 13:29:43 OK 20251210153512_drop_unused_gin_index.sql (2.14ms)16332026/09/23 13:29:43 OK 20260923120000_add_pushes.sql (3.19ms)16342026/09/23 13:29:43 goose: successfully migrated database to version: 2026092312000016352026/09/23 13:29:43 OK 20251218171726_add_pins.sql (2.85ms)16362026/09/23 13:29:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16372026/09/23 13:29:43 OK 1_commit_pending_closure.sql (2.76ms)16382026/09/23 13:29:43 OK 2_object_stats_trigger.sql (1.59ms)16392026/09/23 13:29:43 OK 20260628120000_add_object_size_and_stats.sql (3.97ms)16402026/09/23 13:29:43 OK 3_commit_push.sql (2.38ms)16412026/09/23 13:29:43 goose: up to current file version: 316422026/09/23 13:29:43 OK 20260905000000_add_claims.sql (3.1ms)16432026/09/23 13:29:43 OK 20260920000000_drop_claims.sql (2.45ms)16442026/09/23 13:29:43 OK 20260923120000_add_pushes.sql (2.35ms)16452026/09/23 13:29:43 goose: successfully migrated database to version: 2026092312000016462026-09-23 13:29:43.070 UTC [776] ERROR: relation "goose_db_version" does not exist at character 3616472026-09-23 13:29:43.070 UTC [776] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16482026/09/23 13:29:43 OK 1_commit_pending_closure.sql (2.36ms)1649--- PASS: TestReadProxyNarinfo (0.60s)1650=== CONT TestClientErrorHandling1651=== RUN TestClientErrorHandling/InvalidStorePath1652=== PAUSE TestClientErrorHandling/InvalidStorePath1653=== RUN TestClientErrorHandling/InvalidAuthToken1654=== PAUSE TestClientErrorHandling/InvalidAuthToken1655=== RUN TestClientErrorHandling/ServerNotAvailable1656=== PAUSE TestClientErrorHandling/ServerNotAvailable1657=== CONT TestClientCADerivations16582026/09/23 13:29:43 OK 2_object_stats_trigger.sql (1.62ms)16592026/09/23 13:29:43 OK 3_commit_push.sql (1.64ms)16602026/09/23 13:29:43 goose: up to current file version: 316612026/09/23 13:29:43 INFO Starting HTTP server address=127.0.0.1:4152516622026/09/23 13:29:43 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket1204809553/001/proxy.sock16632026/09/23 13:29:43 WARN mTLS auth: subject not in bound subjects subject="CN=someone"16642026/09/23 13:29:43 INFO Shutdown signal received, draining in-flight requests timeout=10s1665--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.59s)1666=== CONT TestNARDeduplicationMetadataUploadBug16672026/09/23 13:29:43 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MDUzMGYyMGQtZGQ2MS00MzRmLWFkY2ItMDEwZGE0NjY5YTM5LmE2ODZlNDkwLTVjOTctNGE0MC1hMzg0LTUxMDcxZWZkNTE2NngxNzkwMTcwMTgyNDAzMTU1ODc2 parts=1216682026/09/23 13:29:43 OK 20241026095416_initial_model.sql (10.2ms)1669--- PASS: TestRedundantMultipartUpload (1.40s)1670=== CONT TestCreatePendingClosureRejectsOversizedNAR16712026/09/23 13:29:43 INFO Received uploads request method=POST path=/api/pending_closures1672--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)16732026-09-23 13:29:43.099 UTC [779] ERROR: relation "goose_db_version" does not exist at character 3616742026-09-23 13:29:43.099 UTC [779] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1675=== CONT TestCacheStatsHandler16762026/09/23 13:29:43 OK 20251210153512_drop_unused_gin_index.sql (2.19ms)16772026/09/23 13:29:43 OK 20251218171726_add_pins.sql (3.16ms)16782026/09/23 13:29:43 OK 20260628120000_add_object_size_and_stats.sql (4.8ms)16792026/09/23 13:29:43 OK 20260905000000_add_claims.sql (6ms)16802026/09/23 13:29:43 OK 20241026095416_initial_model.sql (10.93ms)16812026/09/23 13:29:43 OK 20260920000000_drop_claims.sql (3.06ms)16822026/09/23 13:29:43 OK 20251210153512_drop_unused_gin_index.sql (2.27ms)16832026/09/23 13:29:43 OK 20260923120000_add_pushes.sql (1.9ms)16842026/09/23 13:29:43 goose: successfully migrated database to version: 2026092312000016852026/09/23 13:29:43 OK 20251218171726_add_pins.sql (2.51ms)16862026/09/23 13:29:43 OK 1_commit_pending_closure.sql (2.06ms)16872026/09/23 13:29:43 OK 2_object_stats_trigger.sql (1.96ms)16882026/09/23 13:29:43 OK 20260628120000_add_object_size_and_stats.sql (4.47ms)16892026/09/23 13:29:43 OK 3_commit_push.sql (2.56ms)16902026/09/23 13:29:43 goose: up to current file version: 316912026-09-23 13:29:43.128 UTC [784] ERROR: relation "goose_db_version" does not exist at character 3616922026-09-23 13:29:43.128 UTC [784] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16932026/09/23 13:29:43 OK 20260905000000_add_claims.sql (2.99ms)16942026/09/23 13:29:43 OK 20260920000000_drop_claims.sql (2.61ms)16952026/09/23 13:29:43 OK 20260923120000_add_pushes.sql (2.68ms)16962026/09/23 13:29:43 goose: successfully migrated database to version: 2026092312000016972026/09/23 13:29:43 OK 1_commit_pending_closure.sql (2.45ms)16982026/09/23 13:29:43 OK 2_object_stats_trigger.sql (1.6ms)16992026/09/23 13:29:43 OK 3_commit_push.sql (1.52ms)17002026/09/23 13:29:43 goose: up to current file version: 317012026/09/23 13:29:43 OK 20241026095416_initial_model.sql (8.77ms)17022026/09/23 13:29:43 OK 20251210153512_drop_unused_gin_index.sql (1.85ms)17032026/09/23 13:29:43 OK 20251218171726_add_pins.sql (3.29ms)17042026/09/23 13:29:43 OK 20260628120000_add_object_size_and_stats.sql (3.7ms)17052026/09/23 13:29:43 OK 20260905000000_add_claims.sql (3.3ms)17062026/09/23 13:29:43 OK 20260920000000_drop_claims.sql (2.49ms)17072026/09/23 13:29:43 OK 20260923120000_add_pushes.sql (2.57ms)17082026/09/23 13:29:43 goose: successfully migrated database to version: 2026092312000017092026/09/23 13:29:43 OK 1_commit_pending_closure.sql (2.28ms)17102026/09/23 13:29:43 OK 2_object_stats_trigger.sql (1.43ms)17112026/09/23 13:29:43 OK 3_commit_push.sql (1.62ms)17122026/09/23 13:29:43 goose: up to current file version: 317132026-09-23 13:29:43.172 UTC [785] ERROR: relation "goose_db_version" does not exist at character 3617142026-09-23 13:29:43.172 UTC [785] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1715--- PASS: TestResurrectedObjectNotDeleted (0.66s)17162026/09/23 13:29:43 OK 20241026095416_initial_model.sql (19.08ms)1717=== CONT TestCacheConfigHandlerMaxNarSize1718--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1719=== CONT TestCacheConfigHandler1720=== RUN TestCacheConfigHandler/full_config,_no_issuer1721=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1722=== RUN TestCacheConfigHandler/no_cache_url_configured1723=== PAUSE TestCacheConfigHandler/no_cache_url_configured1724=== RUN TestCacheConfigHandler/no_signing_keys1725=== PAUSE TestCacheConfigHandler/no_signing_keys1726=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1727=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1728=== CONT TestGenerateLandingPage17292026/09/23 13:29:43 OK 20251210153512_drop_unused_gin_index.sql (1.15ms)1730--- PASS: TestGenerateLandingPage (0.00s)1731=== CONT TestService_ReadAuthMiddleware17322026/09/23 13:29:43 OK 20251218171726_add_pins.sql (2.18ms)17332026/09/23 13:29:43 OK 20260628120000_add_object_size_and_stats.sql (2.27ms)17342026/09/23 13:29:43 OK 20260905000000_add_claims.sql (2.15ms)17352026-09-23 13:29:43.206 UTC [788] ERROR: relation "goose_db_version" does not exist at character 3617362026-09-23 13:29:43.206 UTC [788] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17372026-09-23 13:29:43.206 UTC [789] ERROR: relation "goose_db_version" does not exist at character 3617382026-09-23 13:29:43.206 UTC [789] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17392026/09/23 13:29:43 OK 20260920000000_drop_claims.sql (1.74ms)17402026/09/23 13:29:43 OK 20260923120000_add_pushes.sql (1.08ms)17412026/09/23 13:29:43 goose: successfully migrated database to version: 2026092312000017422026/09/23 13:29:43 OK 1_commit_pending_closure.sql (1.99ms)17432026/09/23 13:29:43 OK 2_object_stats_trigger.sql (824.82µs)17442026/09/23 13:29:43 OK 3_commit_push.sql (2.38ms)17452026/09/23 13:29:43 goose: up to current file version: 317462026/09/23 13:29:43 OK 20241026095416_initial_model.sql (9.17ms)17472026/09/23 13:29:43 OK 20241026095416_initial_model.sql (9.23ms)17482026/09/23 13:29:43 OK 20251210153512_drop_unused_gin_index.sql (1.48ms)17492026/09/23 13:29:43 OK 20251210153512_drop_unused_gin_index.sql (2.16ms)17502026/09/23 13:29:43 OK 20251218171726_add_pins.sql (3.58ms)17512026/09/23 13:29:43 OK 20251218171726_add_pins.sql (4.41ms)17522026/09/23 13:29:43 OK 20260628120000_add_object_size_and_stats.sql (3.28ms)17532026/09/23 13:29:43 OK 20260628120000_add_object_size_and_stats.sql (3.99ms)17542026/09/23 13:29:43 OK 20260905000000_add_claims.sql (2.64ms)1755=== NAME TestClientIntegration1756 client_integration_test.go:286: Created store path: /build/TestClientIntegration1245664881/002/store/hmqyqk213jzjx1q0gkjfaasgv5ahdxlq-test-file.txt17572026/09/23 13:29:43 OK 20260905000000_add_claims.sql (2.78ms)17582026/09/23 13:29:43 OK 20260920000000_drop_claims.sql (2.46ms)17592026/09/23 13:29:43 OK 20260920000000_drop_claims.sql (1.73ms)17602026/09/23 13:29:43 OK 20260923120000_add_pushes.sql (2.15ms)17612026/09/23 13:29:43 goose: successfully migrated database to version: 2026092312000017622026/09/23 13:29:43 OK 20260923120000_add_pushes.sql (2.9ms)17632026/09/23 13:29:43 goose: successfully migrated database to version: 2026092312000017642026/09/23 13:29:43 OK 1_commit_pending_closure.sql (2.44ms)17652026/09/23 13:29:43 OK 1_commit_pending_closure.sql (2.19ms)17662026/09/23 13:29:43 OK 2_object_stats_trigger.sql (857µs)17672026/09/23 13:29:43 OK 2_object_stats_trigger.sql (788.62µs)17682026/09/23 13:29:43 OK 3_commit_push.sql (1.44ms)17692026/09/23 13:29:43 goose: up to current file version: 317702026/09/23 13:29:43 OK 3_commit_push.sql (1.36ms)17712026/09/23 13:29:43 goose: up to current file version: 317722026/09/23 13:29:43 INFO lead: acquired remote=192.0.2.1:123417732026/09/23 13:29:43 INFO lead: released remote=192.0.2.1:12341774--- PASS: TestLeadEndsOnShutdown (0.59s)1775=== CONT TestService_RequireScope_OIDC17762026/09/23 13:29:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17772026-09-23 13:29:43.276 UTC [827] ERROR: relation "goose_db_version" does not exist at character 3617782026-09-23 13:29:43.276 UTC [827] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17792026/09/23 13:29:43 INFO lead: acquired remote=192.0.2.1:123417802026/09/23 13:29:43 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MDUzMGYyMGQtZGQ2MS00MzRmLWFkY2ItMDEwZGE0NjY5YTM5LjZkNWRhNGJkLTRjZjctNGQ3Zi05MmEwLWU3YTVmYzI0OWJiOXgxNzkwMTcwMTgyNjM2MjQ2NzY1 parts=1217812026/09/23 13:29:43 INFO Received uploads request method=POST path=/api/pending_closures1782--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.54s)1783=== CONT TestService_readinessHandler17842026/09/23 13:29:43 OK 20241026095416_initial_model.sql (7.23ms)17852026/09/23 13:29:43 OK 20251210153512_drop_unused_gin_index.sql (1.02ms)17862026/09/23 13:29:43 OK 20251218171726_add_pins.sql (2.43ms)17872026/09/23 13:29:43 OK 20260628120000_add_object_size_and_stats.sql (2.18ms)17882026/09/23 13:29:43 OK 20260905000000_add_claims.sql (2.39ms)17892026/09/23 13:29:43 OK 20260920000000_drop_claims.sql (1.67ms)17902026/09/23 13:29:43 OK 20260923120000_add_pushes.sql (1.88ms)17912026/09/23 13:29:43 goose: successfully migrated database to version: 2026092312000017922026/09/23 13:29:43 OK 1_commit_pending_closure.sql (2.47ms)17932026/09/23 13:29:43 OK 2_object_stats_trigger.sql (1.67ms)17942026/09/23 13:29:43 OK 3_commit_push.sql (1.71ms)17952026/09/23 13:29:43 goose: up to current file version: 317962026/09/23 13:29:43 INFO Received uploads request method=POST path=/api/pending_closures17972026/09/23 13:29:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17982026/09/23 13:29:43 INFO Uploading hmqyqk213jzjx1q0gkjfaasgv5ahdxlq-test-file.txt (152B)17992026/09/23 13:29:43 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"18002026/09/23 13:29:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18012026/09/23 13:29:43 WARN Failed to register uploaded object key=hmqyqk213jzjx1q0gkjfaasgv5ahdxlq.ls error="server returned 404: 404 page not found\n"18022026/09/23 13:29:43 INFO Signed narinfos id=1 count=118032026/09/23 13:29:43 INFO Uploading 1 narinfos18042026/09/23 13:29:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18052026/09/23 13:29:43 WARN Failed to register uploaded object key=hmqyqk213jzjx1q0gkjfaasgv5ahdxlq.narinfo error="server returned 404: 404 page not found\n"18062026/09/23 13:29:43 INFO Aborted multipart uploads count=018072026/09/23 13:29:43 INFO Completed upload id=118082026/09/23 13:29:43 INFO Upload complete. (72ms)18092026/09/23 13:29:43 WARN Force mode enabled - objects will be deleted immediately without grace period18102026/09/23 13:29:43 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=018112026/09/23 13:29:43 INFO Vacuumed table table=pending_closures18122026/09/23 13:29:43 INFO Vacuumed table table=pending_objects18132026/09/23 13:29:43 INFO Vacuumed table table=multipart_uploads18142026/09/23 13:29:43 INFO Vacuumed table table=closures18152026/09/23 13:29:43 INFO Vacuumed table table=objects18162026/09/23 13:29:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38893/oidc1817--- PASS: TestGCMetrics (0.61s)1818=== CONT TestService_healthCheckHandler18192026-09-23 13:29:43.360 UTC [870] ERROR: relation "goose_db_version" does not exist at character 3618202026-09-23 13:29:43.360 UTC [870] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18212026/09/23 13:29:43 OK 20241026095416_initial_model.sql (7.2ms)18222026/09/23 13:29:43 OK 20251210153512_drop_unused_gin_index.sql (1.69ms)18232026/09/23 13:29:43 OK 20251218171726_add_pins.sql (2.91ms)18242026/09/23 13:29:43 INFO All 1 paths already cached18252026/09/23 13:29:43 OK 20260628120000_add_object_size_and_stats.sql (3.17ms)1826=== NAME TestClientIntegration1827 client_integration_test.go:312: Retrieved narinfo from S3:1828 StorePath: /build/TestClientIntegration1245664881/002/store/hmqyqk213jzjx1q0gkjfaasgv5ahdxlq-test-file.txt1829 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1830 Compression: zstd1831 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11832 NarSize: 1521833 References: 1834 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk118352026/09/23 13:29:43 OK 20260905000000_add_claims.sql (2.86ms)1836 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1837 client_integration_test.go:313: Decompressed .ls content (64 bytes):1838 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1839 client_integration_test.go:316: Testing garbage collection...18402026/09/23 13:29:43 OK 20260920000000_drop_claims.sql (2.27ms)18412026/09/23 13:29:43 OK 20260923120000_add_pushes.sql (2.05ms)18422026/09/23 13:29:43 goose: successfully migrated database to version: 2026092312000018432026/09/23 13:29:43 OK 1_commit_pending_closure.sql (2.09ms)18442026/09/23 13:29:43 OK 2_object_stats_trigger.sql (758.04µs)18452026/09/23 13:29:43 OK 3_commit_push.sql (863.83µs)18462026/09/23 13:29:43 goose: up to current file version: 318472026/09/23 13:29:43 INFO Starting cleanup of old closures method=DELETE path=/api/closures18482026/09/23 13:29:43 INFO Garbage collection started18492026/09/23 13:29:43 INFO lead: released remote=192.0.2.1:123418502026/09/23 13:29:43 INFO Aborted multipart uploads count=018512026/09/23 13:29:43 WARN Force mode enabled - objects will be deleted immediately without grace period1852--- PASS: TestObjectStatsTrigger (0.64s)1853=== CONT TestService_AuthMiddleware_OIDC18542026-09-23 13:29:43.451 UTC [998] ERROR: relation "goose_db_version" does not exist at character 3618552026-09-23 13:29:43.451 UTC [998] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18562026-09-23 13:29:43.452 UTC [999] ERROR: relation "goose_db_version" does not exist at character 3618572026-09-23 13:29:43.452 UTC [999] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1858--- PASS: TestGCBugBareHashReferences (0.80s)1859=== CONT TestGracefulShutdownDrainsInflight18602026/09/23 13:29:43 INFO Starting HTTP server address=127.0.0.1:4209118612026/09/23 13:29:43 INFO Shutdown signal received, draining in-flight requests timeout=10s1862=== NAME TestPinProtectsFromGC1863 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC1019887588/001/store/dvycpdg4n5f6fhq36il1cd7nazfvzp35-pinned-file.txt1864 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC1019887588/001/store/xsgwxssnh97fk61lrii7pvx27n17cgqz-unpinned-file.txt18652026/09/23 13:29:43 OK 20241026095416_initial_model.sql (7.67ms)18662026/09/23 13:29:43 OK 20241026095416_initial_model.sql (7.4ms)18672026/09/23 13:29:43 OK 20251210153512_drop_unused_gin_index.sql (1.27ms)18682026/09/23 13:29:43 OK 20251210153512_drop_unused_gin_index.sql (1.57ms)18692026/09/23 13:29:43 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18702026/09/23 13:29:43 WARN Refused reserved pin name=worker-x86_64-linux18712026/09/23 13:29:43 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18722026/09/23 13:29:43 INFO Received create pin request method=POST path=/api/pins/my-app18732026/09/23 13:29:43 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1874--- PASS: TestCreatePin_ReservedPins (0.93s)1875=== CONT TestService_AuthMiddleware_MTLSBoundSubjects18762026/09/23 13:29:43 OK 20251218171726_add_pins.sql (1.88ms)18772026/09/23 13:29:43 OK 20251218171726_add_pins.sql (3.07ms)18782026/09/23 13:29:43 OK 20260628120000_add_object_size_and_stats.sql (2.32ms)18792026/09/23 13:29:43 OK 20260628120000_add_object_size_and_stats.sql (3.08ms)18802026/09/23 13:29:43 OK 20260905000000_add_claims.sql (2.94ms)18812026/09/23 13:29:43 OK 20260920000000_drop_claims.sql (1.65ms)18822026/09/23 13:29:43 OK 20260905000000_add_claims.sql (2.19ms)18832026/09/23 13:29:43 OK 20260923120000_add_pushes.sql (1.55ms)18842026/09/23 13:29:43 goose: successfully migrated database to version: 2026092312000018852026/09/23 13:29:43 OK 20260920000000_drop_claims.sql (1.72ms)18862026/09/23 13:29:43 INFO lead: acquired remote=192.0.2.1:123418872026/09/23 13:29:43 OK 20260923120000_add_pushes.sql (1.88ms)18882026/09/23 13:29:43 goose: successfully migrated database to version: 2026092312000018892026/09/23 13:29:43 OK 1_commit_pending_closure.sql (3.12ms)18902026/09/23 13:29:43 OK 1_commit_pending_closure.sql (1.42ms)18912026/09/23 13:29:43 OK 2_object_stats_trigger.sql (897.83µs)18922026/09/23 13:29:43 INFO Received uploads request method=POST path=/api/pending_closures18932026/09/23 13:29:43 OK 2_object_stats_trigger.sql (998.91µs)18942026/09/23 13:29:43 OK 3_commit_push.sql (1.13ms)18952026/09/23 13:29:43 goose: up to current file version: 318962026/09/23 13:29:43 INFO lead: released remote=192.0.2.1:12341897--- PASS: TestLeadElectsOneAndHandsOver (0.79s)1898=== CONT TestGCTaskStore_Fail1899--- PASS: TestGCTaskStore_Fail (0.00s)1900=== CONT TestGCTaskStore_PhaseUpdates1901--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1902=== CONT TestGCTaskStore_CompletedAllowsNewTask1903--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1904=== CONT TestService_AuthMiddleware_MTLSProxyHeader19052026/09/23 13:29:43 OK 3_commit_push.sql (1.3ms)19062026/09/23 13:29:43 goose: up to current file version: 319072026/09/23 13:29:43 INFO Received uploads request method=POST path=/api/pending_closures19082026/09/23 13:29:43 INFO Received uploads request method=POST path=/api/pending_closures19092026/09/23 13:29:43 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)19102026/09/23 13:29:43 INFO Uploading dllk9l99a4dsnmaxbsb5yvzz3qmqa5w7-a (216B)19112026/09/23 13:29:43 INFO Uploading a2cal9dkabw2j0jkm7gb27vqr6lb33ql-shared-dep (136B)19122026/09/23 13:29:43 WARN Failed to register uploaded object key=4d2qqq8q5zn5yjrhvd84y31y4b8rm5qs.ls error="server returned 404: 404 page not found\n"19132026/09/23 13:29:43 WARN Failed to register uploaded object key=nar/0d90vlh8bsp1zx44spamgpmd157fn7z8yb429p4rklqiwyrf7kb0.nar.zst error="server returned 404: 404 page not found\n"19142026/09/23 13:29:43 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19152026/09/23 13:29:43 WARN Failed to register uploaded object key=dllk9l99a4dsnmaxbsb5yvzz3qmqa5w7.ls error="server returned 404: 404 page not found\n"19162026/09/23 13:29:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19172026/09/23 13:29:43 WARN Failed to register uploaded object key=a2cal9dkabw2j0jkm7gb27vqr6lb33ql.ls error="server returned 404: 404 page not found\n"19182026/09/23 13:29:43 INFO Signed narinfos id=1 count=219192026/09/23 13:29:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign19202026/09/23 13:29:43 INFO Signed narinfos id=2 count=219212026/09/23 13:29:43 INFO Uploading 4 narinfos1922--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1923=== CONT TestGCTaskStore_GetReturnsLatest1924--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1925=== CONT TestGCTaskStore_ConflictDifferentParams1926--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)19272026/09/23 13:29:43 WARN Failed to register uploaded object key=4d2qqq8q5zn5yjrhvd84y31y4b8rm5qs.narinfo error="server returned 404: 404 page not found\n"1928=== CONT TestGCTaskStore_DeduplicateSameParams1929--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)19302026/09/23 13:29:43 WARN Failed to register uploaded object key=a2cal9dkabw2j0jkm7gb27vqr6lb33ql.narinfo error="server returned 404: 404 page not found\n"1931=== CONT TestGCTaskStore_GetEmpty19322026/09/23 13:29:43 WARN Failed to register uploaded object key=dllk9l99a4dsnmaxbsb5yvzz3qmqa5w7.narinfo error="server returned 404: 404 page not found\n"1933--- PASS: TestGCTaskStore_GetEmpty (0.00s)1934=== CONT TestGCTaskStore_StartNew1935--- PASS: TestGCTaskStore_StartNew (0.00s)1936=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info19372026/09/23 13:29:43 INFO Received uploads request method=POST path=/1938=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key19392026/09/23 13:29:43 INFO Received complete multipart upload request method=POST path=/1940=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal19412026/09/23 13:29:43 INFO Received uploads request method=POST path=/1942=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key19432026/09/23 13:29:43 INFO Received request for more parts method=POST path=/1944=== CONT TestProxyWriteTimeout/narinfo1945=== CONT TestProxyWriteTimeout/unknown_size1946=== CONT TestProxyWriteTimeout/10_GiB_nar1947=== CONT TestProxyWriteTimeout/1_GiB_nar1948=== CONT TestIsValidUploadKey/narinfo1949=== CONT TestIsValidUploadKey/realisation_plus_in_output1950=== CONT TestIsValidUploadKey/unknown_type1951=== CONT TestIsValidUploadKey/empty_key1952--- PASS: TestUploadHandlersRejectInvalidKeys (0.06s)1953 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1954 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1955 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1956 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1957=== CONT TestIsValidUploadKey/absolute1958=== CONT TestIsValidUploadKey/traversal_nar19592026/09/23 13:29:43 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1960=== CONT TestIsValidUploadKey/traversal1961=== CONT TestIsValidUploadKey/listing_key,_narinfo_type19622026/09/23 13:29:43 WARN Failed to register uploaded object key=a2cal9dkabw2j0jkm7gb27vqr6lb33ql.narinfo error="server returned 404: 404 page not found\n"1963=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1964--- PASS: TestProxyWriteTimeout (0.06s)1965 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1966 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1967 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1968 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1969=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1970=== CONT TestIsValidUploadKey/index.html1971=== CONT TestIsValidUploadKey/nix-cache-info1972=== CONT TestIsValidUploadKey/nar_plain1973=== CONT TestIsValidUploadKey/build_log1974=== CONT TestIsValidUploadKey/listing1975=== CONT TestIsValidUploadKey/nar_xz1976=== CONT TestIsValidUploadKey/build_log_equals1977=== CONT TestIsValidUploadKey/realisation1978=== CONT TestIsValidUploadKey/build_log_question_mark1979=== CONT TestIsValidUploadKey/nar_zst1980=== CONT TestIsValidUploadKey/build_log_plus_in_name1981=== CONT TestIsValidUploadKey/build_log_home-manager_file1982=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19832026/09/23 13:29:43 INFO Received uploads request method=POST path=/1984--- PASS: TestIsValidUploadKey (0.07s)1985 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1986 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1987 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1988 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1989 --- PASS: TestIsValidUploadKey/absolute (0.00s)1990 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1991 --- PASS: TestIsValidUploadKey/traversal (0.00s)1992 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1993 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1994 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1995 --- PASS: TestIsValidUploadKey/index.html (0.00s)1996 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1997 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1998 --- PASS: TestIsValidUploadKey/build_log (0.00s)1999 --- PASS: TestIsValidUploadKey/listing (0.00s)2000 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2001 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2002 --- PASS: TestIsValidUploadKey/realisation (0.00s)2003 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2004 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2005 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2006 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)20072026/09/23 13:29:43 INFO Completed upload id=220082026/09/23 13:29:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20092026/09/23 13:29:43 INFO Completed upload id=120102026/09/23 13:29:43 INFO Upload complete. (69ms)2011=== NAME TestClientPushesUseOnePush2012 client_pushes_test.go:97: Retrieved narinfo from S3:2013 StorePath: /build/TestClientPushesUseOnePush1358068344/001/store/a2cal9dkabw2j0jkm7gb27vqr6lb33ql-shared-dep2014 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2015 Compression: zstd2016 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822017 NarSize: 1362018 References: 2019 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n20202026/09/23 13:29:43 INFO Received uploads request method=POST path=/api/pending_closures2021 client_pushes_test.go:97: Retrieved narinfo from S3:2022 StorePath: /build/TestClientPushesUseOnePush1358068344/001/store/dllk9l99a4dsnmaxbsb5yvzz3qmqa5w7-a2023 URL: nar/0d90vlh8bsp1zx44spamgpmd157fn7z8yb429p4rklqiwyrf7kb0.nar.zst2024 Compression: zstd2025 NarHash: sha256:0d90vlh8bsp1zx44spamgpmd157fn7z8yb429p4rklqiwyrf7kb02026 NarSize: 2162027 References: /build/TestClientPushesUseOnePush1358068344/001/store/a2cal9dkabw2j0jkm7gb27vqr6lb33ql-shared-dep2028 CA: text:sha256:0088w7zzlh4nz05zdqxdz7zq2xr843dkjsbinpniirn99rs92r522029 client_pushes_test.go:97: Retrieved narinfo from S3:2030 StorePath: /build/TestClientPushesUseOnePush1358068344/001/store/4d2qqq8q5zn5yjrhvd84y31y4b8rm5qs-b2031 URL: nar/0d90vlh8bsp1zx44spamgpmd157fn7z8yb429p4rklqiwyrf7kb0.nar.zst2032 Compression: zstd2033 NarHash: sha256:0d90vlh8bsp1zx44spamgpmd157fn7z8yb429p4rklqiwyrf7kb02034 NarSize: 2162035 References: /build/TestClientPushesUseOnePush1358068344/001/store/a2cal9dkabw2j0jkm7gb27vqr6lb33ql-shared-dep2036 CA: text:sha256:0088w7zzlh4nz05zdqxdz7zq2xr843dkjsbinpniirn99rs92r522037 client_pushes_test.go:100: POST /api/pushes calls = 0, want 120382026/09/23 13:29:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)2039 client_pushes_test.go:104: POST /api/pending_closures calls = 2, want 020402026/09/23 13:29:43 INFO Uploading dvycpdg4n5f6fhq36il1cd7nazfvzp35-pinned-file.txt (128B)20412026/09/23 13:29:43 INFO Received uploads request method=POST path=/api/pending_closures20422026/09/23 13:29:43 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"20432026/09/23 13:29:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20442026/09/23 13:29:43 WARN Failed to register uploaded object key=dvycpdg4n5f6fhq36il1cd7nazfvzp35.ls error="server returned 404: 404 page not found\n"20452026/09/23 13:29:43 INFO Signed narinfos id=1 count=120462026/09/23 13:29:43 INFO Uploading 1 narinfos2047--- FAIL: TestClientPushesUseOnePush (0.81s)2048=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart20492026/09/23 13:29:43 INFO Received complete multipart upload request method=POST path=/20502026-09-23 13:29:43.548 UTC [1215] ERROR: relation "goose_db_version" does not exist at character 3620512026-09-23 13:29:43.548 UTC [1215] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20522026/09/23 13:29:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39631/oidc20532026/09/23 13:29:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20542026/09/23 13:29:43 WARN Failed to register uploaded object key=dvycpdg4n5f6fhq36il1cd7nazfvzp35.narinfo error="server returned 404: 404 page not found\n"20552026/09/23 13:29:43 INFO Received uploads request method=POST path=/api/pending_closures20562026/09/23 13:29:43 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)20572026/09/23 13:29:43 INFO Uploading 88grdi0w2ynqabg63k5lpk4npgyyf2xm-shared-dep (136B)20582026/09/23 13:29:43 INFO Uploading imq9s9l367p7yqn9rmxc6gbj6az2csaf-b (216B)20592026/09/23 13:29:43 WARN mTLS auth: subject not in bound subjects subject="CN=reader"20602026/09/23 13:29:43 WARN mTLS auth: subject not in bound subjects subject="CN=reader"2061--- PASS: TestService_NativeMTLS (0.59s)2062=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts20632026/09/23 13:29:43 INFO Received request for more parts method=POST path=/20642026/09/23 13:29:43 INFO Completed upload id=120652026/09/23 13:29:43 INFO Upload complete. (67ms)20662026/09/23 13:29:43 WARN Failed to register uploaded object key=hvci0xpqabixak32cq7ifdymq0crwibj.ls error="server returned 404: 404 page not found\n"20672026/09/23 13:29:43 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"20682026/09/23 13:29:43 WARN Failed to register uploaded object key=88grdi0w2ynqabg63k5lpk4npgyyf2xm.ls error="server returned 404: 404 page not found\n"20692026/09/23 13:29:43 WARN Failed to register uploaded object key=nar/1xickpf6mzpjgs75ygmix84d25i60qx40zps89bbmpi3wnpf0zfv.nar.zst error="server returned 404: 404 page not found\n"20702026/09/23 13:29:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20712026/09/23 13:29:43 WARN Failed to register uploaded object key=imq9s9l367p7yqn9rmxc6gbj6az2csaf.ls error="server returned 404: 404 page not found\n"20722026/09/23 13:29:43 INFO Signed narinfos id=1 count=220732026/09/23 13:29:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign20742026/09/23 13:29:43 INFO Signed narinfos id=2 count=220752026/09/23 13:29:43 INFO Uploading 4 narinfos20762026/09/23 13:29:43 OK 20241026095416_initial_model.sql (9.66ms)20772026/09/23 13:29:43 OK 20251210153512_drop_unused_gin_index.sql (1.66ms)20782026/09/23 13:29:43 WARN Failed to register uploaded object key=hvci0xpqabixak32cq7ifdymq0crwibj.narinfo error="server returned 404: 404 page not found\n"20792026/09/23 13:29:43 OK 20251218171726_add_pins.sql (2.79ms)20802026/09/23 13:29:43 WARN Failed to register uploaded object key=88grdi0w2ynqabg63k5lpk4npgyyf2xm.narinfo error="server returned 404: 404 page not found\n"20812026/09/23 13:29:43 WARN Failed to register uploaded object key=imq9s9l367p7yqn9rmxc6gbj6az2csaf.narinfo error="server returned 404: 404 page not found\n"20822026/09/23 13:29:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20832026/09/23 13:29:43 WARN Failed to register uploaded object key=88grdi0w2ynqabg63k5lpk4npgyyf2xm.narinfo error="server returned 404: 404 page not found\n"20842026/09/23 13:29:43 OK 20260628120000_add_object_size_and_stats.sql (3.36ms)2085=== NAME TestClientMultipleUploads2086 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads4174622300/001/store/f00dk1k3f27wg9anv26a1kfvi5h2mq3p-test-file-0.txt20872026/09/23 13:29:43 OK 20260905000000_add_claims.sql (3.54ms)20882026/09/23 13:29:43 OK 20260920000000_drop_claims.sql (1.6ms)20892026/09/23 13:29:43 INFO Received uploads request method=POST path=/api/pending_closures20902026/09/23 13:29:43 OK 20260923120000_add_pushes.sql (1.18ms)20912026/09/23 13:29:43 goose: successfully migrated database to version: 2026092312000020922026/09/23 13:29:43 INFO Completed upload id=120932026/09/23 13:29:43 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete20942026/09/23 13:29:43 OK 1_commit_pending_closure.sql (1.29ms)20952026-09-23 13:29:43.580 UTC [1271] ERROR: relation "goose_db_version" does not exist at character 3620962026-09-23 13:29:43.580 UTC [1271] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20972026/09/23 13:29:43 INFO Completed upload id=220982026/09/23 13:29:43 INFO Upload complete. (78ms)20992026/09/23 13:29:43 OK 2_object_stats_trigger.sql (1.08ms)2100=== NAME TestClientFallsBackToClosures2101 client_pushes_test.go:112: Retrieved narinfo from S3:2102 StorePath: /build/TestClientFallsBackToClosures1660229642/001/store/88grdi0w2ynqabg63k5lpk4npgyyf2xm-shared-dep2103 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2104 Compression: zstd2105 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822106 NarSize: 1362107 References: 2108 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n21092026/09/23 13:29:43 OK 3_commit_push.sql (1.23ms)21102026/09/23 13:29:43 goose: up to current file version: 32111--- PASS: TestService_ReadScope_PublicByDefault (0.58s)2112=== CONT TestIsValidCachePath/narinfo2113=== CONT TestIsValidCachePath/index.html2114=== CONT TestIsValidCachePath/short_hash2115=== CONT TestIsValidCachePath/invalid_char_u2116=== CONT TestIsValidCachePath/invalid_char_e2117=== CONT TestIsValidCachePath/random_path2118=== CONT TestIsValidCachePath/wrong_extension2119=== CONT TestIsValidCachePath/traversal_in_middle2120=== CONT TestIsValidCachePath/leading_slash2121=== CONT TestIsValidCachePath/traversal_parent2122=== CONT TestIsValidCachePath/empty2123=== CONT TestIsValidCachePath/nar_uncompressed2124=== CONT TestIsValidCachePath/nar_xz2125=== CONT TestIsValidCachePath/nix-cache-info2126=== CONT TestIsValidCachePath/nar_bz22127=== CONT TestIsValidCachePath/realisation2128=== CONT TestIsValidCachePath/log2129=== CONT TestIsValidCachePath/ls2130=== CONT TestIsValidCachePath/nar_zst2131=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2132--- PASS: TestIsValidCachePath (0.00s)2133 --- PASS: TestIsValidCachePath/narinfo (0.00s)2134 --- PASS: TestIsValidCachePath/index.html (0.00s)2135 --- PASS: TestIsValidCachePath/short_hash (0.00s)2136 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2137 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2138 --- PASS: TestIsValidCachePath/random_path (0.00s)2139 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2140 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2141 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2142 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2143 --- PASS: TestIsValidCachePath/empty (0.00s)2144 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2145 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2146 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2147 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2148 --- PASS: TestIsValidCachePath/realisation (0.00s)2149 --- PASS: TestIsValidCachePath/log (0.00s)2150 --- PASS: TestIsValidCachePath/ls (0.00s)2151 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2152 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2153=== CONT TestParseSingleRange/none2154=== CONT TestParseSingleRange/open-ended2155=== CONT TestParseSingleRange/start_far_past_EOF2156=== CONT TestParseSingleRange/start_past_EOF2157=== CONT TestParseSingleRange/single_byte2158=== CONT TestParseSingleRange/suffix_exceeds_size2159=== CONT TestParseSingleRange/end_clamped_to_size2160=== CONT TestParseSingleRange/suffix2161=== CONT TestParseSingleRange/malformed_both_empty2162=== CONT TestParseSingleRange/malformed_end_before_start2163=== CONT TestParseSingleRange/closed2164=== CONT TestParseSingleRange/multi-range_ignored2165=== CONT TestParseSingleRange/unknown_unit2166=== CONT TestParseSingleRange/malformed_no_dash2167--- PASS: TestParseSingleRange (0.00s)2168 --- PASS: TestParseSingleRange/none (0.00s)2169 --- PASS: TestParseSingleRange/open-ended (0.00s)2170 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2171 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2172 --- PASS: TestParseSingleRange/single_byte (0.00s)2173 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2174 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2175 --- PASS: TestParseSingleRange/suffix (0.00s)2176 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2177 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2178 --- PASS: TestParseSingleRange/closed (0.00s)2179 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2180 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2181 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2182=== CONT TestPush_RejectsBadRequests/bad_root21832026/09/23 13:29:43 INFO Received push request method=POST path=/api/pushes2184=== CONT TestPush_RejectsBadRequests/no_roots21852026/09/23 13:29:43 INFO Received push request method=POST path=/api/pushes2186=== CONT TestPush_RejectsBadRequests/no_objects21872026/09/23 13:29:43 INFO Received push request method=POST path=/api/pushes2188=== NAME TestClientFallsBackToClosures2189 client_pushes_test.go:112: Retrieved narinfo from S3:2190 StorePath: /build/TestClientFallsBackToClosures1660229642/001/store/hvci0xpqabixak32cq7ifdymq0crwibj-a2191 URL: nar/1xickpf6mzpjgs75ygmix84d25i60qx40zps89bbmpi3wnpf0zfv.nar.zst2192 Compression: zstd2193 NarHash: sha256:1xickpf6mzpjgs75ygmix84d25i60qx40zps89bbmpi3wnpf0zfv2194 NarSize: 2162195 References: /build/TestClientFallsBackToClosures1660229642/001/store/88grdi0w2ynqabg63k5lpk4npgyyf2xm-shared-dep2196 CA: text:sha256:1ss9qgfb1zxgnjk6ylj26lyq9jhshlwbg33r1sq2x1bsy3xz5yf12197=== CONT TestPush_RejectsBadRequests/root_not_in_objects21982026/09/23 13:29:43 INFO Received push request method=POST path=/api/pushes2199=== CONT TestResolveDBConnectionString/flag_wins2200=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2201=== CONT TestResolveDBConnectionString/nothing_configured2202=== CONT TestResolveDBConnectionString/file_when_flag_empty2203--- PASS: TestPush_RejectsBadRequests (0.90s)2204 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2205 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2206 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2207 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2208=== CONT TestResolveDBConnectionString/missing_file_is_an_error2209=== CONT TestServerTLSConfig/no_client_CA2210=== CONT TestServerTLSConfig/not_a_PEM_file2211--- PASS: TestResolveDBConnectionString (0.00s)2212 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2213 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2214 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2215 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2216 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2217=== NAME TestClientFallsBackToClosures2218 client_pushes_test.go:112: Retrieved narinfo from S3:2219 StorePath: /build/TestClientFallsBackToClosures1660229642/001/store/imq9s9l367p7yqn9rmxc6gbj6az2csaf-b2220 URL: nar/1xickpf6mzpjgs75ygmix84d25i60qx40zps89bbmpi3wnpf0zfv.nar.zst2221 Compression: zstd2222 NarHash: sha256:1xickpf6mzpjgs75ygmix84d25i60qx40zps89bbmpi3wnpf0zfv2223 NarSize: 2162224 References: /build/TestClientFallsBackToClosures1660229642/001/store/88grdi0w2ynqabg63k5lpk4npgyyf2xm-shared-dep2225 CA: text:sha256:1ss9qgfb1zxgnjk6ylj26lyq9jhshlwbg33r1sq2x1bsy3xz5yf12226=== CONT TestServerTLSConfig/missing_CA_file2227--- PASS: TestServerTLSConfig (0.00s)2228 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2229 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2230 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2231=== CONT TestClientErrorHandling/InvalidStorePath2232=== NAME TestClientWithDependencies2233 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies243552410/001/store/2jlgcn8xz80y04lr2cmhmzrnf9zz698b-test-script22342026/09/23 13:29:43 OK 20241026095416_initial_model.sql (7.94ms)22352026/09/23 13:29:43 INFO Received cleanup request method=DELETE path=/api/pending_closures2236--- PASS: TestClientFallsBackToClosures (0.88s)2237=== CONT TestClientErrorHandling/ServerNotAvailable22382026/09/23 13:29:43 OK 20251210153512_drop_unused_gin_index.sql (1.09ms)22392026/09/23 13:29:43 OK 20251218171726_add_pins.sql (2.09ms)22402026/09/23 13:29:43 INFO Aborted multipart uploads count=122412026/09/23 13:29:43 OK 20260628120000_add_object_size_and_stats.sql (3.1ms)2242--- PASS: TestMultipartCleanup (0.72s)2243=== CONT TestClientErrorHandling/InvalidAuthToken22442026/09/23 13:29:43 OK 20260905000000_add_claims.sql (2.6ms)22452026/09/23 13:29:43 OK 20260920000000_drop_claims.sql (2.03ms)22462026/09/23 13:29:43 OK 20260923120000_add_pushes.sql (2.19ms)22472026/09/23 13:29:43 goose: successfully migrated database to version: 2026092312000022482026/09/23 13:29:43 OK 1_commit_pending_closure.sql (1.84ms)2249=== NAME TestClientMultipleUploads2250 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads4174622300/001/store/c41zqdadax3ashda1ximaqrg67dlypf9-test-file-1.txt22512026/09/23 13:29:43 OK 2_object_stats_trigger.sql (1.22ms)22522026/09/23 13:29:43 OK 3_commit_push.sql (1.96ms)22532026/09/23 13:29:43 goose: up to current file version: 32254=== CONT TestCacheConfigHandler/full_config,_no_issuer2255=== CONT TestCacheConfigHandler/no_signing_keys2256=== CONT TestCacheConfigHandler/no_cache_url_configured2257=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2258--- PASS: TestCacheConfigHandler (0.00s)2259 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2260 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2261 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2262 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)22632026/09/23 13:29:43 INFO Received uploads request method=POST path=/api/pending_closures22642026/09/23 13:29:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)22652026/09/23 13:29:43 INFO Uploading xsgwxssnh97fk61lrii7pvx27n17cgqz-unpinned-file.txt (128B)2266=== NAME TestClientWithDependencies2267 client_integration_test.go:615: Found 1 dependencies (including self)22682026/09/23 13:29:43 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"22692026/09/23 13:29:43 WARN Failed to register uploaded object key=xsgwxssnh97fk61lrii7pvx27n17cgqz.ls error="server returned 404: 404 page not found\n"22702026/09/23 13:29:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign22712026/09/23 13:29:43 INFO Signed narinfos id=2 count=122722026/09/23 13:29:43 INFO Uploading 1 narinfos22732026/09/23 13:29:43 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22742026/09/23 13:29:43 WARN Failed to register uploaded object key=xsgwxssnh97fk61lrii7pvx27n17cgqz.narinfo error="server returned 404: 404 page not found\n"22752026/09/23 13:29:43 INFO Completed upload id=222762026/09/23 13:29:43 INFO Upload complete. (52ms)2277=== NAME TestClientMultipleUploads2278 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads4174622300/001/store/dd473kirp3di80rkhxs5v0dif5q79idb-test-file-2.txt22792026-09-23 13:29:43.645 UTC [1402] ERROR: relation "goose_db_version" does not exist at character 3622802026-09-23 13:29:43.645 UTC [1402] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2281--- PASS: TestMetricsInventory (0.61s)22822026/09/23 13:29:43 OK 20241026095416_initial_model.sql (7.26ms)22832026/09/23 13:29:43 INFO Received uploads request method=POST path=/api/pending_closures22842026/09/23 13:29:43 OK 20251210153512_drop_unused_gin_index.sql (1.62ms)22852026/09/23 13:29:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)22862026/09/23 13:29:43 INFO Uploading ynk8h8kf831gkp89wdxl8dk6xw8clgch-shared-dep (136B)22872026/09/23 13:29:43 OK 20251218171726_add_pins.sql (3.3ms)22882026-09-23 13:29:43.667 UTC [1457] ERROR: relation "goose_db_version" does not exist at character 3622892026-09-23 13:29:43.667 UTC [1457] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22902026/09/23 13:29:43 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"22912026/09/23 13:29:43 OK 20260628120000_add_object_size_and_stats.sql (3.21ms)22922026/09/23 13:29:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign22932026/09/23 13:29:43 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/present22942026/09/23 13:29:43 WARN Failed to register uploaded object key=ynk8h8kf831gkp89wdxl8dk6xw8clgch.ls error="server returned 404: 404 page not found\n"22952026/09/23 13:29:43 INFO Signed narinfos id=2 count=122962026/09/23 13:29:43 INFO Uploading 1 narinfos2297--- PASS: TestCacheStatsHandler (0.57s)22982026/09/23 13:29:43 OK 20260905000000_add_claims.sql (3.11ms)22992026/09/23 13:29:43 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete23002026/09/23 13:29:43 WARN Failed to register uploaded object key=ynk8h8kf831gkp89wdxl8dk6xw8clgch.narinfo error="server returned 404: 404 page not found\n"23012026/09/23 13:29:43 OK 20260920000000_drop_claims.sql (2.54ms)23022026/09/23 13:29:43 OK 20260923120000_add_pushes.sql (2.25ms)23032026/09/23 13:29:43 goose: successfully migrated database to version: 2026092312000023042026/09/23 13:29:43 INFO Completed upload id=223052026/09/23 13:29:43 INFO Upload complete. (56ms)23062026/09/23 13:29:43 INFO Received uploads request method=POST path=/api/pending_closures23072026/09/23 13:29:43 OK 1_commit_pending_closure.sql (2.27ms)23082026/09/23 13:29:43 OK 2_object_stats_trigger.sql (1.37ms)23092026/09/23 13:29:43 INFO Received create pin request method=POST path=/api/pins/myapp23102026/09/23 13:29:43 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)23112026/09/23 13:29:43 INFO Uploading 40p30dnid7283b0rdmbpkncxpmwwh63a-top (224B)23122026/09/23 13:29:43 INFO Uploading ynk8h8kf831gkp89wdxl8dk6xw8clgch-shared-dep (136B)23132026/09/23 13:29:43 OK 3_commit_push.sql (1.15ms)23142026/09/23 13:29:43 goose: up to current file version: 323152026/09/23 13:29:43 OK 20241026095416_initial_model.sql (11.3ms)23162026/09/23 13:29:43 WARN Failed to register uploaded object key=nar/1qi65ysyxq2ynf8n6xizhxfllbdq46d4k53fdragmn8xjlh875xm.nar.zst error="server returned 404: 404 page not found\n"23172026/09/23 13:29:43 WARN Failed to register uploaded object key=40p30dnid7283b0rdmbpkncxpmwwh63a.ls error="server returned 404: 404 page not found\n"23182026/09/23 13:29:43 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"23192026/09/23 13:29:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign23202026/09/23 13:29:43 WARN Failed to register uploaded object key=ynk8h8kf831gkp89wdxl8dk6xw8clgch.ls error="server returned 404: 404 page not found\n"23212026/09/23 13:29:43 INFO Signed narinfos id=1 count=123222026/09/23 13:29:43 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1019887588/001/store/dvycpdg4n5f6fhq36il1cd7nazfvzp35-pinned-file.txt narinfo_key=dvycpdg4n5f6fhq36il1cd7nazfvzp35.narinfo23232026/09/23 13:29:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign23242026/09/23 13:29:43 INFO Signed narinfos id=3 count=123252026/09/23 13:29:43 INFO Uploading 2 narinfos23262026/09/23 13:29:43 OK 20251210153512_drop_unused_gin_index.sql (2.48ms)23272026/09/23 13:29:43 INFO Starting cleanup of old closures method=DELETE path=/api/closures23282026/09/23 13:29:43 INFO Garbage collection started23292026/09/23 13:29:43 OK 20251218171726_add_pins.sql (2.83ms)23302026/09/23 13:29:43 WARN Failed to register uploaded object key=ynk8h8kf831gkp89wdxl8dk6xw8clgch.narinfo error="server returned 404: 404 page not found\n"23312026/09/23 13:29:43 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete23322026/09/23 13:29:43 WARN Failed to register uploaded object key=40p30dnid7283b0rdmbpkncxpmwwh63a.narinfo error="server returned 404: 404 page not found\n"23332026/09/23 13:29:43 OK 20260628120000_add_object_size_and_stats.sql (2.69ms)23342026/09/23 13:29:43 INFO Completed upload id=323352026/09/23 13:29:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete23362026/09/23 13:29:43 INFO Completed upload id=123372026/09/23 13:29:43 INFO Upload complete. (158ms)23382026/09/23 13:29:43 OK 20260905000000_add_claims.sql (2.83ms)23392026/09/23 13:29:43 INFO Aborted multipart uploads count=02340=== NAME TestClientSharedPathCommittedMidPush2341 client_integration_test.go:680: Retrieved narinfo from S3:2342 StorePath: /build/TestClientSharedPathCommittedMidPush1530557346/001/store/ynk8h8kf831gkp89wdxl8dk6xw8clgch-shared-dep2343 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2344 Compression: zstd2345 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822346 NarSize: 1362347 References: 2348 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n23492026/09/23 13:29:43 OK 20260920000000_drop_claims.sql (1.53ms)23502026/09/23 13:29:43 OK 20260923120000_add_pushes.sql (1.13ms)23512026/09/23 13:29:43 goose: successfully migrated database to version: 2026092312000023522026/09/23 13:29:43 WARN Force mode enabled - objects will be deleted immediately without grace period2353 client_integration_test.go:680: Retrieved narinfo from S3:2354 StorePath: /build/TestClientSharedPathCommittedMidPush1530557346/001/store/40p30dnid7283b0rdmbpkncxpmwwh63a-top2355 URL: nar/1qi65ysyxq2ynf8n6xizhxfllbdq46d4k53fdragmn8xjlh875xm.nar.zst2356 Compression: zstd2357 NarHash: sha256:1qi65ysyxq2ynf8n6xizhxfllbdq46d4k53fdragmn8xjlh875xm2358 NarSize: 2242359 References: /build/TestClientSharedPathCommittedMidPush1530557346/001/store/ynk8h8kf831gkp89wdxl8dk6xw8clgch-shared-dep2360 CA: text:sha256:04p8kz27wmj2xwd8j05klq7y6jsjfva6dh2b5z925k3rckhyf2ag23612026/09/23 13:29:43 OK 1_commit_pending_closure.sql (1.48ms)23622026-09-23 13:29:43.700 UTC [1513] ERROR: relation "goose_db_version" does not exist at character 3623632026-09-23 13:29:43.700 UTC [1513] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23642026/09/23 13:29:43 OK 2_object_stats_trigger.sql (739.02µs)23652026/09/23 13:29:43 OK 3_commit_push.sql (759.62µs)23662026/09/23 13:29:43 goose: up to current file version: 323672026/09/23 13:29:43 INFO Received uploads request method=POST path=/api/pending_closures2368--- PASS: TestClientSharedPathCommittedMidPush (0.85s)2369--- PASS: TestService_ReadAuthMiddleware (0.51s)23702026/09/23 13:29:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23712026/09/23 13:29:43 INFO Uploading 2jlgcn8xz80y04lr2cmhmzrnf9zz698b-test-script (136B)23722026/09/23 13:29:43 OK 20241026095416_initial_model.sql (7.5ms)23732026/09/23 13:29:43 WARN Failed to register uploaded object key=log/xz9g8m3h10ajzsjmzipin52kpgpgjnfy-test-script.drv error="server returned 404: 404 page not found\n"23742026/09/23 13:29:43 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"23752026/09/23 13:29:43 OK 20251210153512_drop_unused_gin_index.sql (983.68µs)23762026/09/23 13:29:43 WARN Failed to register uploaded object key=2jlgcn8xz80y04lr2cmhmzrnf9zz698b.ls error="server returned 404: 404 page not found\n"23772026/09/23 13:29:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign23782026/09/23 13:29:43 INFO Signed narinfos id=1 count=123792026/09/23 13:29:43 INFO Uploading 1 narinfos23802026/09/23 13:29:43 INFO Received uploads request method=POST path=/api/pending_closures23812026/09/23 13:29:43 OK 20251218171726_add_pins.sql (1.7ms)23822026/09/23 13:29:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete23832026/09/23 13:29:43 WARN Failed to register uploaded object key=2jlgcn8xz80y04lr2cmhmzrnf9zz698b.narinfo error="server returned 404: 404 page not found\n"23842026/09/23 13:29:43 OK 20260628120000_add_object_size_and_stats.sql (2.74ms)23852026/09/23 13:29:43 INFO Received uploads request method=POST path=/api/pending_closures23862026/09/23 13:29:43 INFO Received uploads request method=POST path=/api/pending_closures23872026/09/23 13:29:43 OK 20260905000000_add_claims.sql (2.25ms)23882026/09/23 13:29:43 INFO Completed upload id=123892026/09/23 13:29:43 INFO Upload complete. (53ms)23902026/09/23 13:29:43 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)23912026/09/23 13:29:43 INFO Uploading f00dk1k3f27wg9anv26a1kfvi5h2mq3p-test-file-0.txt (160B)23922026/09/23 13:29:43 INFO Uploading c41zqdadax3ashda1ximaqrg67dlypf9-test-file-1.txt (160B)23932026/09/23 13:29:43 INFO Uploading dd473kirp3di80rkhxs5v0dif5q79idb-test-file-2.txt (160B)23942026/09/23 13:29:43 OK 20260920000000_drop_claims.sql (1.69ms)2395=== NAME TestClientWithDependencies2396 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies243552410/001/store) requires matching store prefix23972026/09/23 13:29:43 OK 20260923120000_add_pushes.sql (1.06ms)23982026/09/23 13:29:43 goose: successfully migrated database to version: 2026092312000023992026/09/23 13:29:43 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"24002026/09/23 13:29:43 OK 1_commit_pending_closure.sql (1.5ms)24012026/09/23 13:29:43 OK 2_object_stats_trigger.sql (739.4µs)24022026/09/23 13:29:43 WARN Failed to register uploaded object key=f00dk1k3f27wg9anv26a1kfvi5h2mq3p.ls error="server returned 404: 404 page not found\n"24032026/09/23 13:29:43 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"24042026/09/23 13:29:43 OK 3_commit_push.sql (852.05µs)24052026/09/23 13:29:43 goose: up to current file version: 32406=== NAME TestNARDeduplicationMetadataUploadBug2407 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug879993838/001/store/bbla9ca3jnn56rxygvn4b4kv79wd2sv8-file1.txt24082026/09/23 13:29:43 WARN Failed to register uploaded object key=c41zqdadax3ashda1ximaqrg67dlypf9.ls error="server returned 404: 404 page not found\n"24092026/09/23 13:29:43 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"24102026/09/23 13:29:43 WARN readiness check failed error="closed pool"2411--- PASS: TestService_readinessHandler (0.44s)24122026/09/23 13:29:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign24132026/09/23 13:29:43 WARN Failed to register uploaded object key=dd473kirp3di80rkhxs5v0dif5q79idb.ls error="server returned 404: 404 page not found\n"24142026/09/23 13:29:43 INFO Signed narinfos id=3 count=124152026/09/23 13:29:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign24162026/09/23 13:29:43 INFO Signed narinfos id=1 count=124172026/09/23 13:29:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign24182026/09/23 13:29:43 INFO Signed narinfos id=2 count=124192026/09/23 13:29:43 INFO Uploading 3 narinfos2420=== NAME TestClientCADerivations2421 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2364397480/001/store/p11g875gppk190fww97z5vzlfwfzchbq-ca-test2422--- PASS: TestClientWithDependencies (0.82s)24232026/09/23 13:29:43 WARN Failed to register uploaded object key=dd473kirp3di80rkhxs5v0dif5q79idb.narinfo error="server returned 404: 404 page not found\n"24242026/09/23 13:29:43 WARN Failed to register uploaded object key=c41zqdadax3ashda1ximaqrg67dlypf9.narinfo error="server returned 404: 404 page not found\n"24252026/09/23 13:29:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete24262026/09/23 13:29:43 WARN Failed to register uploaded object key=f00dk1k3f27wg9anv26a1kfvi5h2mq3p.narinfo error="server returned 404: 404 page not found\n"24272026/09/23 13:29:43 INFO Completed upload id=124282026/09/23 13:29:43 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete24292026/09/23 13:29:43 INFO Completed upload id=224302026/09/23 13:29:43 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete24312026/09/23 13:29:43 INFO Completed upload id=324322026/09/23 13:29:43 INFO Upload complete. (62ms)2433=== NAME TestClientMultipleUploads2434 client_integration_test.go:369: Uploaded 3 paths in 94.722302ms2435--- PASS: TestClientMultipleUploads (0.82s)2436=== NAME TestClientCADerivations2437 client_ca_test.go:139: Found 1 dependencies (including self)2438=== RUN TestService_RequireScope_OIDC/builder_may_write2439=== PAUSE TestService_RequireScope_OIDC/builder_may_write2440=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2441=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2442=== RUN TestService_RequireScope_OIDC/ops_may_admin2443=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2444=== RUN TestService_RequireScope_OIDC/ops_may_not_write2445=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2446=== RUN TestService_RequireScope_OIDC/reader_may_not_write2447=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2448=== RUN TestService_RequireScope_OIDC/static_token_may_admin2449=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2450=== RUN TestService_RequireScope_OIDC/static_token_may_write2451=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2452=== RUN TestService_RequireScope_OIDC/reader_may_read2453=== PAUSE TestService_RequireScope_OIDC/reader_may_read2454=== RUN TestService_RequireScope_OIDC/writer_implies_read2455=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2456=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2457=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2458=== CONT TestService_RequireScope_OIDC/builder_may_write2459=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2460=== CONT TestService_RequireScope_OIDC/static_token_may_admin2461=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2462=== CONT TestService_RequireScope_OIDC/writer_implies_read2463=== CONT TestService_RequireScope_OIDC/reader_may_read24642026/09/23 13:29:43 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=194.991117ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2465=== CONT TestService_RequireScope_OIDC/static_token_may_write2466=== CONT TestService_RequireScope_OIDC/ops_may_not_write2467=== CONT TestService_RequireScope_OIDC/ops_may_admin2468=== CONT TestService_RequireScope_OIDC/reader_may_not_write2469--- PASS: TestService_RequireScope_OIDC (0.52s)2470 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2471 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2472 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2473 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2474 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2475 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2476 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2477 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2478 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2479 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2480--- PASS: TestService_healthCheckHandler (0.41s)24812026/09/23 13:29:43 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"24822026/09/23 13:29:43 WARN mTLS auth: bound subjects configured but subject DN unavailable24832026/09/23 13:29:43 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2484--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.32s)24852026/09/23 13:29:43 INFO Received uploads request method=POST path=/api/pending_closures24862026/09/23 13:29:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)24872026/09/23 13:29:43 INFO Uploading bbla9ca3jnn56rxygvn4b4kv79wd2sv8-file1.txt (160B)24882026/09/23 13:29:43 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"24892026/09/23 13:29:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign24902026/09/23 13:29:43 WARN Failed to register uploaded object key=bbla9ca3jnn56rxygvn4b4kv79wd2sv8.ls error="server returned 404: 404 page not found\n"24912026/09/23 13:29:43 INFO Signed narinfos id=1 count=124922026/09/23 13:29:43 INFO Uploading 1 narinfos24932026/09/23 13:29:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete24942026/09/23 13:29:43 WARN Failed to register uploaded object key=bbla9ca3jnn56rxygvn4b4kv79wd2sv8.narinfo error="server returned 404: 404 page not found\n"2495--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.33s)24962026/09/23 13:29:43 INFO Completed upload id=124972026/09/23 13:29:43 INFO Upload complete. (55ms)2498=== NAME TestNARDeduplicationMetadataUploadBug2499 metadata_upload_test.go:54: Retrieved narinfo from S3:2500 StorePath: /build/TestNARDeduplicationMetadataUploadBug879993838/001/store/bbla9ca3jnn56rxygvn4b4kv79wd2sv8-file1.txt2501 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2502 Compression: zstd2503 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2504 NarSize: 1602505 References: 2506 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2507 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2508 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2509 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}2510=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2511=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2512=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2513=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2514=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2515=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2516=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2517=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2518=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2519=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2520=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected25212026/09/23 13:29:43 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2522=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured25232026/09/23 13:29:43 WARN Authentication failed token_preview=eyJhbGciOi...qP2osQQqHA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2524--- PASS: TestService_AuthMiddleware_OIDC (0.39s)2525 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2526 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2527 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2528 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2529=== NAME TestNARDeduplicationMetadataUploadBug2530 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug879993838/001/store/3pprlp651fwbffflrycl78ij0wzz3i02-file2.txt25312026/09/23 13:29:43 INFO Received uploads request method=POST path=/api/pending_closures25322026/09/23 13:29:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)25332026/09/23 13:29:43 INFO Uploading p11g875gppk190fww97z5vzlfwfzchbq-ca-test (144B)25342026/09/23 13:29:43 WARN Failed to register uploaded object key=p11g875gppk190fww97z5vzlfwfzchbq.ls error="server returned 404: 404 page not found\n"25352026/09/23 13:29:43 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"25362026/09/23 13:29:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign25372026/09/23 13:29:43 WARN Failed to register uploaded object key=log/6dmlcaashkj2a26rva7ilx6iczlindv2-ca-test.drv error="server returned 404: 404 page not found\n"25382026/09/23 13:29:43 INFO Signed narinfos id=1 count=125392026/09/23 13:29:43 INFO Uploading 1 narinfos25402026/09/23 13:29:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete25412026/09/23 13:29:43 WARN Failed to register uploaded object key=p11g875gppk190fww97z5vzlfwfzchbq.narinfo error="server returned 404: 404 page not found\n"25422026/09/23 13:29:43 INFO Completed upload id=125432026/09/23 13:29:43 INFO Upload complete. (94ms)2544=== NAME TestClientCADerivations2545 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2364397480/001/store/p11g875gppk190fww97z5vzlfwfzchbq-ca-test2546 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2547 Compression: zstd2548 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2549 NarSize: 1442550 References: 2551 Deriver: /build/TestClientCADerivations2364397480/001/store/6dmlcaashkj2a26rva7ilx6iczlindv2-ca-test.drv2552 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2553 client_ca_test.go:185: Checking for realisation files in S3...2554 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2555 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache25562026/09/23 13:29:43 INFO Received uploads request method=POST path=/api/pending_closures25572026/09/23 13:29:43 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)25582026/09/23 13:29:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign25592026/09/23 13:29:43 INFO Signed narinfos id=2 count=125602026/09/23 13:29:43 WARN Failed to register uploaded object key=3pprlp651fwbffflrycl78ij0wzz3i02.ls error="server returned 404: 404 page not found\n"25612026/09/23 13:29:43 INFO Uploading 1 narinfos25622026/09/23 13:29:43 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete25632026/09/23 13:29:43 WARN Failed to register uploaded object key=3pprlp651fwbffflrycl78ij0wzz3i02.narinfo error="server returned 404: 404 page not found\n"25642026/09/23 13:29:43 INFO Completed upload id=225652026/09/23 13:29:43 INFO Upload complete. (51ms)2566=== NAME TestNARDeduplicationMetadataUploadBug2567 metadata_upload_test.go:76: Retrieved narinfo from S3:2568 StorePath: /build/TestNARDeduplicationMetadataUploadBug879993838/001/store/3pprlp651fwbffflrycl78ij0wzz3i02-file2.txt2569 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2570 Compression: zstd2571 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2572 NarSize: 1602573 References: 2574 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2575 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2576 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2577 {"version":1,"root":{"type":"regular","size":44}}2578--- PASS: TestNARDeduplicationMetadataUploadBug (0.85s)25792026/09/23 13:29:43 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"25802026/09/23 13:29:43 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=384.364104ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present25812026/09/23 13:29:43 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2582=== NAME TestClientCADerivations2583 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2584 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2585 error: binary cache 's3://bucket54?endpoint=http://localhost:41939®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2364397480/001/store'2586 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12587--- PASS: TestClientCADerivations (0.96s)2588--- PASS: TestUploadHandlersRejectOversizedBody (0.13s)2589 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)2590 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)2591 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.64s)25922026/09/23 13:29:44 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=758.689872ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present25932026/09/23 13:29:44 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=025942026/09/23 13:29:44 INFO Vacuumed table table=pending_closures25952026/09/23 13:29:44 INFO Vacuumed table table=pending_objects25962026/09/23 13:29:44 INFO Vacuumed table table=multipart_uploads25972026/09/23 13:29:44 INFO Vacuumed table table=closures25982026/09/23 13:29:44 INFO Vacuumed table table=objects2599=== NAME TestOrphanedObjectsGCStressTest2600 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2601 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion26022026/09/23 13:29:44 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=026032026/09/23 13:29:44 INFO Vacuumed table table=pending_closures26042026/09/23 13:29:44 INFO Vacuumed table table=pending_objects26052026/09/23 13:29:44 INFO Vacuumed table table=multipart_uploads26062026/09/23 13:29:44 INFO Vacuumed table table=closures26072026/09/23 13:29:44 INFO Vacuumed table table=objects2608 orphaned_objects_gc_test.go:509: Stress test completed successfully:2609 orphaned_objects_gc_test.go:510: - Active objects preserved: 202610 orphaned_objects_gc_test.go:511: - Objects deleted: 2102611 orphaned_objects_gc_test.go:512: - Total GC'd: 2102612--- PASS: TestOrphanedObjectsGCStressTest (2.46s)26132026/09/23 13:29:45 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.633157469s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present26142026/09/23 13:29:45 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02615=== NAME TestClientIntegration2616 client_integration_test.go:323: Objects in database after GC:2617 client_integration_test.go:323: Successfully deleted all objects with GC --force2618--- PASS: TestClientIntegration (2.82s)26192026/09/23 13:29:45 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02620=== NAME TestPinProtectsFromGC2621 client_integration_test.go:794: Pin successfully protected closure from garbage collection2622--- PASS: TestPinProtectsFromGC (2.94s)26232026/09/23 13:29:46 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26242026/09/23 13:29:46 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=190.800165ms 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:29:47 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=423.781365ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26262026/09/23 13:29:47 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=760.254185ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26272026/09/23 13:29:47 WARN Rate limiter enabled after throttle name=s3-test rate=526282026/09/23 13:29:47 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2629=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2630 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102631 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002632--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.03s)26332026/09/23 13:29:48 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.563875094s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26342026/09/23 13:29:49 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"26352026/09/23 13:29:49 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26362026/09/23 13:29:49 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=218.955592ms 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:29:50 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=411.131272ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26382026/09/23 13:29:50 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=737.938907ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26392026/09/23 13:29:51 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.605703062s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2640--- PASS: TestClientErrorHandling (0.00s)2641 --- PASS: TestClientErrorHandling/InvalidStorePath (0.30s)2642 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.39s)2643 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.32s)2644FAIL2645{"timestamp":"2026-09-23T13:29:52.921278169Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:51214","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(394)"}2646{"timestamp":"2026-09-23T13:29:52.921326209Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:50568","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(393)"}26472026-09-23 13:29:53.257 UTC [129] LOG: received smart shutdown request26482026-09-23 13:29:53.262 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 126492026-09-23 13:29:53.270 UTC [134] LOG: shutting down26502026-09-23 13:29:53.271 UTC [134] LOG: checkpoint starting: shutdown immediate26512026-09-23 13:29:53.994 UTC [134] LOG: checkpoint complete: wrote 11081 buffers (67.6%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 18 recycled; write=0.235 s, sync=0.452 s, total=0.724 s; sync files=21875, longest=0.007 s, average=0.001 s; distance=297531 kB, estimate=297531 kB; lsn=0/139F4B98, redo lsn=0/139F4B9826522026-09-23 13:29:54.064 UTC [129] LOG: database system is shut down