niks3-go-unit-tests
aarch64-darwin.go-unit-tests
· build #109
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestCaseHackSuffix5=== PAUSE TestCaseHackSuffix6=== RUN TestFilterOversizedClosures7=== PAUSE TestFilterOversizedClosures8=== RUN TestPartSizeForNAR9=== PAUSE TestPartSizeForNAR10=== RUN TestUploadMultipart_SupersededByPeer11=== PAUSE TestUploadMultipart_SupersededByPeer12=== RUN TestDumpPathMatchesNix13=== PAUSE TestDumpPathMatchesNix14=== RUN TestDumpPathSingleFile15=== PAUSE TestDumpPathSingleFile16=== RUN TestDumpPathWriterError17=== PAUSE TestDumpPathWriterError18=== RUN TestEncodeNixBase3219=== PAUSE TestEncodeNixBase3220=== RUN TestEncodeNixBase32WithRealHash21=== PAUSE TestEncodeNixBase32WithRealHash22=== RUN TestConvertHashToNix3223=== PAUSE TestConvertHashToNix3224=== RUN TestGetStorePathHash25=== PAUSE TestGetStorePathHash26=== RUN TestPathInfoHashCompatibility27=== PAUSE TestPathInfoHashCompatibility28=== RUN TestParsePathInfoJSON29=== PAUSE TestParsePathInfoJSON30=== RUN TestParsePathInfoJSONMultiplePaths31=== PAUSE TestParsePathInfoJSONMultiplePaths32=== RUN TestPathInfoCACompatibility33=== PAUSE TestPathInfoCACompatibility34=== RUN TestRateLimiterFeedback35=== PAUSE TestRateLimiterFeedback36=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess37=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess38=== RUN TestResolveStorePath39=== PAUSE TestResolveStorePath40=== RUN TestDoWithRetry_BodyReplayedViaGetBody41=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody42=== RUN TestShellSplit43=== PAUSE TestShellSplit44=== RUN TestShellSplitErrors45=== PAUSE TestShellSplitErrors46=== RUN TestSetClientTLS47=== PAUSE TestSetClientTLS48=== RUN TestSetClientTLSDoesNotMutateDefaultTransport49=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport50=== RUN TestSetClientTLSErrors51=== PAUSE TestSetClientTLSErrors52=== RUN TestStaticToken53=== PAUSE TestStaticToken54=== RUN TestFileTokenReadsAndCaches55=== PAUSE TestFileTokenReadsAndCaches56=== RUN TestFileTokenMissing57=== PAUSE TestFileTokenMissing58=== RUN TestFileTokenEmpty59=== PAUSE TestFileTokenEmpty60=== RUN TestScriptTokenNoExpiryRerunsEveryCall61=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall62=== RUN TestScriptTokenCachesUntilRefresh63=== PAUSE TestScriptTokenCachesUntilRefresh64=== RUN TestScriptTokenEmptyToken65=== PAUSE TestScriptTokenEmptyToken66=== RUN TestScriptTokenBadJSON67=== PAUSE TestScriptTokenBadJSON68=== RUN TestScriptTokenScriptFails69=== PAUSE TestScriptTokenScriptFails70=== RUN TestScriptTokenEmptyCommand71=== PAUSE TestScriptTokenEmptyCommand72=== CONT TestDoServerRequestAttachesToken73=== CONT TestScriptTokenScriptFails74=== CONT TestScriptTokenCachesUntilRefresh75=== CONT TestPathInfoCACompatibility76=== RUN TestPathInfoCACompatibility/null_ca_field77=== PAUSE TestPathInfoCACompatibility/null_ca_field78=== RUN TestPathInfoCACompatibility/old_string_format_-_text79=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text80=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive81=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive82=== RUN TestPathInfoCACompatibility/new_structured_format_-_text83=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text84=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method85=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method86=== CONT TestEncodeNixBase32WithRealHash87--- PASS: TestEncodeNixBase32WithRealHash (0.00s)88=== CONT TestScriptTokenEmptyCommand89--- PASS: TestScriptTokenEmptyCommand (0.00s)90=== CONT TestSetClientTLSDoesNotMutateDefaultTransport91=== CONT TestEncodeNixBase3292=== RUN TestEncodeNixBase32/test_string_hash93=== CONT TestParsePathInfoJSONMultiplePaths94=== CONT TestParsePathInfoJSON95=== CONT TestPathInfoHashCompatibility96=== CONT TestGetStorePathHash97=== CONT TestConvertHashToNix3298=== RUN TestConvertHashToNix32/SRI_format_to_Nix3299=== PAUSE TestEncodeNixBase32/test_string_hash100=== RUN TestEncodeNixBase32/empty_input101=== PAUSE TestEncodeNixBase32/empty_input102=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32103=== RUN TestConvertHashToNix32/already_Nix32_format104=== PAUSE TestConvertHashToNix32/already_Nix32_format105=== CONT TestScriptTokenNoExpiryRerunsEveryCall106=== RUN TestConvertHashToNix32/invalid_format107=== PAUSE TestConvertHashToNix32/invalid_format108=== RUN TestGetStorePathHash/valid_store_path109=== RUN TestParsePathInfoJSON/Nix_format110=== PAUSE TestGetStorePathHash/valid_store_path111=== RUN TestGetStorePathHash/basename_without_hyphen_should_error112=== PAUSE TestParsePathInfoJSON/Nix_format113=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error114=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths115=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths116=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths117=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths118=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error119=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error120=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error121=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error122=== CONT TestFileTokenMissing123=== CONT TestFileTokenReadsAndCaches124=== CONT TestFileTokenEmpty125=== RUN TestParsePathInfoJSON/Lix_format126=== PAUSE TestParsePathInfoJSON/Lix_format127=== RUN TestParsePathInfoJSON/empty_input128=== PAUSE TestParsePathInfoJSON/empty_input129=== RUN TestParsePathInfoJSON/whitespace_only130=== PAUSE TestParsePathInfoJSON/whitespace_only131=== RUN TestParsePathInfoJSON/invalid_JSON132=== PAUSE TestParsePathInfoJSON/invalid_JSON133=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)134=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)135=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon136=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon137=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI138=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI139=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512140=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512141=== CONT TestStaticToken142--- PASS: TestStaticToken (0.00s)143=== CONT TestScriptTokenBadJSON144=== CONT TestSetClientTLSErrors145--- PASS: TestDoServerRequestAttachesToken (0.00s)146=== CONT TestUploadMultipart_SupersededByPeer147=== RUN TestUploadMultipart_SupersededByPeer/exists148=== PAUSE TestUploadMultipart_SupersededByPeer/exists149=== RUN TestUploadMultipart_SupersededByPeer/missing150=== PAUSE TestUploadMultipart_SupersededByPeer/missing151=== CONT TestDumpPathWriterError152--- PASS: TestScriptTokenScriptFails (0.01s)153=== CONT TestDumpPathSingleFile154--- PASS: TestFileTokenMissing (0.01s)155=== CONT TestDumpPathMatchesNix156=== RUN TestSetClientTLSErrors/missing_cert_file157=== PAUSE TestSetClientTLSErrors/missing_cert_file158=== RUN TestSetClientTLSErrors/missing_key_file159=== PAUSE TestSetClientTLSErrors/missing_key_file160=== RUN TestSetClientTLSErrors/missing_ca_file161=== PAUSE TestSetClientTLSErrors/missing_ca_file162=== RUN TestSetClientTLSErrors/invalid_ca_file163=== PAUSE TestSetClientTLSErrors/invalid_ca_file164=== CONT TestScriptTokenEmptyToken165--- PASS: TestFileTokenEmpty (0.02s)166=== CONT TestFilterOversizedClosures167=== RUN TestFilterOversizedClosures/no_limit_keeps_everything168=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything169=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped170=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped171=== RUN TestFilterOversizedClosures/all_closures_skipped172=== PAUSE TestFilterOversizedClosures/all_closures_skipped173=== CONT TestPartSizeForNAR174=== RUN TestPartSizeForNAR/zero_stays_at_minimum175=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum176=== RUN TestPartSizeForNAR/small_stays_at_minimum177=== PAUSE TestPartSizeForNAR/small_stays_at_minimum178=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum179=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum180=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts181=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts182=== RUN TestPartSizeForNAR/1_TiB183=== PAUSE TestPartSizeForNAR/1_TiB184=== RUN TestPartSizeForNAR/5_TiB_S3_max_object185=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object186=== RUN TestPartSizeForNAR/capped_at_5_GiB187=== PAUSE TestPartSizeForNAR/capped_at_5_GiB188=== CONT TestCaseHackSuffix189--- PASS: TestFileTokenReadsAndCaches (0.02s)190=== CONT TestDoWithRetry_BodyReplayedViaGetBody191--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.02s)192=== CONT TestSetClientTLS1932026/07/19 11:32:19 WARN Rate limiter enabled after throttle name=server-test rate=51942026/07/19 11:32:19 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:603241952026/07/19 11:32:19 WARN Rate limiter backed off name=server-test rate=51962026/07/19 11:32:19 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:60324197--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)198=== CONT TestShellSplitErrors199--- PASS: TestShellSplitErrors (0.00s)200=== CONT TestShellSplit201--- PASS: TestShellSplit (0.00s)202=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess2032026/07/19 11:32:19 WARN Rate limiter enabled after throttle name=server-test rate=5204--- PASS: TestScriptTokenBadJSON (0.02s)205=== CONT TestResolveStorePath206=== RUN TestSetClientTLS/rejects_connection_without_client_cert207=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert208=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA209=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA210=== RUN TestSetClientTLS/preserves_debug_logging_transport211=== PAUSE TestSetClientTLS/preserves_debug_logging_transport212=== CONT TestRateLimiterFeedback213=== RUN TestRateLimiterFeedback/429_enables_limiter214=== PAUSE TestRateLimiterFeedback/429_enables_limiter215=== RUN TestRateLimiterFeedback/503_enables_limiter216=== PAUSE TestRateLimiterFeedback/503_enables_limiter217=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter218=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter219=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter220=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter221=== CONT TestPathInfoCACompatibility/null_ca_field222=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive223=== CONT TestPathInfoCACompatibility/new_structured_format_-_text224=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method225=== CONT TestPathInfoCACompatibility/old_string_format_-_text226--- PASS: TestPathInfoCACompatibility (0.00s)227 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)228 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)229 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)230 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)231 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)232=== CONT TestEncodeNixBase32/test_string_hash233=== CONT TestEncodeNixBase32/empty_input234--- PASS: TestEncodeNixBase32 (0.00s)235 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)236 --- PASS: TestEncodeNixBase32/empty_input (0.00s)237=== CONT TestConvertHashToNix32/SRI_format_to_Nix32238=== CONT TestConvertHashToNix32/invalid_format239=== CONT TestConvertHashToNix32/already_Nix32_format240--- PASS: TestConvertHashToNix32 (0.00s)241 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)242 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)243 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)244=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths245=== CONT TestGetStorePathHash/valid_store_path246=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error247=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error248=== CONT TestGetStorePathHash/basename_without_hyphen_should_error249--- PASS: TestGetStorePathHash (0.00s)250 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)251 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)252 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)253 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)254=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths255--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)256 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)257 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)258=== CONT TestParsePathInfoJSON/Nix_format259=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)260=== CONT TestParsePathInfoJSON/Lix_format261=== CONT TestParsePathInfoJSON/invalid_JSON262=== CONT TestParsePathInfoJSON/whitespace_only263=== CONT TestParsePathInfoJSON/empty_input264--- PASS: TestParsePathInfoJSON (0.00s)265 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)266 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)267 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)268 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)269 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)270=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512271=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI272=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon273--- PASS: TestPathInfoHashCompatibility (0.00s)274 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)275 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)276 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)277 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)278=== CONT TestUploadMultipart_SupersededByPeer/exists279--- PASS: TestResolveStorePath (0.00s)280=== CONT TestUploadMultipart_SupersededByPeer/missing281=== CONT TestSetClientTLSErrors/missing_ca_file282--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)283 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)284 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)285=== CONT TestSetClientTLSErrors/missing_cert_file286=== CONT TestSetClientTLSErrors/missing_key_file287=== CONT TestSetClientTLSErrors/invalid_ca_file288=== CONT TestFilterOversizedClosures/no_limit_keeps_everything289=== CONT TestFilterOversizedClosures/all_closures_skipped2902026/07/19 11:32:19 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50291=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2922026/07/19 11:32:19 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000293--- PASS: TestFilterOversizedClosures (0.00s)294 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)295 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)296 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)297=== CONT TestPartSizeForNAR/zero_stays_at_minimum298=== CONT TestPartSizeForNAR/1_TiB299=== CONT TestPartSizeForNAR/capped_at_5_GiB300=== CONT TestPartSizeForNAR/5_TiB_S3_max_object301=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum302=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts303=== CONT TestPartSizeForNAR/small_stays_at_minimum304--- PASS: TestPartSizeForNAR (0.00s)305 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)306 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)307 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)308 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)309 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)310 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)311 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)312=== CONT TestSetClientTLS/rejects_connection_without_client_cert313=== CONT TestRateLimiterFeedback/429_enables_limiter314--- PASS: TestSetClientTLSErrors (0.02s)315 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)316 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)317 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)318 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)3192026/07/19 11:32:19 WARN Rate limiter enabled after throttle name=server-test rate=53202026/07/19 11:32:19 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:603343212026/07/19 11:32:19 WARN Rate limiter backed off name=server-test rate=5322=== CONT TestSetClientTLS/preserves_debug_logging_transport323--- PASS: TestScriptTokenEmptyToken (0.01s)324=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA325=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter326=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter327=== CONT TestRateLimiterFeedback/503_enables_limiter3282026/07/19 11:32:19 WARN Rate limiter enabled after throttle name=server-test rate=53292026/07/19 11:32:19 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:603423302026/07/19 11:32:19 WARN Rate limiter backed off name=server-test rate=5331--- PASS: TestRateLimiterFeedback (0.00s)332 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)333 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)334 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)335 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)3362026/07/19 11:32:19 http: TLS handshake error from 127.0.0.1:60333: read tcp 127.0.0.1:60328->127.0.0.1:60333: use of closed network connection337--- PASS: TestSetClientTLS (0.01s)338 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)339 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)340 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)341--- PASS: TestScriptTokenCachesUntilRefresh (0.05s)342--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)343--- PASS: TestDumpPathWriterError (0.06s)344--- PASS: TestDumpPathSingleFile (0.06s)345--- PASS: TestCaseHackSuffix (0.05s)346--- PASS: TestDumpPathMatchesNix (0.08s)347--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)348PASS349Running server tests...350The files belonging to this database system will be owned by user "_nixbld1".351This user must also own the server process.352353The database cluster will be initialized with locale "C".354The default database encoding has accordingly been set to "SQL_ASCII".355The default text search configuration will be set to "english".356357Data page checksums are enabled.358359creating directory /nix/var/nix/builds/nix-12522-1347016672/postgres130731467/data ... ok360creating subdirectories ... ok361selecting dynamic shared memory implementation ... posix362selecting default "max_connections" ... 100363selecting default "shared_buffers" ... 128MB364selecting default time zone ... UTC365creating configuration files ... ok366running bootstrap script ... ok367performing post-bootstrap initialization ... ok368syncing data to disk ... ok369370initdb: warning: enabling "trust" authentication for local connections371initdb: 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.372373Success. You can now start the database server using:374375 pg_ctl -D /nix/var/nix/builds/nix-12522-1347016672/postgres130731467/data -l logfile start376377/nix/var/nix/builds/nix-12522-1347016672/postgres130731467:5432 - no response3782026-07-19 11:32:20.905 UTC [12561] LOG: starting PostgreSQL 18.4 on aarch64-apple-darwin25.3.0, compiled by clang version 21.1.8, 64-bit3792026-07-19 11:32:20.905 UTC [12561] LOG: listening on Unix socket "/nix/var/nix/builds/nix-12522-1347016672/postgres130731467/.s.PGSQL.5432"3802026-07-19 11:32:20.907 UTC [12568] LOG: database system was shut down at 2026-07-19 11:32:20 UTC3812026-07-19 11:32:20.907 UTC [12561] LOG: database system is ready to accept connections382/nix/var/nix/builds/nix-12522-1347016672/postgres130731467:5432 - accepting connections383<jemalloc>: option background_thread currently supports pthread only384{"timestamp":"2026-07-19T11:32:21.028912Z","level":"ERROR","fields":{"message":"list_path_raw: revjob err VolumeNotFound"},"target":"rustfs_ecstore::cache_value::metacache_set","filename":"crates/ecstore/src/cache_value/metacache_set.rs","line_number":486,"threadName":"rustfs-worker","threadId":"ThreadId(5)"}385=== RUN TestService_AuthMiddleware386=== PAUSE TestService_AuthMiddleware387=== RUN TestService_AuthMiddleware_MTLSProxyHeader388=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader389=== RUN TestService_AuthMiddleware_MTLSBoundSubjects390=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects391=== RUN TestService_ReadAuthMiddleware392=== PAUSE TestService_ReadAuthMiddleware393=== RUN TestService_AuthMiddleware_OIDC394=== PAUSE TestService_AuthMiddleware_OIDC395=== RUN TestCacheConfigHandler396=== PAUSE TestCacheConfigHandler397=== RUN TestCacheStatsHandler398=== PAUSE TestCacheStatsHandler399=== RUN TestClientCADerivations400=== PAUSE TestClientCADerivations401=== RUN TestClientErrorHandling402=== PAUSE TestClientErrorHandling403=== RUN TestClientIntegration404=== PAUSE TestClientIntegration405=== RUN TestClientMultipleUploads406=== PAUSE TestClientMultipleUploads407=== RUN TestClientWithDependencies408=== PAUSE TestClientWithDependencies409=== RUN TestPinProtectsFromGC410=== PAUSE TestPinProtectsFromGC411=== RUN TestGCAdvisoryLockBlocksConcurrentRun4122026-07-19 11:32:21.179 UTC [12619] ERROR: relation "goose_db_version" does not exist at character 364132026-07-19 11:32:21.179 UTC [12619] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4142026/07/19 11:32:21 OK 20241026095416_initial_model.sql (3.06ms)4152026/07/19 11:32:21 OK 20251210153512_drop_unused_gin_index.sql (464.46µs)4162026/07/19 11:32:21 OK 20251218171726_add_pins.sql (806.5µs)4172026/07/19 11:32:21 OK 20260628120000_add_object_size_and_stats.sql (856.17µs)4182026/07/19 11:32:21 goose: successfully migrated database to version: 202606281200004192026/07/19 11:32:21 OK 1_commit_pending_closure.sql (813.21µs)4202026/07/19 11:32:21 OK 2_object_stats_trigger.sql (208.21µs)4212026/07/19 11:32:21 goose: up to current file version: 2422--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.07s)423=== RUN TestGCBugBareHashReferences424=== PAUSE TestGCBugBareHashReferences425=== RUN TestGCMetrics426=== PAUSE TestGCMetrics427=== RUN TestGCTaskStore_StartNew428=== PAUSE TestGCTaskStore_StartNew429=== RUN TestGCTaskStore_DeduplicateSameParams430=== PAUSE TestGCTaskStore_DeduplicateSameParams431=== RUN TestGCTaskStore_ConflictDifferentParams432=== PAUSE TestGCTaskStore_ConflictDifferentParams433=== RUN TestGCTaskStore_GetEmpty434=== PAUSE TestGCTaskStore_GetEmpty435=== RUN TestGCTaskStore_GetReturnsLatest436=== PAUSE TestGCTaskStore_GetReturnsLatest437=== RUN TestGCTaskStore_CompletedAllowsNewTask438=== PAUSE TestGCTaskStore_CompletedAllowsNewTask439=== RUN TestGCTaskStore_PhaseUpdates440=== PAUSE TestGCTaskStore_PhaseUpdates441=== RUN TestGCTaskStore_Fail442=== PAUSE TestGCTaskStore_Fail443=== RUN TestGracefulShutdownDrainsInflight444=== PAUSE TestGracefulShutdownDrainsInflight445=== RUN TestService_healthCheckHandler446=== PAUSE TestService_healthCheckHandler447=== RUN TestGenerateLandingPage448=== PAUSE TestGenerateLandingPage449=== RUN TestCacheConfigHandlerMaxNarSize450=== PAUSE TestCacheConfigHandlerMaxNarSize451=== RUN TestCreatePendingClosureRejectsOversizedNAR452=== PAUSE TestCreatePendingClosureRejectsOversizedNAR453=== RUN TestNARDeduplicationMetadataUploadBug454=== PAUSE TestNARDeduplicationMetadataUploadBug455=== RUN TestMetricsInventory456=== PAUSE TestMetricsInventory457=== RUN TestService_NativeMTLS458=== PAUSE TestService_NativeMTLS459=== RUN TestServerTLSConfig460=== PAUSE TestServerTLSConfig461=== RUN TestMultipartCleanup462=== PAUSE TestMultipartCleanup463=== RUN TestObjectStatsTrigger464=== PAUSE TestObjectStatsTrigger465=== RUN TestOrphanedObjectsGC466=== PAUSE TestOrphanedObjectsGC467=== RUN TestOrphanedObjectsGCStressTest468=== PAUSE TestOrphanedObjectsGCStressTest469=== RUN TestResurrectedObjectNotDeleted470=== PAUSE TestResurrectedObjectNotDeleted471=== RUN TestParseSingleRange472=== PAUSE TestParseSingleRange473=== RUN TestIsValidCachePath474=== PAUSE TestIsValidCachePath475=== RUN TestReadProxyNarinfo476=== PAUSE TestReadProxyNarinfo477=== RUN TestReadProxyNarinfoAlreadyDecompressed478=== PAUSE TestReadProxyNarinfoAlreadyDecompressed479=== RUN TestReadProxyNarStreaming480=== PAUSE TestReadProxyNarStreaming481=== RUN TestReadProxy404482=== PAUSE TestReadProxy404483=== RUN TestReadProxyInvalidPath484=== PAUSE TestReadProxyInvalidPath485=== RUN TestReadProxyHead486=== PAUSE TestReadProxyHead487=== RUN TestReadProxyConditionalGet488=== PAUSE TestReadProxyConditionalGet489=== RUN TestReadProxyRootRedirectsToIndexHTML490=== PAUSE TestReadProxyRootRedirectsToIndexHTML491=== RUN TestReadProxyDisabled492=== PAUSE TestReadProxyDisabled493=== RUN TestReadProxyRangeRequest494=== PAUSE TestReadProxyRangeRequest495=== RUN TestRedundantMultipartUpload496=== PAUSE TestRedundantMultipartUpload497=== RUN TestCompleteMultipartUpload_ErrorButObjectExists498=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists499=== RUN TestCompletedNarNotReofferedAcrossClosures500=== PAUSE TestCompletedNarNotReofferedAcrossClosures501=== RUN TestPresignedUploadRegisteredBeforeCommit502=== PAUSE TestPresignedUploadRegisteredBeforeCommit503=== RUN TestService_Rustfstest504=== PAUSE TestService_Rustfstest505=== RUN TestParseSize506=== PAUSE TestParseSize507=== RUN TestSkippedUploadsHandler508=== PAUSE TestSkippedUploadsHandler509=== RUN TestSystemdListenerNotActivated510--- PASS: TestSystemdListenerNotActivated (0.00s)511=== RUN TestWatchdogBeatsWhenHealthy512--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)513=== RUN TestWatchdogSkipsWhenUnhealthy5142026/07/19 11:32:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5152026/07/19 11:32:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5162026/07/19 11:32:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5172026/07/19 11:32:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5182026/07/19 11:32:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5192026/07/19 11:32:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5202026/07/19 11:32:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5212026/07/19 11:32:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5222026/07/19 11:32:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"523--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)524=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle525=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle526=== RUN TestProxyWriteTimeout527=== PAUSE TestProxyWriteTimeout528=== RUN TestIsValidUploadKey529=== PAUSE TestIsValidUploadKey530=== RUN TestUploadHandlersRejectInvalidKeys531=== PAUSE TestUploadHandlersRejectInvalidKeys532=== RUN TestUploadHandlersRejectOversizedBody533=== PAUSE TestUploadHandlersRejectOversizedBody534=== RUN TestService_cleanupPendingClosuresHandler535=== PAUSE TestService_cleanupPendingClosuresHandler536=== RUN TestService_createPendingClosureHandler537=== PAUSE TestService_createPendingClosureHandler538=== RUN TestService_verifyS3Integrity539=== PAUSE TestService_verifyS3Integrity540=== RUN TestCompleteMultipartUnregistered541=== PAUSE TestCompleteMultipartUnregistered542=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT543=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT544=== CONT TestService_AuthMiddleware545=== CONT TestObjectStatsTrigger546=== CONT TestCompleteMultipartUpload_ErrorButObjectExists547=== CONT TestReadProxy404548=== CONT TestIsValidUploadKey549=== RUN TestIsValidUploadKey/narinfo550=== CONT TestGCTaskStore_ConflictDifferentParams551--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)552=== CONT TestGCTaskStore_CompletedAllowsNewTask553--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)554=== CONT TestProxyWriteTimeout555=== RUN TestProxyWriteTimeout/narinfo556=== PAUSE TestProxyWriteTimeout/narinfo557=== CONT TestService_healthCheckHandler558=== CONT TestGracefulShutdownDrainsInflight559=== CONT TestGCTaskStore_Fail560--- PASS: TestGCTaskStore_Fail (0.00s)561=== CONT TestGCTaskStore_GetReturnsLatest562--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)563=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle564=== CONT TestGCTaskStore_PhaseUpdates565--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)566=== CONT TestGCTaskStore_GetEmpty567--- PASS: TestGCTaskStore_GetEmpty (0.00s)568=== CONT TestSkippedUploadsHandler569=== PAUSE TestIsValidUploadKey/narinfo570=== RUN TestProxyWriteTimeout/1_GiB_nar571=== PAUSE TestProxyWriteTimeout/1_GiB_nar572=== RUN TestIsValidUploadKey/nar_zst573=== RUN TestProxyWriteTimeout/10_GiB_nar574=== PAUSE TestProxyWriteTimeout/10_GiB_nar575=== RUN TestProxyWriteTimeout/unknown_size576=== PAUSE TestProxyWriteTimeout/unknown_size577=== PAUSE TestIsValidUploadKey/nar_zst578=== RUN TestIsValidUploadKey/nar_xz579=== PAUSE TestIsValidUploadKey/nar_xz580=== CONT TestParseSize581--- PASS: TestParseSize (0.00s)582=== CONT TestService_Rustfstest5832026/07/19 11:32:21 INFO Starting HTTP server address=127.0.0.1:60355584=== RUN TestIsValidUploadKey/nar_plain5852026/07/19 11:32:21 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000586=== PAUSE TestIsValidUploadKey/nar_plain587=== RUN TestIsValidUploadKey/listing588=== PAUSE TestIsValidUploadKey/listing589=== RUN TestIsValidUploadKey/build_log590=== PAUSE TestIsValidUploadKey/build_log591=== RUN TestIsValidUploadKey/build_log_home-manager_file592=== PAUSE TestIsValidUploadKey/build_log_home-manager_file593=== RUN TestIsValidUploadKey/build_log_plus_in_name594=== PAUSE TestIsValidUploadKey/build_log_plus_in_name595=== RUN TestIsValidUploadKey/build_log_question_mark596=== PAUSE TestIsValidUploadKey/build_log_question_mark597=== RUN TestIsValidUploadKey/build_log_equals598=== PAUSE TestIsValidUploadKey/build_log_equals599=== RUN TestIsValidUploadKey/realisation600=== PAUSE TestIsValidUploadKey/realisation601=== RUN TestIsValidUploadKey/realisation_plus_in_output602=== PAUSE TestIsValidUploadKey/realisation_plus_in_output603=== RUN TestIsValidUploadKey/nix-cache-info604=== PAUSE TestIsValidUploadKey/nix-cache-info605=== RUN TestIsValidUploadKey/index.html606=== PAUSE TestIsValidUploadKey/index.html607=== RUN TestIsValidUploadKey/narinfo_key,_nar_type608=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type609=== RUN TestIsValidUploadKey/nar_key,_narinfo_type610=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type611=== RUN TestIsValidUploadKey/listing_key,_narinfo_type612=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type613=== RUN TestIsValidUploadKey/traversal614=== PAUSE TestIsValidUploadKey/traversal615=== RUN TestIsValidUploadKey/traversal_nar616=== PAUSE TestIsValidUploadKey/traversal_nar617=== RUN TestIsValidUploadKey/absolute618=== PAUSE TestIsValidUploadKey/absolute619=== RUN TestIsValidUploadKey/empty_key620=== PAUSE TestIsValidUploadKey/empty_key621=== RUN TestIsValidUploadKey/unknown_type622=== PAUSE TestIsValidUploadKey/unknown_type623=== CONT TestPresignedUploadRegisteredBeforeCommit6242026/07/19 11:32:21 INFO Shutdown signal received, draining in-flight requests timeout=10s625--- PASS: TestSkippedUploadsHandler (0.01s)626=== CONT TestCompletedNarNotReofferedAcrossClosures627--- PASS: TestGracefulShutdownDrainsInflight (0.08s)628=== CONT TestService_createPendingClosureHandler6292026-07-19 11:32:21.658 UTC [12641] ERROR: relation "goose_db_version" does not exist at character 366302026-07-19 11:32:21.658 UTC [12641] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6312026-07-19 11:32:21.677 UTC [12642] ERROR: relation "goose_db_version" does not exist at character 366322026-07-19 11:32:21.677 UTC [12642] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6332026/07/19 11:32:21 OK 20241026095416_initial_model.sql (13.13ms)6342026-07-19 11:32:21.679 UTC [12643] ERROR: relation "goose_db_version" does not exist at character 366352026-07-19 11:32:21.679 UTC [12643] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6362026-07-19 11:32:21.680 UTC [12645] ERROR: relation "goose_db_version" does not exist at character 366372026-07-19 11:32:21.680 UTC [12645] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6382026-07-19 11:32:21.680 UTC [12644] ERROR: relation "goose_db_version" does not exist at character 366392026-07-19 11:32:21.680 UTC [12644] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6402026-07-19 11:32:21.681 UTC [12647] ERROR: relation "goose_db_version" does not exist at character 366412026-07-19 11:32:21.681 UTC [12647] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6422026-07-19 11:32:21.681 UTC [12646] ERROR: relation "goose_db_version" does not exist at character 366432026-07-19 11:32:21.681 UTC [12646] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6442026/07/19 11:32:21 OK 20251210153512_drop_unused_gin_index.sql (2.19ms)6452026-07-19 11:32:21.682 UTC [12649] ERROR: relation "goose_db_version" does not exist at character 366462026-07-19 11:32:21.682 UTC [12649] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6472026/07/19 11:32:21 OK 20251218171726_add_pins.sql (1.93ms)6482026-07-19 11:32:21.683 UTC [12648] ERROR: relation "goose_db_version" does not exist at character 366492026-07-19 11:32:21.683 UTC [12648] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6502026/07/19 11:32:21 OK 20260628120000_add_object_size_and_stats.sql (1.78ms)6512026/07/19 11:32:21 goose: successfully migrated database to version: 202606281200006522026/07/19 11:32:21 OK 1_commit_pending_closure.sql (1.19ms)6532026/07/19 11:32:21 OK 2_object_stats_trigger.sql (752.38µs)6542026/07/19 11:32:21 goose: up to current file version: 26552026-07-19 11:32:21.687 UTC [12650] ERROR: relation "goose_db_version" does not exist at character 366562026-07-19 11:32:21.687 UTC [12650] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6572026/07/19 11:32:21 OK 20241026095416_initial_model.sql (6.28ms)6582026/07/19 11:32:21 OK 20251210153512_drop_unused_gin_index.sql (1.31ms)6592026/07/19 11:32:21 OK 20241026095416_initial_model.sql (7.48ms)6602026/07/19 11:32:21 OK 20251210153512_drop_unused_gin_index.sql (818.38µs)6612026/07/19 11:32:21 OK 20241026095416_initial_model.sql (7.21ms)6622026/07/19 11:32:21 OK 20251210153512_drop_unused_gin_index.sql (527.13µs)6632026/07/19 11:32:21 OK 20241026095416_initial_model.sql (9.26ms)6642026/07/19 11:32:21 OK 20241026095416_initial_model.sql (7.12ms)6652026/07/19 11:32:21 OK 20251210153512_drop_unused_gin_index.sql (539.38µs)6662026/07/19 11:32:21 OK 20251210153512_drop_unused_gin_index.sql (634.46µs)6672026/07/19 11:32:21 OK 20251218171726_add_pins.sql (2.34ms)6682026/07/19 11:32:21 OK 20251218171726_add_pins.sql (1.36ms)6692026/07/19 11:32:21 OK 20241026095416_initial_model.sql (7.77ms)670--- PASS: TestObjectStatsTrigger (0.28s)671=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT6722026/07/19 11:32:21 OK 20251210153512_drop_unused_gin_index.sql (678.33µs)6732026/07/19 11:32:21 OK 20241026095416_initial_model.sql (6.92ms)6742026/07/19 11:32:21 OK 20251218171726_add_pins.sql (2.4ms)6752026/07/19 11:32:21 OK 20251218171726_add_pins.sql (1.85ms)6762026/07/19 11:32:21 OK 20260628120000_add_object_size_and_stats.sql (1.94ms)6772026/07/19 11:32:21 goose: successfully migrated database to version: 202606281200006782026/07/19 11:32:21 OK 20251210153512_drop_unused_gin_index.sql (1.36ms)6792026/07/19 11:32:21 OK 20251218171726_add_pins.sql (2.52ms)6802026/07/19 11:32:21 OK 20241026095416_initial_model.sql (8.38ms)6812026/07/19 11:32:21 OK 20260628120000_add_object_size_and_stats.sql (2.58ms)6822026/07/19 11:32:21 goose: successfully migrated database to version: 202606281200006832026/07/19 11:32:21 OK 20251218171726_add_pins.sql (1.96ms)6842026/07/19 11:32:21 OK 20260628120000_add_object_size_and_stats.sql (1.2ms)6852026/07/19 11:32:21 goose: successfully migrated database to version: 202606281200006862026/07/19 11:32:21 OK 20251210153512_drop_unused_gin_index.sql (592.92µs)6872026/07/19 11:32:21 OK 1_commit_pending_closure.sql (1.07ms)6882026/07/19 11:32:21 OK 20260628120000_add_object_size_and_stats.sql (2.07ms)6892026/07/19 11:32:21 goose: successfully migrated database to version: 202606281200006902026/07/19 11:32:21 OK 1_commit_pending_closure.sql (1.48ms)6912026/07/19 11:32:21 OK 2_object_stats_trigger.sql (314.5µs)6922026/07/19 11:32:21 goose: up to current file version: 26932026/07/19 11:32:21 OK 1_commit_pending_closure.sql (1.3ms)6942026/07/19 11:32:21 OK 20260628120000_add_object_size_and_stats.sql (1.66ms)6952026/07/19 11:32:21 goose: successfully migrated database to version: 202606281200006962026/07/19 11:32:21 OK 2_object_stats_trigger.sql (561.54µs)6972026/07/19 11:32:21 goose: up to current file version: 26982026/07/19 11:32:21 OK 20251218171726_add_pins.sql (2.42ms)6992026/07/19 11:32:21 OK 20260628120000_add_object_size_and_stats.sql (2.19ms)7002026/07/19 11:32:21 goose: successfully migrated database to version: 202606281200007012026/07/19 11:32:21 OK 2_object_stats_trigger.sql (477.58µs)7022026/07/19 11:32:21 goose: up to current file version: 27032026/07/19 11:32:21 OK 20251218171726_add_pins.sql (1.77ms)7042026/07/19 11:32:21 OK 1_commit_pending_closure.sql (1.22ms)7052026/07/19 11:32:21 OK 20241026095416_initial_model.sql (7.26ms)7062026/07/19 11:32:21 OK 2_object_stats_trigger.sql (298.88µs)7072026/07/19 11:32:21 goose: up to current file version: 27082026/07/19 11:32:21 OK 1_commit_pending_closure.sql (1.12ms)7092026/07/19 11:32:21 OK 20260628120000_add_object_size_and_stats.sql (1.23ms)7102026/07/19 11:32:21 goose: successfully migrated database to version: 202606281200007112026/07/19 11:32:21 OK 1_commit_pending_closure.sql (1.37ms)7122026/07/19 11:32:21 OK 2_object_stats_trigger.sql (646.71µs)7132026/07/19 11:32:21 goose: up to current file version: 27142026/07/19 11:32:21 OK 20251210153512_drop_unused_gin_index.sql (629.71µs)7152026/07/19 11:32:21 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"716--- PASS: TestService_AuthMiddleware (0.28s)717=== CONT TestCompleteMultipartUnregistered7182026/07/19 11:32:21 INFO Received uploads request method=POST path=/api/pending_closures7192026/07/19 11:32:21 INFO Received uploads request method=POST path=/api/pending_closures7202026/07/19 11:32:21 OK 20260628120000_add_object_size_and_stats.sql (1.58ms)7212026/07/19 11:32:21 goose: successfully migrated database to version: 202606281200007222026/07/19 11:32:21 OK 2_object_stats_trigger.sql (807.33µs)7232026/07/19 11:32:21 goose: up to current file version: 2724--- PASS: TestService_healthCheckHandler (0.28s)725=== CONT TestService_verifyS3Integrity7262026/07/19 11:32:21 OK 20251218171726_add_pins.sql (1.84ms)7272026/07/19 11:32:21 OK 1_commit_pending_closure.sql (2.43ms)7282026/07/19 11:32:21 OK 1_commit_pending_closure.sql (2.07ms)7292026/07/19 11:32:21 OK 2_object_stats_trigger.sql (778.5µs)7302026/07/19 11:32:21 goose: up to current file version: 27312026/07/19 11:32:21 OK 2_object_stats_trigger.sql (598.21µs)7322026/07/19 11:32:21 goose: up to current file version: 27332026/07/19 11:32:21 OK 20260628120000_add_object_size_and_stats.sql (1.66ms)7342026/07/19 11:32:21 goose: successfully migrated database to version: 20260628120000735--- PASS: TestService_Rustfstest (0.28s)736=== CONT TestMetricsInventory7372026/07/19 11:32:21 INFO Received uploads request method=POST path=/api/pending_closures7382026/07/19 11:32:21 OK 1_commit_pending_closure.sql (1.29ms)7392026/07/19 11:32:21 INFO Received uploads request method=POST path=/api/pending_closures7402026/07/19 11:32:21 OK 2_object_stats_trigger.sql (855.38µs)7412026/07/19 11:32:21 goose: up to current file version: 2742--- PASS: TestReadProxy404 (0.29s)743=== CONT TestMultipartCleanup7442026/07/19 11:32:21 INFO Received uploads request method=POST path=/api/pending_closures7452026/07/19 11:32:21 INFO Received uploads request method=POST path=/api/pending_closures7462026/07/19 11:32:21 INFO Received uploads request method=POST path=/api/pending_closures747{"timestamp":"2026-07-19T11:32:21.710273Z","level":"ERROR","fields":{"message":"system path read failed","path_kind":"data_usage","operation":"read_primary","reason":"config_not_found","object":"buckets/.usage.json","error":"Config not found"},"target":"rustfs_ecstore::data_usage","filename":"crates/ecstore/src/data_usage.rs","line_number":126,"threadName":"rustfs-worker","threadId":"ThreadId(11)"}7482026/07/19 11:32:21 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst7492026/07/19 11:32:21 INFO Received uploads request method=POST path=/api/pending_closures750--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.29s)751=== CONT TestServerTLSConfig752=== RUN TestServerTLSConfig/no_client_CA753=== PAUSE TestServerTLSConfig/no_client_CA754=== RUN TestServerTLSConfig/missing_CA_file755=== PAUSE TestServerTLSConfig/missing_CA_file756=== RUN TestServerTLSConfig/not_a_PEM_file757=== PAUSE TestServerTLSConfig/not_a_PEM_file758=== CONT TestService_NativeMTLS7592026/07/19 11:32:21 INFO Received complete multipart upload request method=POST path=/api/multipart/complete760{"timestamp":"2026-07-19T11:32:21.719663Z","level":"ERROR","fields":{"message":"complete_multipart_upload part error: \"part.1 not found\""},"target":"rustfs_ecstore::set_disk","filename":"crates/ecstore/src/set_disk.rs","line_number":3463,"threadName":"rustfs-worker","threadId":"ThreadId(5)"}761{"timestamp":"2026-07-19T11:32:21.719682Z","level":"ERROR","fields":{"message":"complete_multipart_upload etag err client=Some(\"deadbeef\"), stored=\"\", part_id=1, bucket=bucket3, object=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst"},"target":"rustfs_ecstore::set_disk","filename":"crates/ecstore/src/set_disk.rs","line_number":3534,"threadName":"rustfs-worker","threadId":"ThreadId(5)"}7622026/07/19 11:32:21 WARN CompleteMultipartUpload errored but object exists; treating as success error="One or more of the specified parts could not be found. The part may not have been uploaded, or the specified entity tag may not match the part's entity tag." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MTM4NTQ3NWItMGIwZC00Yjg1LThjOWQtNjUwODE0ZGM2ZjkyLjI1YTQ5ZmUyLWJkMGQtNGU5Mi05MTExLWQyY2IzZTIzNWNjOHgxNzg0NDYwNzQxNzA0MDQ1MDAw7632026/07/19 11:32:21 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MTM4NTQ3NWItMGIwZC00Yjg1LThjOWQtNjUwODE0ZGM2ZjkyLjI1YTQ5ZmUyLWJkMGQtNGU5Mi05MTExLWQyY2IzZTIzNWNjOHgxNzg0NDYwNzQxNzA0MDQ1MDAw parts=1764--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.31s)765=== CONT TestReadProxyRootRedirectsToIndexHTML7662026/07/19 11:32:21 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7672026/07/19 11:32:21 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7682026/07/19 11:32:21 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MTM4NTQ3NWItMGIwZC00Yjg1LThjOWQtNjUwODE0ZGM2ZjkyLjIzOTJlNzljLTY5YjQtNDVmYS1hY2JjLTcyMGRlNTdiNjM2MngxNzg0NDYwNzQxNzExNjA5MDAw parts=107692026/07/19 11:32:21 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7702026/07/19 11:32:21 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7712026/07/19 11:32:21 INFO Completed upload id=17722026/07/19 11:32:21 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000007732026/07/19 11:32:21 INFO Received uploads request method=POST path=/api/pending_closures7742026/07/19 11:32:21 INFO Starting cleanup of old closures method=DELETE path=/api/closures7752026/07/19 11:32:21 INFO Aborted multipart uploads count=07762026/07/19 11:32:21 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MTM4NTQ3NWItMGIwZC00Yjg1LThjOWQtNjUwODE0ZGM2ZjkyLjQ5MTQwNjVmLWVmODctNGViNy1iOTljLTA1ZTg2YzY3ZGY3ZHgxNzg0NDYwNzQxNzA4ODgwMDAw parts=127772026/07/19 11:32:21 INFO Received uploads request method=POST path=/api/pending_closures778--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.44s)779=== CONT TestRedundantMultipartUpload7802026/07/19 11:32:21 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=07812026/07/19 11:32:21 INFO Vacuumed table table=pending_closures7822026-07-19 11:32:21.873 UTC [12667] ERROR: relation "goose_db_version" does not exist at character 367832026-07-19 11:32:21.873 UTC [12667] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7842026/07/19 11:32:21 INFO Vacuumed table table=pending_objects7852026/07/19 11:32:21 INFO Vacuumed table table=multipart_uploads7862026/07/19 11:32:21 INFO Vacuumed table table=closures7872026/07/19 11:32:21 INFO Vacuumed table table=objects7882026/07/19 11:32:21 OK 20241026095416_initial_model.sql (47.82ms)7892026/07/19 11:32:21 OK 20251210153512_drop_unused_gin_index.sql (427.29µs)7902026/07/19 11:32:21 OK 20251218171726_add_pins.sql (2.62ms)7912026/07/19 11:32:21 OK 20260628120000_add_object_size_and_stats.sql (6.05ms)7922026/07/19 11:32:21 goose: successfully migrated database to version: 202606281200007932026/07/19 11:32:21 OK 1_commit_pending_closure.sql (974.29µs)7942026/07/19 11:32:21 OK 2_object_stats_trigger.sql (199.92µs)7952026/07/19 11:32:21 goose: up to current file version: 27962026/07/19 11:32:21 INFO Received uploads request method=POST path=/api/pending_closures7972026-07-19 11:32:21.945 UTC [12669] ERROR: relation "goose_db_version" does not exist at character 367982026-07-19 11:32:21.945 UTC [12669] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7992026-07-19 11:32:21.955 UTC [12670] ERROR: relation "goose_db_version" does not exist at character 368002026-07-19 11:32:21.955 UTC [12670] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8012026/07/19 11:32:21 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000802--- PASS: TestService_createPendingClosureHandler (0.46s)803=== CONT TestReadProxyRangeRequest804--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.26s)805=== CONT TestReadProxyDisabled8062026/07/19 11:32:21 OK 20241026095416_initial_model.sql (9.87ms)8072026/07/19 11:32:21 OK 20251210153512_drop_unused_gin_index.sql (389.92µs)8082026/07/19 11:32:21 OK 20251218171726_add_pins.sql (781.29µs)8092026-07-19 11:32:21.973 UTC [12675] ERROR: relation "goose_db_version" does not exist at character 368102026-07-19 11:32:21.973 UTC [12675] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8112026/07/19 11:32:21 OK 20241026095416_initial_model.sql (18.79ms)8122026/07/19 11:32:21 OK 20251210153512_drop_unused_gin_index.sql (358µs)8132026/07/19 11:32:21 OK 20260628120000_add_object_size_and_stats.sql (7.53ms)8142026/07/19 11:32:21 goose: successfully migrated database to version: 202606281200008152026/07/19 11:32:21 OK 20251218171726_add_pins.sql (1.09ms)8162026/07/19 11:32:21 OK 1_commit_pending_closure.sql (1.15ms)8172026/07/19 11:32:21 OK 2_object_stats_trigger.sql (327.25µs)8182026/07/19 11:32:21 goose: up to current file version: 28192026/07/19 11:32:21 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8202026/07/19 11:32:21 OK 20260628120000_add_object_size_and_stats.sql (3.01ms)8212026/07/19 11:32:21 goose: successfully migrated database to version: 202606281200008222026/07/19 11:32:21 OK 1_commit_pending_closure.sql (763.13µs)8232026/07/19 11:32:21 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst824--- PASS: TestCompleteMultipartUnregistered (0.28s)825=== CONT TestReadProxyHead8262026/07/19 11:32:21 OK 2_object_stats_trigger.sql (367.92µs)8272026/07/19 11:32:21 goose: up to current file version: 28282026/07/19 11:32:21 INFO Received uploads request method=POST path=/api/pending_closures8292026/07/19 11:32:21 OK 20241026095416_initial_model.sql (8.64ms)8302026/07/19 11:32:21 OK 20251210153512_drop_unused_gin_index.sql (805.42µs)8312026/07/19 11:32:21 OK 20251218171726_add_pins.sql (2.99ms)8322026/07/19 11:32:21 OK 20260628120000_add_object_size_and_stats.sql (3.6ms)8332026/07/19 11:32:21 goose: successfully migrated database to version: 202606281200008342026/07/19 11:32:21 OK 1_commit_pending_closure.sql (1.25ms)8352026/07/19 11:32:21 OK 2_object_stats_trigger.sql (393.63µs)8362026/07/19 11:32:21 goose: up to current file version: 2837--- PASS: TestMetricsInventory (0.30s)838=== CONT TestReadProxyConditionalGet8392026/07/19 11:32:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8402026-07-19 11:32:22.102 UTC [12680] ERROR: relation "goose_db_version" does not exist at character 368412026-07-19 11:32:22.102 UTC [12680] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8422026/07/19 11:32:22 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MTM4NTQ3NWItMGIwZC00Yjg1LThjOWQtNjUwODE0ZGM2ZjkyLjhiMGU0ODY3LTA1YzEtNDNhNC1iYjQ4LWY2ODRiMTAwNGQ2YngxNzg0NDYwNzQxOTkwMjk2MDAw parts=108432026/07/19 11:32:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8442026/07/19 11:32:22 INFO Completed upload id=18452026/07/19 11:32:22 INFO Received uploads request method=POST path=/api/pending_closures8462026/07/19 11:32:22 INFO Received uploads request method=POST path=/api/pending_closures8472026/07/19 11:32:22 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo8482026/07/19 11:32:22 WARN Found objects in DB but missing from S3, will re-upload count=1849--- PASS: TestService_verifyS3Integrity (0.41s)850=== CONT TestCreatePendingClosureRejectsOversizedNAR8512026/07/19 11:32:22 INFO Received uploads request method=POST path=/api/pending_closures852--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)853=== CONT TestNARDeduplicationMetadataUploadBug8542026-07-19 11:32:22.122 UTC [12682] ERROR: relation "goose_db_version" does not exist at character 368552026-07-19 11:32:22.122 UTC [12682] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8562026/07/19 11:32:22 OK 20241026095416_initial_model.sql (15.61ms)8572026/07/19 11:32:22 OK 20251210153512_drop_unused_gin_index.sql (520.13µs)8582026/07/19 11:32:22 OK 20251218171726_add_pins.sql (752.88µs)8592026/07/19 11:32:22 OK 20260628120000_add_object_size_and_stats.sql (8.54ms)8602026/07/19 11:32:22 goose: successfully migrated database to version: 202606281200008612026/07/19 11:32:22 OK 20241026095416_initial_model.sql (11.85ms)8622026/07/19 11:32:22 OK 20251210153512_drop_unused_gin_index.sql (348.75µs)8632026/07/19 11:32:22 OK 1_commit_pending_closure.sql (956.5µs)8642026/07/19 11:32:22 OK 20251218171726_add_pins.sql (727.67µs)8652026/07/19 11:32:22 OK 2_object_stats_trigger.sql (250.29µs)8662026/07/19 11:32:22 goose: up to current file version: 28672026/07/19 11:32:22 INFO Received uploads request method=POST path=/api/pending_closures8682026-07-19 11:32:22.149 UTC [12684] ERROR: relation "goose_db_version" does not exist at character 368692026-07-19 11:32:22.149 UTC [12684] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8702026/07/19 11:32:22 OK 20260628120000_add_object_size_and_stats.sql (23.98ms)8712026/07/19 11:32:22 goose: successfully migrated database to version: 202606281200008722026/07/19 11:32:22 OK 1_commit_pending_closure.sql (1.11ms)8732026/07/19 11:32:22 OK 2_object_stats_trigger.sql (356.5µs)8742026/07/19 11:32:22 goose: up to current file version: 28752026/07/19 11:32:22 WARN mTLS auth: subject not in bound subjects subject="CN=reader"8762026/07/19 11:32:22 WARN mTLS auth: subject not in bound subjects subject="CN=writer"877--- PASS: TestService_NativeMTLS (0.46s)878=== CONT TestCacheConfigHandlerMaxNarSize879--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)880=== CONT TestParseSingleRange881=== RUN TestParseSingleRange/none882=== PAUSE TestParseSingleRange/none883=== RUN TestParseSingleRange/unknown_unit884=== PAUSE TestParseSingleRange/unknown_unit885=== RUN TestParseSingleRange/multi-range_ignored886=== PAUSE TestParseSingleRange/multi-range_ignored887=== RUN TestParseSingleRange/malformed_no_dash888=== PAUSE TestParseSingleRange/malformed_no_dash889=== RUN TestParseSingleRange/malformed_both_empty890=== PAUSE TestParseSingleRange/malformed_both_empty891=== RUN TestParseSingleRange/malformed_end_before_start892=== PAUSE TestParseSingleRange/malformed_end_before_start893=== RUN TestParseSingleRange/closed894=== PAUSE TestParseSingleRange/closed895=== RUN TestParseSingleRange/open-ended896=== PAUSE TestParseSingleRange/open-ended897=== RUN TestParseSingleRange/end_clamped_to_size898=== PAUSE TestParseSingleRange/end_clamped_to_size899=== RUN TestParseSingleRange/suffix900=== PAUSE TestParseSingleRange/suffix901=== RUN TestParseSingleRange/suffix_exceeds_size902=== PAUSE TestParseSingleRange/suffix_exceeds_size903=== RUN TestParseSingleRange/single_byte904=== PAUSE TestParseSingleRange/single_byte905=== RUN TestParseSingleRange/start_past_EOF906=== PAUSE TestParseSingleRange/start_past_EOF907=== RUN TestParseSingleRange/start_far_past_EOF908=== PAUSE TestParseSingleRange/start_far_past_EOF909=== CONT TestReadProxyNarinfoAlreadyDecompressed9102026/07/19 11:32:22 OK 20241026095416_initial_model.sql (7.8ms)9112026/07/19 11:32:22 OK 20251210153512_drop_unused_gin_index.sql (393µs)9122026/07/19 11:32:22 OK 20251218171726_add_pins.sql (1.13ms)9132026/07/19 11:32:22 OK 20260628120000_add_object_size_and_stats.sql (2.75ms)9142026/07/19 11:32:22 goose: successfully migrated database to version: 202606281200009152026/07/19 11:32:22 OK 1_commit_pending_closure.sql (1.17ms)9162026/07/19 11:32:22 OK 2_object_stats_trigger.sql (240.29µs)9172026/07/19 11:32:22 goose: up to current file version: 2918--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.46s)919=== CONT TestReadProxyNarinfo9202026/07/19 11:32:22 INFO Received cleanup request method=DELETE path=/api/pending_closures9212026/07/19 11:32:22 INFO Aborted multipart uploads count=1922--- PASS: TestMultipartCleanup (0.57s)923=== CONT TestIsValidCachePath924=== RUN TestIsValidCachePath/narinfo925=== PAUSE TestIsValidCachePath/narinfo926=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars927=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars928=== RUN TestIsValidCachePath/nar_zst929=== PAUSE TestIsValidCachePath/nar_zst930=== RUN TestIsValidCachePath/nar_xz931=== PAUSE TestIsValidCachePath/nar_xz932=== RUN TestIsValidCachePath/nar_bz2933=== PAUSE TestIsValidCachePath/nar_bz2934=== RUN TestIsValidCachePath/nar_uncompressed935=== PAUSE TestIsValidCachePath/nar_uncompressed936=== RUN TestIsValidCachePath/ls937=== PAUSE TestIsValidCachePath/ls938=== RUN TestIsValidCachePath/log939=== PAUSE TestIsValidCachePath/log940=== RUN TestIsValidCachePath/realisation941=== PAUSE TestIsValidCachePath/realisation942=== RUN TestIsValidCachePath/nix-cache-info943=== PAUSE TestIsValidCachePath/nix-cache-info944=== RUN TestIsValidCachePath/index.html945=== PAUSE TestIsValidCachePath/index.html946=== RUN TestIsValidCachePath/traversal_parent947=== PAUSE TestIsValidCachePath/traversal_parent948=== RUN TestIsValidCachePath/traversal_in_middle949=== PAUSE TestIsValidCachePath/traversal_in_middle950=== RUN TestIsValidCachePath/invalid_char_e951=== PAUSE TestIsValidCachePath/invalid_char_e952=== RUN TestIsValidCachePath/invalid_char_u953=== PAUSE TestIsValidCachePath/invalid_char_u954=== RUN TestIsValidCachePath/random_path955=== PAUSE TestIsValidCachePath/random_path956=== RUN TestIsValidCachePath/empty957=== PAUSE TestIsValidCachePath/empty958=== RUN TestIsValidCachePath/leading_slash959=== PAUSE TestIsValidCachePath/leading_slash960=== RUN TestIsValidCachePath/wrong_extension961=== PAUSE TestIsValidCachePath/wrong_extension962=== RUN TestIsValidCachePath/short_hash963=== PAUSE TestIsValidCachePath/short_hash964=== CONT TestUploadHandlersRejectOversizedBody965=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure966=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure967=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart968=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart969=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts970=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts971=== CONT TestService_cleanupPendingClosuresHandler9722026-07-19 11:32:22.369 UTC [12691] ERROR: relation "goose_db_version" does not exist at character 369732026-07-19 11:32:22.369 UTC [12691] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9742026-07-19 11:32:22.369 UTC [12692] ERROR: relation "goose_db_version" does not exist at character 369752026-07-19 11:32:22.369 UTC [12692] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9762026-07-19 11:32:22.369 UTC [12693] ERROR: relation "goose_db_version" does not exist at character 369772026-07-19 11:32:22.369 UTC [12693] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9782026/07/19 11:32:22 OK 20241026095416_initial_model.sql (20.98ms)9792026/07/19 11:32:22 OK 20251210153512_drop_unused_gin_index.sql (356.33µs)9802026/07/19 11:32:22 OK 20251218171726_add_pins.sql (799.63µs)9812026/07/19 11:32:22 OK 20241026095416_initial_model.sql (7.82ms)9822026/07/19 11:32:22 OK 20251210153512_drop_unused_gin_index.sql (339.63µs)9832026/07/19 11:32:22 OK 20241026095416_initial_model.sql (8.77ms)9842026/07/19 11:32:22 OK 20251210153512_drop_unused_gin_index.sql (305.17µs)9852026/07/19 11:32:22 OK 20251218171726_add_pins.sql (2.25ms)9862026/07/19 11:32:22 OK 20251218171726_add_pins.sql (1.05ms)9872026/07/19 11:32:22 OK 20260628120000_add_object_size_and_stats.sql (5.4ms)9882026/07/19 11:32:22 goose: successfully migrated database to version: 202606281200009892026/07/19 11:32:22 OK 1_commit_pending_closure.sql (1.27ms)9902026/07/19 11:32:22 OK 2_object_stats_trigger.sql (221.17µs)9912026/07/19 11:32:22 goose: up to current file version: 29922026/07/19 11:32:22 OK 20260628120000_add_object_size_and_stats.sql (3.59ms)9932026/07/19 11:32:22 goose: successfully migrated database to version: 202606281200009942026/07/19 11:32:22 OK 20260628120000_add_object_size_and_stats.sql (3.33ms)9952026/07/19 11:32:22 goose: successfully migrated database to version: 202606281200009962026/07/19 11:32:22 OK 1_commit_pending_closure.sql (1.37ms)9972026/07/19 11:32:22 OK 1_commit_pending_closure.sql (1.48ms)9982026/07/19 11:32:22 OK 2_object_stats_trigger.sql (206.29µs)9992026/07/19 11:32:22 goose: up to current file version: 210002026/07/19 11:32:22 OK 2_object_stats_trigger.sql (214.63µs)10012026/07/19 11:32:22 goose: up to current file version: 210022026/07/19 11:32:22 INFO Received uploads request method=POST path=/api/pending_closures1003--- PASS: TestReadProxyDisabled (0.46s)1004=== CONT TestGCBugBareHashReferences1005--- PASS: TestReadProxyRangeRequest (0.47s)1006=== CONT TestGCTaskStore_DeduplicateSameParams1007--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1008=== CONT TestGCTaskStore_StartNew1009--- PASS: TestGCTaskStore_StartNew (0.00s)1010=== CONT TestGCMetrics10112026-07-19 11:32:22.432 UTC [12719] ERROR: relation "goose_db_version" does not exist at character 3610122026-07-19 11:32:22.432 UTC [12719] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10132026/07/19 11:32:22 INFO Received uploads request method=POST path=/api/pending_closures10142026/07/19 11:32:22 OK 20241026095416_initial_model.sql (7.25ms)10152026/07/19 11:32:22 OK 20251210153512_drop_unused_gin_index.sql (455µs)10162026/07/19 11:32:22 OK 20251218171726_add_pins.sql (745.58µs)10172026/07/19 11:32:22 OK 20260628120000_add_object_size_and_stats.sql (4.03ms)10182026/07/19 11:32:22 goose: successfully migrated database to version: 2026062812000010192026/07/19 11:32:22 OK 1_commit_pending_closure.sql (938.71µs)10202026/07/19 11:32:22 OK 2_object_stats_trigger.sql (208.88µs)10212026/07/19 11:32:22 goose: up to current file version: 21022--- PASS: TestReadProxyHead (0.47s)1023=== CONT TestReadProxyInvalidPath10242026-07-19 11:32:22.491 UTC [12722] ERROR: relation "goose_db_version" does not exist at character 3610252026-07-19 11:32:22.491 UTC [12722] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10262026/07/19 11:32:22 OK 20241026095416_initial_model.sql (12.49ms)10272026/07/19 11:32:22 OK 20251210153512_drop_unused_gin_index.sql (452.75µs)10282026/07/19 11:32:22 OK 20251218171726_add_pins.sql (777.79µs)10292026/07/19 11:32:22 OK 20260628120000_add_object_size_and_stats.sql (12.92ms)10302026/07/19 11:32:22 goose: successfully migrated database to version: 2026062812000010312026/07/19 11:32:22 OK 1_commit_pending_closure.sql (1.88ms)10322026/07/19 11:32:22 OK 2_object_stats_trigger.sql (314.75µs)10332026/07/19 11:32:22 goose: up to current file version: 21034--- PASS: TestReadProxyConditionalGet (0.54s)1035=== CONT TestUploadHandlersRejectInvalidKeys1036=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1037=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1038=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1039=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1040=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1041=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1042=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1043=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1044=== CONT TestClientWithDependencies10452026/07/19 11:32:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10462026/07/19 11:32:22 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MTM4NTQ3NWItMGIwZC00Yjg1LThjOWQtNjUwODE0ZGM2ZjkyLjEzMDZjNzJlLTQ1NGItNDRmNy04ZTRjLTRmMjQ4YzI4MWMwN3gxNzg0NDYwNzQyNDM4MDM2MDAw parts=121047--- PASS: TestRedundantMultipartUpload (0.70s)1048=== CONT TestPinProtectsFromGC10492026-07-19 11:32:22.595 UTC [12727] ERROR: relation "goose_db_version" does not exist at character 3610502026-07-19 11:32:22.595 UTC [12727] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10512026-07-19 11:32:22.615 UTC [12728] ERROR: relation "goose_db_version" does not exist at character 3610522026-07-19 11:32:22.615 UTC [12728] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10532026/07/19 11:32:22 OK 20241026095416_initial_model.sql (19.88ms)10542026/07/19 11:32:22 OK 20251210153512_drop_unused_gin_index.sql (756.58µs)10552026/07/19 11:32:22 OK 20251218171726_add_pins.sql (1.5ms)10562026/07/19 11:32:22 OK 20260628120000_add_object_size_and_stats.sql (6.29ms)10572026/07/19 11:32:22 goose: successfully migrated database to version: 2026062812000010582026/07/19 11:32:22 OK 1_commit_pending_closure.sql (1.97ms)10592026/07/19 11:32:22 OK 2_object_stats_trigger.sql (267.04µs)10602026/07/19 11:32:22 goose: up to current file version: 210612026/07/19 11:32:22 OK 20241026095416_initial_model.sql (10.54ms)10622026/07/19 11:32:22 OK 20251210153512_drop_unused_gin_index.sql (503.54µs)10632026/07/19 11:32:22 OK 20251218171726_add_pins.sql (1.01ms)10642026/07/19 11:32:22 INFO Created nix-cache-info in bucket bucket=bucket2410652026/07/19 11:32:22 OK 20260628120000_add_object_size_and_stats.sql (5.44ms)10662026/07/19 11:32:22 goose: successfully migrated database to version: 2026062812000010672026/07/19 11:32:22 OK 1_commit_pending_closure.sql (940.13µs)10682026/07/19 11:32:22 OK 2_object_stats_trigger.sql (226.13µs)10692026/07/19 11:32:22 goose: up to current file version: 21070--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.48s)1071=== CONT TestCacheConfigHandler1072=== RUN TestCacheConfigHandler/full_config,_no_issuer1073=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1074=== RUN TestCacheConfigHandler/no_cache_url_configured1075=== PAUSE TestCacheConfigHandler/no_cache_url_configured1076=== RUN TestCacheConfigHandler/no_signing_keys1077=== PAUSE TestCacheConfigHandler/no_signing_keys1078=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1079=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1080=== CONT TestClientIntegration10812026-07-19 11:32:22.664 UTC [12732] ERROR: relation "goose_db_version" does not exist at character 3610822026-07-19 11:32:22.664 UTC [12732] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1083=== NAME TestNARDeduplicationMetadataUploadBug1084 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-12522-1347016672/TestNARDeduplicationMetadataUploadBug4126895497/001/store/yjbva8ljmjf7jyi45a60p4x7xlccl6xj-file1.txt10852026/07/19 11:32:22 OK 20241026095416_initial_model.sql (29.62ms)10862026/07/19 11:32:22 OK 20251210153512_drop_unused_gin_index.sql (442.08µs)10872026/07/19 11:32:22 OK 20251218171726_add_pins.sql (728.46µs)10882026/07/19 11:32:22 OK 20260628120000_add_object_size_and_stats.sql (3.81ms)10892026/07/19 11:32:22 goose: successfully migrated database to version: 2026062812000010902026/07/19 11:32:22 OK 1_commit_pending_closure.sql (1.34ms)10912026/07/19 11:32:22 OK 2_object_stats_trigger.sql (230.96µs)10922026/07/19 11:32:22 goose: up to current file version: 21093--- PASS: TestReadProxyNarinfo (0.53s)1094=== CONT TestClientErrorHandling1095=== RUN TestClientErrorHandling/InvalidStorePath1096=== PAUSE TestClientErrorHandling/InvalidStorePath1097=== RUN TestClientErrorHandling/InvalidAuthToken1098=== PAUSE TestClientErrorHandling/InvalidAuthToken1099=== RUN TestClientErrorHandling/ServerNotAvailable1100=== PAUSE TestClientErrorHandling/ServerNotAvailable1101=== CONT TestClientCADerivations11022026-07-19 11:32:22.741 UTC [12739] ERROR: relation "goose_db_version" does not exist at character 3611032026-07-19 11:32:22.741 UTC [12739] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11042026/07/19 11:32:22 OK 20241026095416_initial_model.sql (11.79ms)11052026/07/19 11:32:22 OK 20251210153512_drop_unused_gin_index.sql (512.79µs)11062026/07/19 11:32:22 OK 20251218171726_add_pins.sql (906µs)11072026/07/19 11:32:22 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"11082026/07/19 11:32:22 OK 20260628120000_add_object_size_and_stats.sql (12.71ms)11092026/07/19 11:32:22 goose: successfully migrated database to version: 2026062812000011102026/07/19 11:32:22 OK 1_commit_pending_closure.sql (1.15ms)11112026/07/19 11:32:22 OK 2_object_stats_trigger.sql (351.46µs)11122026/07/19 11:32:22 goose: up to current file version: 211132026/07/19 11:32:22 INFO Received cleanup request method=DELETE path=/api/pending_closures11142026/07/19 11:32:22 INFO Aborted multipart uploads count=011152026/07/19 11:32:22 INFO Received uploads request method=POST path=/api/pending_closures11162026/07/19 11:32:22 INFO Received cleanup request method=DELETE path=/api/pending_closures11172026/07/19 11:32:22 INFO Aborted multipart uploads count=111182026/07/19 11:32:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11192026-07-19 11:32:22.791 UTC [12739] ERROR: Closure does not exist: id=111202026-07-19 11:32:22.791 UTC [12739] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE11212026-07-19 11:32:22.791 UTC [12739] STATEMENT: -- name: CommitPendingClosure :exec1122 SELECT commit_pending_closure($1::bigint)1123 1124--- PASS: TestService_cleanupPendingClosuresHandler (0.50s)1125=== CONT TestClientMultipleUploads11262026/07/19 11:32:22 INFO Received uploads request method=POST path=/api/pending_closures11272026-07-19 11:32:22.823 UTC [12745] ERROR: relation "goose_db_version" does not exist at character 3611282026-07-19 11:32:22.823 UTC [12745] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11292026/07/19 11:32:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11302026/07/19 11:32:22 INFO Uploading yjbva8ljmjf7jyi45a60p4x7xlccl6xj-file1.txt (160B)11312026/07/19 11:32:22 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11322026/07/19 11:32:22 WARN Failed to register uploaded object key=yjbva8ljmjf7jyi45a60p4x7xlccl6xj.ls error="server returned 404: 404 page not found\n"11332026/07/19 11:32:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11342026/07/19 11:32:22 INFO Signed narinfos id=1 count=111352026/07/19 11:32:22 INFO Uploading 1 narinfos11362026/07/19 11:32:22 WARN Failed to register uploaded object key=yjbva8ljmjf7jyi45a60p4x7xlccl6xj.narinfo error="server returned 404: 404 page not found\n"11372026/07/19 11:32:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11382026-07-19 11:32:22.833 UTC [12746] ERROR: relation "goose_db_version" does not exist at character 3611392026-07-19 11:32:22.833 UTC [12746] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11402026/07/19 11:32:22 INFO Completed upload id=111412026/07/19 11:32:22 INFO Upload complete. (104ms)11422026/07/19 11:32:22 OK 20241026095416_initial_model.sql (14.69ms)1143=== NAME TestNARDeduplicationMetadataUploadBug1144 metadata_upload_test.go:54: Retrieved narinfo from S3:1145 StorePath: /nix/var/nix/builds/nix-12522-1347016672/TestNARDeduplicationMetadataUploadBug4126895497/001/store/yjbva8ljmjf7jyi45a60p4x7xlccl6xj-file1.txt1146 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1147 Compression: zstd1148 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1149 NarSize: 1601150 References: 1151 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf11522026/07/19 11:32:22 OK 20251210153512_drop_unused_gin_index.sql (810.42µs)1153 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1154 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1155 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}11562026/07/19 11:32:22 OK 20251218171726_add_pins.sql (2.07ms)11572026/07/19 11:32:22 OK 20260628120000_add_object_size_and_stats.sql (3.05ms)11582026/07/19 11:32:22 goose: successfully migrated database to version: 2026062812000011592026/07/19 11:32:22 OK 1_commit_pending_closure.sql (995.33µs)11602026/07/19 11:32:22 OK 2_object_stats_trigger.sql (208.88µs)11612026/07/19 11:32:22 goose: up to current file version: 211622026/07/19 11:32:22 INFO Aborted multipart uploads count=011632026/07/19 11:32:22 OK 20241026095416_initial_model.sql (11.77ms)11642026/07/19 11:32:22 OK 20251210153512_drop_unused_gin_index.sql (346.58µs)11652026/07/19 11:32:22 WARN Force mode enabled - objects will be deleted immediately without grace period11662026/07/19 11:32:22 OK 20251218171726_add_pins.sql (1.07ms)11672026/07/19 11:32:22 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=011682026/07/19 11:32:22 INFO Vacuumed table table=pending_closures11692026/07/19 11:32:22 INFO Vacuumed table table=pending_objects11702026/07/19 11:32:22 INFO Vacuumed table table=multipart_uploads11712026/07/19 11:32:22 INFO Vacuumed table table=closures11722026/07/19 11:32:22 INFO Vacuumed table table=objects11732026/07/19 11:32:22 OK 20260628120000_add_object_size_and_stats.sql (4.84ms)11742026/07/19 11:32:22 goose: successfully migrated database to version: 202606281200001175--- PASS: TestGCMetrics (0.44s)1176=== CONT TestCacheStatsHandler11772026/07/19 11:32:22 OK 1_commit_pending_closure.sql (1.79ms)11782026/07/19 11:32:22 OK 2_object_stats_trigger.sql (245.54µs)11792026/07/19 11:32:22 goose: up to current file version: 211802026-07-19 11:32:22.875 UTC [12752] ERROR: relation "goose_db_version" does not exist at character 3611812026-07-19 11:32:22.875 UTC [12752] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1182=== NAME TestNARDeduplicationMetadataUploadBug1183 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-12522-1347016672/TestNARDeduplicationMetadataUploadBug4126895497/001/store/0hx91pagmbnwix89lavp9cvjrdnl0jjy-file2.txt11842026/07/19 11:32:22 OK 20241026095416_initial_model.sql (6.69ms)11852026/07/19 11:32:22 OK 20251210153512_drop_unused_gin_index.sql (371.17µs)11862026/07/19 11:32:22 OK 20251218171726_add_pins.sql (731.71µs)11872026/07/19 11:32:22 OK 20260628120000_add_object_size_and_stats.sql (4.52ms)11882026/07/19 11:32:22 goose: successfully migrated database to version: 2026062812000011892026/07/19 11:32:22 OK 1_commit_pending_closure.sql (1.28ms)11902026/07/19 11:32:22 OK 2_object_stats_trigger.sql (289.92µs)11912026/07/19 11:32:22 goose: up to current file version: 21192--- PASS: TestReadProxyInvalidPath (0.44s)1193=== CONT TestReadProxyNarStreaming11942026-07-19 11:32:22.921 UTC [12758] ERROR: relation "goose_db_version" does not exist at character 3611952026-07-19 11:32:22.921 UTC [12758] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11962026-07-19 11:32:22.936 UTC [12759] ERROR: relation "goose_db_version" does not exist at character 3611972026-07-19 11:32:22.936 UTC [12759] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11982026/07/19 11:32:22 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"11992026/07/19 11:32:22 OK 20241026095416_initial_model.sql (16.18ms)12002026/07/19 11:32:22 OK 20251210153512_drop_unused_gin_index.sql (709.21µs)12012026/07/19 11:32:22 OK 20251218171726_add_pins.sql (1.22ms)12022026/07/19 11:32:22 OK 20260628120000_add_object_size_and_stats.sql (2.01ms)12032026/07/19 11:32:22 goose: successfully migrated database to version: 2026062812000012042026/07/19 11:32:22 OK 20241026095416_initial_model.sql (6.03ms)12052026/07/19 11:32:22 OK 1_commit_pending_closure.sql (910.08µs)12062026/07/19 11:32:22 OK 20251210153512_drop_unused_gin_index.sql (427.71µs)12072026/07/19 11:32:22 OK 2_object_stats_trigger.sql (212.83µs)12082026/07/19 11:32:22 goose: up to current file version: 212092026/07/19 11:32:22 OK 20251218171726_add_pins.sql (746.04µs)12102026/07/19 11:32:22 INFO Created nix-cache-info in bucket bucket=bucket3112112026/07/19 11:32:22 OK 20260628120000_add_object_size_and_stats.sql (2.55ms)12122026/07/19 11:32:22 goose: successfully migrated database to version: 2026062812000012132026/07/19 11:32:22 OK 1_commit_pending_closure.sql (1.4ms)12142026/07/19 11:32:22 OK 2_object_stats_trigger.sql (347.79µs)12152026/07/19 11:32:22 goose: up to current file version: 212162026/07/19 11:32:22 INFO Created nix-cache-info in bucket bucket=bucket3212172026/07/19 11:32:22 INFO Received uploads request method=POST path=/api/pending_closures12182026/07/19 11:32:22 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12192026/07/19 11:32:22 WARN Failed to register uploaded object key=0hx91pagmbnwix89lavp9cvjrdnl0jjy.ls error="server returned 404: 404 page not found\n"12202026/07/19 11:32:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12212026/07/19 11:32:22 INFO Signed narinfos id=2 count=112222026/07/19 11:32:22 INFO Uploading 1 narinfos12232026/07/19 11:32:22 WARN Failed to register uploaded object key=0hx91pagmbnwix89lavp9cvjrdnl0jjy.narinfo error="server returned 404: 404 page not found\n"12242026/07/19 11:32:22 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12252026/07/19 11:32:22 INFO Completed upload id=212262026/07/19 11:32:22 INFO Upload complete. (78ms)1227=== NAME TestNARDeduplicationMetadataUploadBug1228 metadata_upload_test.go:76: Retrieved narinfo from S3:1229 StorePath: /nix/var/nix/builds/nix-12522-1347016672/TestNARDeduplicationMetadataUploadBug4126895497/001/store/0hx91pagmbnwix89lavp9cvjrdnl0jjy-file2.txt1230 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1231 Compression: zstd1232 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1233 NarSize: 1601234 References: 1235 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1236 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1237 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1238 {"version":1,"root":{"type":"regular","size":44}}1239--- PASS: TestNARDeduplicationMetadataUploadBug (0.88s)1240=== CONT TestService_ReadAuthMiddleware12412026-07-19 11:32:23.006 UTC [12768] ERROR: relation "goose_db_version" does not exist at character 3612422026-07-19 11:32:23.006 UTC [12768] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12432026/07/19 11:32:23 OK 20241026095416_initial_model.sql (18.01ms)12442026/07/19 11:32:23 OK 20251210153512_drop_unused_gin_index.sql (539.75µs)12452026/07/19 11:32:23 OK 20251218171726_add_pins.sql (854.42µs)12462026-07-19 11:32:23.070 UTC [12772] ERROR: relation "goose_db_version" does not exist at character 3612472026-07-19 11:32:23.070 UTC [12772] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12482026/07/19 11:32:23 OK 20260628120000_add_object_size_and_stats.sql (13.46ms)12492026/07/19 11:32:23 goose: successfully migrated database to version: 2026062812000012502026/07/19 11:32:23 OK 1_commit_pending_closure.sql (985.21µs)12512026/07/19 11:32:23 OK 2_object_stats_trigger.sql (580.63µs)12522026/07/19 11:32:23 goose: up to current file version: 212532026/07/19 11:32:23 INFO Created nix-cache-info in bucket bucket=bucket331254--- PASS: TestGCBugBareHashReferences (0.66s)1255=== CONT TestService_AuthMiddleware_OIDC12562026/07/19 11:32:23 INFO OIDC provider initialized name=test1257=== NAME TestPinProtectsFromGC1258 client_integration_test.go:646: Pinned store path: /nix/var/nix/builds/nix-12522-1347016672/TestPinProtectsFromGC435883660/001/store/a5anh17y03gaqvad440cbq7i7zrvqw9d-pinned-file.txt1259 client_integration_test.go:647: Unpinned store path: /nix/var/nix/builds/nix-12522-1347016672/TestPinProtectsFromGC435883660/001/store/lghwsl394rz3v1g6bxcdgb3pasbkqj80-unpinned-file.txt12602026/07/19 11:32:23 OK 20241026095416_initial_model.sql (11.75ms)12612026/07/19 11:32:23 OK 20251210153512_drop_unused_gin_index.sql (1.12ms)12622026/07/19 11:32:23 OK 20251218171726_add_pins.sql (1.34ms)12632026/07/19 11:32:23 OK 20260628120000_add_object_size_and_stats.sql (2.8ms)12642026/07/19 11:32:23 goose: successfully migrated database to version: 2026062812000012652026/07/19 11:32:23 OK 1_commit_pending_closure.sql (1.57ms)12662026/07/19 11:32:23 OK 2_object_stats_trigger.sql (265.29µs)12672026/07/19 11:32:23 goose: up to current file version: 212682026/07/19 11:32:23 INFO Created nix-cache-info in bucket bucket=bucket341269=== NAME TestClientIntegration1270 client_integration_test.go:276: Created store path: /nix/var/nix/builds/nix-12522-1347016672/TestClientIntegration3350600812/002/store/mb9vk8n7n120mgjkanwr8gzfpk72m8qd-test-file.txt12712026-07-19 11:32:23.156 UTC [12785] ERROR: relation "goose_db_version" does not exist at character 3612722026-07-19 11:32:23.156 UTC [12785] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12732026/07/19 11:32:23 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"12742026/07/19 11:32:23 OK 20241026095416_initial_model.sql (8.3ms)12752026/07/19 11:32:23 OK 20251210153512_drop_unused_gin_index.sql (426.29µs)12762026/07/19 11:32:23 OK 20251218171726_add_pins.sql (1.79ms)12772026-07-19 11:32:23.184 UTC [12790] ERROR: relation "goose_db_version" does not exist at character 3612782026-07-19 11:32:23.184 UTC [12790] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12792026/07/19 11:32:23 OK 20260628120000_add_object_size_and_stats.sql (13.06ms)12802026/07/19 11:32:23 goose: successfully migrated database to version: 2026062812000012812026/07/19 11:32:23 OK 1_commit_pending_closure.sql (1.64ms)12822026/07/19 11:32:23 OK 2_object_stats_trigger.sql (550.92µs)12832026/07/19 11:32:23 goose: up to current file version: 212842026/07/19 11:32:23 INFO Created nix-cache-info in bucket bucket=bucket3512852026/07/19 11:32:23 OK 20241026095416_initial_model.sql (12.48ms)12862026/07/19 11:32:23 OK 20251210153512_drop_unused_gin_index.sql (878.17µs)12872026/07/19 11:32:23 INFO Received uploads request method=POST path=/api/pending_closures12882026/07/19 11:32:23 OK 20251218171726_add_pins.sql (1.48ms)12892026/07/19 11:32:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12902026/07/19 11:32:23 INFO Uploading a5anh17y03gaqvad440cbq7i7zrvqw9d-pinned-file.txt (128B)12912026/07/19 11:32:23 OK 20260628120000_add_object_size_and_stats.sql (2.01ms)12922026/07/19 11:32:23 goose: successfully migrated database to version: 2026062812000012932026/07/19 11:32:23 OK 1_commit_pending_closure.sql (1.57ms)12942026/07/19 11:32:23 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"12952026/07/19 11:32:23 OK 2_object_stats_trigger.sql (495.88µs)12962026/07/19 11:32:23 goose: up to current file version: 212972026/07/19 11:32:23 WARN Failed to register uploaded object key=a5anh17y03gaqvad440cbq7i7zrvqw9d.ls error="server returned 404: 404 page not found\n"12982026/07/19 11:32:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12992026/07/19 11:32:23 INFO Signed narinfos id=1 count=113002026/07/19 11:32:23 INFO Uploading 1 narinfos13012026/07/19 11:32:23 WARN Failed to register uploaded object key=a5anh17y03gaqvad440cbq7i7zrvqw9d.narinfo error="server returned 404: 404 page not found\n"13022026/07/19 11:32:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13032026/07/19 11:32:23 INFO Completed upload id=113042026/07/19 11:32:23 INFO Upload complete. (90ms)1305--- PASS: TestCacheStatsHandler (0.36s)1306=== CONT TestResurrectedObjectNotDeleted1307=== NAME TestClientWithDependencies1308 client_integration_test.go:593: Built derivation: /nix/var/nix/builds/nix-12522-1347016672/TestClientWithDependencies401453380/001/store/xnzgm59plywa6vgs9jdkwm9cfw13h05k-test-script13092026/07/19 11:32:23 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13102026-07-19 11:32:23.239 UTC [12804] ERROR: relation "goose_db_version" does not exist at character 3613112026-07-19 11:32:23.239 UTC [12804] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1312 client_integration_test.go:595: Found 1 dependencies (including self)1313=== NAME TestClientMultipleUploads1314 client_integration_test.go:338: Created store path 0: /nix/var/nix/builds/nix-12522-1347016672/TestClientMultipleUploads2150709239/001/store/s50s7m5q972g5a44p42cprp2bllicmnv-test-file-0.txt13152026/07/19 11:32:23 INFO Received uploads request method=POST path=/api/pending_closures13162026/07/19 11:32:23 OK 20241026095416_initial_model.sql (9.16ms)13172026/07/19 11:32:23 OK 20251210153512_drop_unused_gin_index.sql (585.46µs)13182026/07/19 11:32:23 OK 20251218171726_add_pins.sql (1.63ms)13192026/07/19 11:32:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13202026/07/19 11:32:23 INFO Uploading mb9vk8n7n120mgjkanwr8gzfpk72m8qd-test-file.txt (152B)13212026/07/19 11:32:23 OK 20260628120000_add_object_size_and_stats.sql (2.34ms)13222026/07/19 11:32:23 goose: successfully migrated database to version: 2026062812000013232026/07/19 11:32:23 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"13242026/07/19 11:32:23 OK 1_commit_pending_closure.sql (2.09ms)13252026/07/19 11:32:23 WARN Failed to register uploaded object key=mb9vk8n7n120mgjkanwr8gzfpk72m8qd.ls error="server returned 404: 404 page not found\n"13262026/07/19 11:32:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13272026/07/19 11:32:23 INFO Signed narinfos id=1 count=113282026/07/19 11:32:23 INFO Uploading 1 narinfos13292026/07/19 11:32:23 OK 2_object_stats_trigger.sql (510.21µs)13302026/07/19 11:32:23 goose: up to current file version: 213312026/07/19 11:32:23 WARN Failed to register uploaded object key=mb9vk8n7n120mgjkanwr8gzfpk72m8qd.narinfo error="server returned 404: 404 page not found\n"13322026/07/19 11:32:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1333--- PASS: TestReadProxyNarStreaming (0.39s)1334=== CONT TestOrphanedObjectsGCStressTest13352026-07-19 11:32:23.294 UTC [12813] ERROR: relation "goose_db_version" does not exist at character 3613362026-07-19 11:32:23.294 UTC [12813] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13372026/07/19 11:32:23 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13382026/07/19 11:32:23 INFO Completed upload id=113392026/07/19 11:32:23 INFO Upload complete. (108ms)1340=== NAME TestClientIntegration1341 client_integration_test.go:292: Retrieved narinfo from S3:1342 StorePath: /nix/var/nix/builds/nix-12522-1347016672/TestClientIntegration3350600812/002/store/mb9vk8n7n120mgjkanwr8gzfpk72m8qd-test-file.txt1343 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1344 Compression: zstd1345 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11346 NarSize: 1521347 References: 1348 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11349=== NAME TestClientMultipleUploads1350 client_integration_test.go:338: Created store path 1: /nix/var/nix/builds/nix-12522-1347016672/TestClientMultipleUploads2150709239/001/store/schzbay2bi1acli1w252gwvhc01aaapf-test-file-1.txt1351=== NAME TestClientIntegration1352 client_integration_test.go:293: Retrieved .ls file from S3 (compressed size: 77 bytes)1353 client_integration_test.go:293: Decompressed .ls content (64 bytes):1354 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1355 client_integration_test.go:296: Testing garbage collection...13562026/07/19 11:32:23 OK 20241026095416_initial_model.sql (8.56ms)13572026/07/19 11:32:23 OK 20251210153512_drop_unused_gin_index.sql (714.88µs)13582026/07/19 11:32:23 OK 20251218171726_add_pins.sql (2.53ms)13592026/07/19 11:32:23 OK 20260628120000_add_object_size_and_stats.sql (4.99ms)13602026/07/19 11:32:23 goose: successfully migrated database to version: 2026062812000013612026/07/19 11:32:23 OK 1_commit_pending_closure.sql (1.78ms)13622026/07/19 11:32:23 OK 2_object_stats_trigger.sql (476.67µs)13632026/07/19 11:32:23 goose: up to current file version: 213642026/07/19 11:32:23 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1365--- PASS: TestService_ReadAuthMiddleware (0.33s)1366=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1367=== NAME TestClientCADerivations1368 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-12522-1347016672/TestClientCADerivations1536073065/001/store/hmc9plhb599sma8nmv62jmfvwbv7apzh-ca-test13692026/07/19 11:32:23 INFO Received uploads request method=POST path=/api/pending_closures13702026-07-19 11:32:23.342 UTC [12827] ERROR: relation "goose_db_version" does not exist at character 3613712026-07-19 11:32:23.342 UTC [12827] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13722026/07/19 11:32:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13732026/07/19 11:32:23 INFO Uploading lghwsl394rz3v1g6bxcdgb3pasbkqj80-unpinned-file.txt (128B)13742026/07/19 11:32:23 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"13752026/07/19 11:32:23 INFO Starting cleanup of old closures method=DELETE path=/api/closures13762026/07/19 11:32:23 WARN Failed to register uploaded object key=lghwsl394rz3v1g6bxcdgb3pasbkqj80.ls error="server returned 404: 404 page not found\n"13772026/07/19 11:32:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13782026/07/19 11:32:23 INFO Garbage collection started13792026/07/19 11:32:23 INFO Signed narinfos id=2 count=113802026/07/19 11:32:23 INFO Uploading 1 narinfos13812026/07/19 11:32:23 WARN Failed to register uploaded object key=lghwsl394rz3v1g6bxcdgb3pasbkqj80.narinfo error="server returned 404: 404 page not found\n"13822026/07/19 11:32:23 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13832026/07/19 11:32:23 INFO Completed upload id=213842026/07/19 11:32:23 INFO Upload complete. (92ms)13852026/07/19 11:32:23 INFO Aborted multipart uploads count=013862026/07/19 11:32:23 WARN Force mode enabled - objects will be deleted immediately without grace period13872026/07/19 11:32:23 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1388=== NAME TestClientMultipleUploads1389 client_integration_test.go:338: Created store path 2: /nix/var/nix/builds/nix-12522-1347016672/TestClientMultipleUploads2150709239/001/store/4r488bcf57d2bpw5mpx5zaqqa0lgbjs4-test-file-2.txt13902026/07/19 11:32:23 INFO Received uploads request method=POST path=/api/pending_closures13912026/07/19 11:32:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13922026/07/19 11:32:23 INFO Uploading xnzgm59plywa6vgs9jdkwm9cfw13h05k-test-script (136B)13932026/07/19 11:32:23 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"13942026/07/19 11:32:23 WARN Failed to register uploaded object key=log/p6508l7c2y7pxg0w7598mkqqbq7yxv4a-test-script.drv error="server returned 404: 404 page not found\n"13952026/07/19 11:32:23 WARN Failed to register uploaded object key=xnzgm59plywa6vgs9jdkwm9cfw13h05k.ls error="server returned 404: 404 page not found\n"13962026/07/19 11:32:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13972026/07/19 11:32:23 INFO Signed narinfos id=1 count=113982026/07/19 11:32:23 INFO Uploading 1 narinfos13992026/07/19 11:32:23 OK 20241026095416_initial_model.sql (5.97ms)14002026/07/19 11:32:23 WARN Failed to register uploaded object key=xnzgm59plywa6vgs9jdkwm9cfw13h05k.narinfo error="server returned 404: 404 page not found\n"14012026/07/19 11:32:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14022026/07/19 11:32:23 OK 20251210153512_drop_unused_gin_index.sql (713.17µs)14032026/07/19 11:32:23 OK 20251218171726_add_pins.sql (1.72ms)14042026/07/19 11:32:23 INFO Completed upload id=114052026/07/19 11:32:23 INFO Upload complete. (62ms)14062026/07/19 11:32:23 OK 20260628120000_add_object_size_and_stats.sql (1.4ms)14072026/07/19 11:32:23 goose: successfully migrated database to version: 202606281200001408=== NAME TestClientWithDependencies1409 client_integration_test.go:597: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-12522-1347016672/TestClientWithDependencies401453380/001/store) requires matching store prefix14102026/07/19 11:32:23 OK 1_commit_pending_closure.sql (1.43ms)14112026/07/19 11:32:23 OK 2_object_stats_trigger.sql (250.13µs)14122026/07/19 11:32:23 goose: up to current file version: 21413--- PASS: TestClientWithDependencies (0.82s)1414=== CONT TestOrphanedObjectsGC1415=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1416=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1417=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1418=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1419=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1420=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1421=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1422=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1423=== CONT TestService_AuthMiddleware_MTLSProxyHeader1424=== NAME TestClientCADerivations1425 client_ca_test.go:139: Found 1 dependencies (including self)14262026/07/19 11:32:23 INFO Received create pin request method=POST path=/api/pins/myapp14272026/07/19 11:32:23 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-12522-1347016672/TestPinProtectsFromGC435883660/001/store/a5anh17y03gaqvad440cbq7i7zrvqw9d-pinned-file.txt narinfo_key=a5anh17y03gaqvad440cbq7i7zrvqw9d.narinfo14282026/07/19 11:32:23 INFO Starting cleanup of old closures method=DELETE path=/api/closures14292026/07/19 11:32:23 INFO Garbage collection started14302026/07/19 11:32:23 INFO Aborted multipart uploads count=014312026/07/19 11:32:23 WARN Force mode enabled - objects will be deleted immediately without grace period14322026/07/19 11:32:23 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14332026-07-19 11:32:23.447 UTC [12847] ERROR: relation "goose_db_version" does not exist at character 3614342026-07-19 11:32:23.447 UTC [12847] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14352026/07/19 11:32:23 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14362026/07/19 11:32:23 INFO Received uploads request method=POST path=/api/pending_closures14372026/07/19 11:32:23 INFO Received uploads request method=POST path=/api/pending_closures14382026/07/19 11:32:23 INFO Received uploads request method=POST path=/api/pending_closures14392026/07/19 11:32:23 OK 20241026095416_initial_model.sql (6.64ms)14402026/07/19 11:32:23 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)14412026/07/19 11:32:23 INFO Uploading schzbay2bi1acli1w252gwvhc01aaapf-test-file-1.txt (160B)14422026/07/19 11:32:23 INFO Uploading 4r488bcf57d2bpw5mpx5zaqqa0lgbjs4-test-file-2.txt (160B)14432026/07/19 11:32:23 INFO Uploading s50s7m5q972g5a44p42cprp2bllicmnv-test-file-0.txt (160B)14442026/07/19 11:32:23 OK 20251210153512_drop_unused_gin_index.sql (968µs)14452026/07/19 11:32:23 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"14462026/07/19 11:32:23 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"14472026/07/19 11:32:23 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"14482026/07/19 11:32:23 OK 20251218171726_add_pins.sql (2.13ms)14492026/07/19 11:32:23 WARN Failed to register uploaded object key=4r488bcf57d2bpw5mpx5zaqqa0lgbjs4.ls error="server returned 404: 404 page not found\n"14502026/07/19 11:32:23 WARN Failed to register uploaded object key=s50s7m5q972g5a44p42cprp2bllicmnv.ls error="server returned 404: 404 page not found\n"14512026/07/19 11:32:23 WARN Failed to register uploaded object key=schzbay2bi1acli1w252gwvhc01aaapf.ls error="server returned 404: 404 page not found\n"14522026/07/19 11:32:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14532026/07/19 11:32:23 INFO Signed narinfos id=1 count=114542026/07/19 11:32:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14552026/07/19 11:32:23 INFO Signed narinfos id=2 count=114562026/07/19 11:32:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign14572026/07/19 11:32:23 INFO Signed narinfos id=3 count=114582026/07/19 11:32:23 INFO Uploading 3 narinfos14592026/07/19 11:32:23 WARN Failed to register uploaded object key=schzbay2bi1acli1w252gwvhc01aaapf.narinfo error="server returned 404: 404 page not found\n"14602026/07/19 11:32:23 WARN Failed to register uploaded object key=s50s7m5q972g5a44p42cprp2bllicmnv.narinfo error="server returned 404: 404 page not found\n"14612026/07/19 11:32:23 WARN Failed to register uploaded object key=4r488bcf57d2bpw5mpx5zaqqa0lgbjs4.narinfo error="server returned 404: 404 page not found\n"14622026/07/19 11:32:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14632026/07/19 11:32:23 OK 20260628120000_add_object_size_and_stats.sql (4.93ms)14642026/07/19 11:32:23 goose: successfully migrated database to version: 2026062812000014652026/07/19 11:32:23 OK 1_commit_pending_closure.sql (1.05ms)14662026/07/19 11:32:23 INFO Completed upload id=114672026/07/19 11:32:23 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14682026/07/19 11:32:23 OK 2_object_stats_trigger.sql (436.63µs)14692026/07/19 11:32:23 goose: up to current file version: 214702026/07/19 11:32:23 INFO Completed upload id=214712026/07/19 11:32:23 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete14722026/07/19 11:32:23 INFO Completed upload id=314732026/07/19 11:32:23 INFO Upload complete. (86ms)1474=== NAME TestClientMultipleUploads1475 client_integration_test.go:349: Uploaded 3 paths in 127.062208ms1476--- PASS: TestClientMultipleUploads (0.69s)1477=== CONT TestGenerateLandingPage1478--- PASS: TestGenerateLandingPage (0.00s)1479=== CONT TestProxyWriteTimeout/narinfo1480=== CONT TestProxyWriteTimeout/unknown_size1481=== CONT TestProxyWriteTimeout/10_GiB_nar1482=== CONT TestProxyWriteTimeout/1_GiB_nar1483--- PASS: TestProxyWriteTimeout (0.00s)1484 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1485 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1486 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1487 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1488=== CONT TestIsValidUploadKey/nix-cache-info1489=== CONT TestIsValidUploadKey/narinfo1490=== CONT TestIsValidUploadKey/realisation_plus_in_output1491=== CONT TestIsValidUploadKey/realisation1492=== CONT TestIsValidUploadKey/build_log_equals1493=== CONT TestIsValidUploadKey/build_log_question_mark1494=== CONT TestIsValidUploadKey/build_log_plus_in_name1495=== CONT TestIsValidUploadKey/build_log_home-manager_file1496=== CONT TestIsValidUploadKey/build_log1497=== CONT TestIsValidUploadKey/listing1498=== CONT TestIsValidUploadKey/nar_plain1499=== CONT TestIsValidUploadKey/nar_xz1500=== CONT TestIsValidUploadKey/traversal1501=== CONT TestIsValidUploadKey/unknown_type1502=== CONT TestIsValidUploadKey/empty_key1503=== CONT TestIsValidUploadKey/absolute1504=== CONT TestIsValidUploadKey/traversal_nar1505=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1506=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1507=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1508=== CONT TestIsValidUploadKey/index.html1509=== CONT TestIsValidUploadKey/nar_zst1510--- PASS: TestIsValidUploadKey (0.00s)1511 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1512 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1513 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1514 --- PASS: TestIsValidUploadKey/realisation (0.00s)1515 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1516 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1517 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1518 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1519 --- PASS: TestIsValidUploadKey/build_log (0.00s)1520 --- PASS: TestIsValidUploadKey/listing (0.00s)1521 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1522 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1523 --- PASS: TestIsValidUploadKey/traversal (0.00s)1524 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1525 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1526 --- PASS: TestIsValidUploadKey/absolute (0.00s)1527 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1528 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1529 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1530 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1531 --- PASS: TestIsValidUploadKey/index.html (0.00s)1532 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1533=== CONT TestServerTLSConfig/no_client_CA1534=== CONT TestServerTLSConfig/not_a_PEM_file1535=== CONT TestServerTLSConfig/missing_CA_file1536--- PASS: TestServerTLSConfig (0.00s)1537 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1538 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1539 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1540=== CONT TestParseSingleRange/none1541=== CONT TestParseSingleRange/open-ended1542=== CONT TestParseSingleRange/closed1543=== CONT TestParseSingleRange/malformed_end_before_start1544=== CONT TestParseSingleRange/malformed_both_empty1545=== CONT TestParseSingleRange/malformed_no_dash1546=== CONT TestParseSingleRange/multi-range_ignored1547=== CONT TestParseSingleRange/unknown_unit1548=== CONT TestParseSingleRange/start_past_EOF1549=== CONT TestParseSingleRange/end_clamped_to_size1550=== CONT TestParseSingleRange/single_byte1551=== CONT TestParseSingleRange/suffix_exceeds_size1552=== CONT TestParseSingleRange/suffix1553=== CONT TestParseSingleRange/start_far_past_EOF1554--- PASS: TestParseSingleRange (0.00s)1555 --- PASS: TestParseSingleRange/none (0.00s)1556 --- PASS: TestParseSingleRange/open-ended (0.00s)1557 --- PASS: TestParseSingleRange/closed (0.00s)1558 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1559 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1560 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1561 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1562 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1563 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1564 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1565 --- PASS: TestParseSingleRange/single_byte (0.00s)1566 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1567 --- PASS: TestParseSingleRange/suffix (0.00s)1568 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1569=== CONT TestIsValidCachePath/narinfo1570=== CONT TestIsValidCachePath/index.html1571=== CONT TestIsValidCachePath/short_hash1572=== CONT TestIsValidCachePath/wrong_extension1573=== CONT TestIsValidCachePath/leading_slash1574=== CONT TestIsValidCachePath/empty1575=== CONT TestIsValidCachePath/random_path1576=== CONT TestIsValidCachePath/invalid_char_u1577=== CONT TestIsValidCachePath/invalid_char_e1578=== CONT TestIsValidCachePath/traversal_in_middle1579=== CONT TestIsValidCachePath/traversal_parent1580=== CONT TestIsValidCachePath/nar_uncompressed1581=== CONT TestIsValidCachePath/nix-cache-info1582=== CONT TestIsValidCachePath/realisation1583=== CONT TestIsValidCachePath/log1584=== CONT TestIsValidCachePath/ls1585=== CONT TestIsValidCachePath/nar_xz1586=== CONT TestIsValidCachePath/nar_bz21587=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1588=== CONT TestIsValidCachePath/nar_zst1589--- PASS: TestIsValidCachePath (0.00s)1590 --- PASS: TestIsValidCachePath/narinfo (0.00s)1591 --- PASS: TestIsValidCachePath/index.html (0.00s)1592 --- PASS: TestIsValidCachePath/short_hash (0.00s)1593 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1594 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1595 --- PASS: TestIsValidCachePath/empty (0.00s)1596 --- PASS: TestIsValidCachePath/random_path (0.00s)1597 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1598 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1599 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1600 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1601 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1602 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1603 --- PASS: TestIsValidCachePath/realisation (0.00s)1604 --- PASS: TestIsValidCachePath/log (0.00s)1605 --- PASS: TestIsValidCachePath/ls (0.00s)1606 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1607 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1608 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1609 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1610=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16112026/07/19 11:32:23 INFO Received uploads request method=POST path=/16122026-07-19 11:32:23.488 UTC [12851] ERROR: relation "goose_db_version" does not exist at character 3616132026-07-19 11:32:23.488 UTC [12851] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16142026/07/19 11:32:23 INFO Received uploads request method=POST path=/api/pending_closures16152026/07/19 11:32:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16162026/07/19 11:32:23 INFO Uploading hmc9plhb599sma8nmv62jmfvwbv7apzh-ca-test (144B)16172026/07/19 11:32:23 OK 20241026095416_initial_model.sql (5.59ms)16182026/07/19 11:32:23 OK 20251210153512_drop_unused_gin_index.sql (886.25µs)16192026/07/19 11:32:23 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16202026/07/19 11:32:23 WARN Failed to register uploaded object key=log/yxlwxyvg2rmh24isp2ldrj75l9g52z16-ca-test.drv error="server returned 404: 404 page not found\n"16212026/07/19 11:32:23 OK 20251218171726_add_pins.sql (1.99ms)16222026/07/19 11:32:23 WARN Failed to register uploaded object key=hmc9plhb599sma8nmv62jmfvwbv7apzh.ls error="server returned 404: 404 page not found\n"16232026/07/19 11:32:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16242026/07/19 11:32:23 INFO Signed narinfos id=1 count=116252026/07/19 11:32:23 INFO Uploading 1 narinfos16262026/07/19 11:32:23 OK 20260628120000_add_object_size_and_stats.sql (2.42ms)16272026/07/19 11:32:23 WARN Failed to register uploaded object key=hmc9plhb599sma8nmv62jmfvwbv7apzh.narinfo error="server returned 404: 404 page not found\n"16282026/07/19 11:32:23 goose: successfully migrated database to version: 2026062812000016292026/07/19 11:32:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16302026/07/19 11:32:23 OK 1_commit_pending_closure.sql (1.47ms)16312026/07/19 11:32:23 OK 2_object_stats_trigger.sql (384.25µs)16322026/07/19 11:32:23 goose: up to current file version: 216332026/07/19 11:32:23 INFO Completed upload id=116342026/07/19 11:32:23 INFO Upload complete. (90ms)1635--- PASS: TestResurrectedObjectNotDeleted (0.29s)1636=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16372026/07/19 11:32:23 INFO Received request for more parts method=POST path=/1638=== NAME TestClientCADerivations1639 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-12522-1347016672/TestClientCADerivations1536073065/001/store/hmc9plhb599sma8nmv62jmfvwbv7apzh-ca-test1640 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1641 Compression: zstd1642 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1643 NarSize: 1441644 References: 1645 Deriver: /nix/var/nix/builds/nix-12522-1347016672/TestClientCADerivations1536073065/001/store/yxlwxyvg2rmh24isp2ldrj75l9g52z16-ca-test.drv1646 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1647 client_ca_test.go:185: Checking for realisation files in S3...1648 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1649 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1650=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16512026/07/19 11:32:23 INFO Received complete multipart upload request method=POST path=/16522026-07-19 11:32:23.538 UTC [12853] ERROR: relation "goose_db_version" does not exist at character 3616532026-07-19 11:32:23.538 UTC [12853] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1654=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16552026/07/19 11:32:23 INFO Received uploads request method=POST path=/1656=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16572026/07/19 11:32:23 INFO Received complete multipart upload request method=POST path=/1658=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16592026/07/19 11:32:23 INFO Received uploads request method=POST path=/1660=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16612026/07/19 11:32:23 INFO Received request for more parts method=POST path=/1662--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1663 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1664 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1665 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1666 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1667=== CONT TestCacheConfigHandler/full_config,_no_issuer1668=== CONT TestCacheConfigHandler/no_signing_keys1669=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1670=== CONT TestCacheConfigHandler/no_cache_url_configured1671--- PASS: TestCacheConfigHandler (0.00s)1672 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1673 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1674 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1675 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1676=== CONT TestClientErrorHandling/InvalidStorePath1677=== NAME TestClientCADerivations1678 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket34?endpoint=http://localhost:60344®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-12522-1347016672/TestClientCADerivations1536073065/001/store'1679 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 116802026/07/19 11:32:23 OK 20241026095416_initial_model.sql (7.68ms)16812026/07/19 11:32:23 OK 20251210153512_drop_unused_gin_index.sql (820.04µs)1682--- PASS: TestClientCADerivations (0.84s)1683=== CONT TestClientErrorHandling/InvalidAuthToken16842026/07/19 11:32:23 OK 20251218171726_add_pins.sql (2.05ms)16852026/07/19 11:32:23 OK 20260628120000_add_object_size_and_stats.sql (2.24ms)16862026/07/19 11:32:23 goose: successfully migrated database to version: 2026062812000016872026/07/19 11:32:23 OK 1_commit_pending_closure.sql (1.69ms)16882026/07/19 11:32:23 OK 2_object_stats_trigger.sql (674.5µs)16892026/07/19 11:32:23 goose: up to current file version: 216902026/07/19 11:32:23 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16912026/07/19 11:32:23 WARN mTLS auth: bound subjects configured but subject DN unavailable16922026/07/19 11:32:23 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1693--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.24s)1694=== CONT TestClientErrorHandling/ServerNotAvailable16952026-07-19 11:32:23.576 UTC [12861] ERROR: relation "goose_db_version" does not exist at character 3616962026-07-19 11:32:23.576 UTC [12861] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16972026-07-19 11:32:23.589 UTC [12862] ERROR: relation "goose_db_version" does not exist at character 3616982026-07-19 11:32:23.589 UTC [12862] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16992026/07/19 11:32:23 OK 20241026095416_initial_model.sql (6.6ms)17002026/07/19 11:32:23 OK 20251210153512_drop_unused_gin_index.sql (586.13µs)17012026/07/19 11:32:23 OK 20251218171726_add_pins.sql (741.5µs)17022026/07/19 11:32:23 OK 20260628120000_add_object_size_and_stats.sql (1.04ms)17032026/07/19 11:32:23 goose: successfully migrated database to version: 2026062812000017042026/07/19 11:32:23 OK 1_commit_pending_closure.sql (1.02ms)17052026/07/19 11:32:23 OK 2_object_stats_trigger.sql (283.33µs)17062026/07/19 11:32:23 goose: up to current file version: 21707--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.23s)1708=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token17092026/07/19 11:32:23 INFO OIDC auth successful provider=test1710=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected17112026/07/19 11:32:23 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]1712=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1713=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected17142026/07/19 11:32:23 WARN Authentication failed token_preview=eyJhbGciOi...gJk9juZVyg token_length=702 oidc_error="bound claims validation failed: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1715--- PASS: TestService_AuthMiddleware_OIDC (0.29s)1716 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1717 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1718 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1719 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)17202026/07/19 11:32:23 OK 20241026095416_initial_model.sql (34.42ms)17212026/07/19 11:32:23 OK 20251210153512_drop_unused_gin_index.sql (915.46µs)17222026/07/19 11:32:23 OK 20251218171726_add_pins.sql (2.16ms)17232026/07/19 11:32:23 OK 20260628120000_add_object_size_and_stats.sql (3.32ms)17242026/07/19 11:32:23 goose: successfully migrated database to version: 2026062812000017252026/07/19 11:32:23 OK 1_commit_pending_closure.sql (1.84ms)17262026/07/19 11:32:23 OK 2_object_stats_trigger.sql (493.5µs)17272026/07/19 11:32:23 goose: up to current file version: 217282026/07/19 11:32:23 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=017292026/07/19 11:32:23 INFO Vacuumed table table=pending_closures17302026/07/19 11:32:23 INFO Vacuumed table table=pending_objects17312026/07/19 11:32:23 INFO Vacuumed table table=multipart_uploads17322026/07/19 11:32:23 INFO Vacuumed table table=closures17332026/07/19 11:32:23 INFO Vacuumed table table=objects17342026/07/19 11:32:23 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-config17352026-07-19 11:32:23.728 UTC [12869] ERROR: relation "goose_db_version" does not exist at character 3617362026-07-19 11:32:23.728 UTC [12869] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17372026-07-19 11:32:23.730 UTC [12870] ERROR: relation "goose_db_version" does not exist at character 3617382026-07-19 11:32:23.730 UTC [12870] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17392026/07/19 11:32:23 OK 20241026095416_initial_model.sql (13.04ms)17402026/07/19 11:32:23 OK 20251210153512_drop_unused_gin_index.sql (410.13µs)17412026/07/19 11:32:23 OK 20251218171726_add_pins.sql (764.67µs)17422026/07/19 11:32:23 OK 20260628120000_add_object_size_and_stats.sql (6.56ms)17432026/07/19 11:32:23 goose: successfully migrated database to version: 2026062812000017442026/07/19 11:32:23 OK 1_commit_pending_closure.sql (907.04µs)17452026/07/19 11:32:23 OK 2_object_stats_trigger.sql (219.42µs)17462026/07/19 11:32:23 goose: up to current file version: 217472026/07/19 11:32:23 OK 20241026095416_initial_model.sql (23.78ms)17482026/07/19 11:32:23 OK 20251210153512_drop_unused_gin_index.sql (1.36ms)17492026/07/19 11:32:23 OK 20251218171726_add_pins.sql (1.11ms)17502026/07/19 11:32:23 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=017512026/07/19 11:32:23 OK 20260628120000_add_object_size_and_stats.sql (1.06ms)17522026/07/19 11:32:23 goose: successfully migrated database to version: 2026062812000017532026/07/19 11:32:23 INFO Vacuumed table table=pending_closures17542026/07/19 11:32:23 OK 1_commit_pending_closure.sql (1.01ms)17552026/07/19 11:32:23 OK 2_object_stats_trigger.sql (325.21µs)17562026/07/19 11:32:23 goose: up to current file version: 217572026/07/19 11:32:23 INFO Vacuumed table table=pending_objects17582026/07/19 11:32:23 INFO Vacuumed table table=multipart_uploads17592026/07/19 11:32:23 INFO Vacuumed table table=closures17602026/07/19 11:32:23 INFO Vacuumed table table=objects1761--- PASS: TestUploadHandlersRejectOversizedBody (0.02s)1762 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1763 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1764 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.31s)17652026/07/19 11:32:23 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=214.81441ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1766=== NAME TestOrphanedObjectsGCStressTest1767 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1768 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion17692026/07/19 11:32:23 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1770=== NAME TestOrphanedObjectsGC1771 orphaned_objects_gc_test.go:290: GC Test Summary:1772 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1773 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1774 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1775 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1776 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1777--- PASS: TestOrphanedObjectsGC (0.51s)17782026/07/19 11:32:23 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1779=== NAME TestOrphanedObjectsGCStressTest1780 orphaned_objects_gc_test.go:509: Stress test completed successfully:1781 orphaned_objects_gc_test.go:510: - Active objects preserved: 201782 orphaned_objects_gc_test.go:511: - Objects deleted: 2101783 orphaned_objects_gc_test.go:512: - Total GC'd: 2101784--- PASS: TestOrphanedObjectsGCStressTest (0.64s)17852026/07/19 11:32:24 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=372.734461ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config17862026/07/19 11:32:24 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=831.351421ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config17872026/07/19 11:32:25 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.663904966s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config17882026/07/19 11:32:25 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01789=== NAME TestClientIntegration1790 client_integration_test.go:303: Objects in database after GC:1791 client_integration_test.go:303: Successfully deleted all objects with GC --force1792--- PASS: TestClientIntegration (2.71s)17932026/07/19 11:32:25 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01794=== NAME TestPinProtectsFromGC1795 client_integration_test.go:709: Pin successfully protected closure from garbage collection1796--- PASS: TestPinProtectsFromGC (2.84s)17972026/07/19 11:32:25 WARN Rate limiter enabled after throttle name=s3-test rate=517982026/07/19 11:32:25 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1799=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1800 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101801 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001802--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.40s)18032026/07/19 11:32:26 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"18042026/07/19 11:32:26 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_closures18052026/07/19 11:32:27 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=217.273184ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures18062026/07/19 11:32:27 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=365.283351ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures18072026/07/19 11:32:27 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=767.19496ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures18082026/07/19 11:32:28 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.753252238s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1809--- PASS: TestClientErrorHandling (0.00s)1810 --- PASS: TestClientErrorHandling/InvalidStorePath (0.25s)1811 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.35s)1812 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.63s)1813PASS1814{"timestamp":"2026-07-19T11:32:30.698851Z","level":"ERROR","fields":{"message":"Unknown connection IO error:Cancelled","peer_addr":"127.0.0.1:60399"},"target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":973,"threadName":"rustfs-worker","threadId":"ThreadId(10)"}18152026-07-19 11:32:30.763 UTC [12561] LOG: received smart shutdown request18162026-07-19 11:32:30.764 UTC [12561] LOG: background worker "logical replication launcher" (PID 12571) exited with exit code 118172026-07-19 11:32:30.773 UTC [12566] LOG: shutting down18182026-07-19 11:32:30.773 UTC [12566] LOG: checkpoint starting: shutdown immediate18192026-07-19 11:32:31.778 UTC [12566] LOG: checkpoint complete: wrote 12608 buffers (77.0%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 13 recycled; write=0.723 s, sync=0.281 s, total=1.006 s; sync files=15167, longest=0.020 s, average=0.001 s; distance=212067 kB, estimate=212067 kB; lsn=0/E69E3C8, redo lsn=0/E69E3C818202026-07-19 11:32:31.783 UTC [12561] LOG: database system is shut down1821Running OIDC tests...1822=== RUN TestGlobMatch1823=== PAUSE TestGlobMatch1824=== RUN TestAudienceForIssuer1825=== PAUSE TestAudienceForIssuer1826=== RUN TestValidateToken_ValidToken1827=== PAUSE TestValidateToken_ValidToken1828=== RUN TestValidateToken_WrongAudience1829=== PAUSE TestValidateToken_WrongAudience1830=== RUN TestValidateToken_Expired1831=== PAUSE TestValidateToken_Expired1832=== RUN TestValidateToken_BoundClaimsMismatch1833=== PAUSE TestValidateToken_BoundClaimsMismatch1834=== RUN TestValidateToken_BoundSubjectMismatch1835=== PAUSE TestValidateToken_BoundSubjectMismatch1836=== RUN TestValidateToken_MultipleProviders1837=== PAUSE TestValidateToken_MultipleProviders1838=== RUN TestValidateToken_NoMatchingProvider1839=== PAUSE TestValidateToken_NoMatchingProvider1840=== CONT TestGlobMatch1841=== CONT TestValidateToken_BoundClaimsMismatch1842=== CONT TestValidateToken_BoundSubjectMismatch1843=== CONT TestValidateToken_MultipleProviders1844=== CONT TestValidateToken_NoMatchingProvider1845=== CONT TestValidateToken_WrongAudience1846=== CONT TestValidateToken_Expired1847=== CONT TestValidateToken_ValidToken1848=== CONT TestAudienceForIssuer1849--- PASS: TestAudienceForIssuer (0.00s)1850=== RUN TestGlobMatch/foo_foo1851=== PAUSE TestGlobMatch/foo_foo1852=== RUN TestGlobMatch/foo_bar1853=== PAUSE TestGlobMatch/foo_bar1854=== RUN TestGlobMatch/*_1855=== PAUSE TestGlobMatch/*_1856=== RUN TestGlobMatch/*_anything1857=== PAUSE TestGlobMatch/*_anything1858=== RUN TestGlobMatch/foo*_foo1859=== PAUSE TestGlobMatch/foo*_foo1860=== RUN TestGlobMatch/foo*_foobar1861=== PAUSE TestGlobMatch/foo*_foobar1862=== RUN TestGlobMatch/foo*_bar1863=== PAUSE TestGlobMatch/foo*_bar1864=== RUN TestGlobMatch/*bar_bar1865=== PAUSE TestGlobMatch/*bar_bar1866=== RUN TestGlobMatch/*bar_foobar1867=== PAUSE TestGlobMatch/*bar_foobar1868=== RUN TestGlobMatch/*bar_foo1869=== PAUSE TestGlobMatch/*bar_foo1870=== RUN TestGlobMatch/foo*bar_foobar1871=== PAUSE TestGlobMatch/foo*bar_foobar1872=== RUN TestGlobMatch/foo*bar_foo123bar1873=== PAUSE TestGlobMatch/foo*bar_foo123bar1874=== RUN TestGlobMatch/foo*bar_foobarbaz1875=== PAUSE TestGlobMatch/foo*bar_foobarbaz1876=== RUN TestGlobMatch/*/*_foo/bar1877=== PAUSE TestGlobMatch/*/*_foo/bar1878=== RUN TestGlobMatch/*/*_foo1879=== PAUSE TestGlobMatch/*/*_foo1880=== RUN TestGlobMatch/refs/heads/*_refs/heads/main1881=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main1882=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.01883=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.01884=== RUN TestGlobMatch/refs/*/main_refs/heads/main1885=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main1886=== RUN TestGlobMatch/fo?_foo1887=== PAUSE TestGlobMatch/fo?_foo1888=== RUN TestGlobMatch/fo?_fo1889=== PAUSE TestGlobMatch/fo?_fo1890=== RUN TestGlobMatch/fo?_fooo1891=== PAUSE TestGlobMatch/fo?_fooo1892=== RUN TestGlobMatch/?oo_foo1893=== PAUSE TestGlobMatch/?oo_foo1894=== RUN TestGlobMatch/?oo_boo1895=== PAUSE TestGlobMatch/?oo_boo1896=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1897=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1898=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1899=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1900=== CONT TestGlobMatch/foo_foo1901=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1902=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1903=== CONT TestGlobMatch/?oo_boo1904=== CONT TestGlobMatch/?oo_foo1905=== CONT TestGlobMatch/fo?_fooo1906=== CONT TestGlobMatch/fo?_fo1907=== CONT TestGlobMatch/fo?_foo1908=== CONT TestGlobMatch/*bar_foobar1909=== CONT TestGlobMatch/*bar_bar1910=== CONT TestGlobMatch/foo*_bar1911=== CONT TestGlobMatch/foo*_foobar1912=== CONT TestGlobMatch/foo*_foo1913=== CONT TestGlobMatch/*_anything1914=== CONT TestGlobMatch/*_1915=== CONT TestGlobMatch/foo_bar1916=== CONT TestGlobMatch/*/*_foo1917=== CONT TestGlobMatch/refs/*/main_refs/heads/main1918=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.01919=== CONT TestGlobMatch/refs/heads/*_refs/heads/main1920=== CONT TestGlobMatch/foo*bar_foobarbaz1921=== CONT TestGlobMatch/*bar_foo1922=== CONT TestGlobMatch/foo*bar_foo123bar1923=== CONT TestGlobMatch/foo*bar_foobar1924=== CONT TestGlobMatch/*/*_foo/bar1925--- PASS: TestGlobMatch (0.00s)1926 --- PASS: TestGlobMatch/foo_foo (0.00s)1927 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)1928 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)1929 --- PASS: TestGlobMatch/?oo_boo (0.00s)1930 --- PASS: TestGlobMatch/?oo_foo (0.00s)1931 --- PASS: TestGlobMatch/fo?_fooo (0.00s)1932 --- PASS: TestGlobMatch/fo?_fo (0.00s)1933 --- PASS: TestGlobMatch/fo?_foo (0.00s)1934 --- PASS: TestGlobMatch/*bar_foobar (0.00s)1935 --- PASS: TestGlobMatch/*bar_bar (0.00s)1936 --- PASS: TestGlobMatch/foo*_bar (0.00s)1937 --- PASS: TestGlobMatch/foo*_foobar (0.00s)1938 --- PASS: TestGlobMatch/foo*_foo (0.00s)1939 --- PASS: TestGlobMatch/*_anything (0.00s)1940 --- PASS: TestGlobMatch/*_ (0.00s)1941 --- PASS: TestGlobMatch/foo_bar (0.00s)1942 --- PASS: TestGlobMatch/*/*_foo (0.00s)1943 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)1944 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)1945 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)1946 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)1947 --- PASS: TestGlobMatch/*bar_foo (0.00s)1948 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)1949 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)1950 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)19512026/07/19 11:32:32 INFO OIDC provider initialized name=test19522026/07/19 11:32:32 INFO OIDC provider initialized name=provider119532026/07/19 11:32:32 INFO OIDC provider initialized name=test19542026/07/19 11:32:32 INFO OIDC provider initialized name=provider119552026/07/19 11:32:32 INFO OIDC provider initialized name=test19562026/07/19 11:32:32 INFO OIDC provider initialized name=test19572026/07/19 11:32:32 INFO OIDC provider initialized name=test19582026/07/19 11:32:32 INFO OIDC provider initialized name=provider21959--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)1960--- PASS: TestValidateToken_WrongAudience (0.01s)1961--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)1962--- PASS: TestValidateToken_Expired (0.01s)1963--- PASS: TestValidateToken_NoMatchingProvider (0.01s)1964--- PASS: TestValidateToken_ValidToken (0.01s)1965--- PASS: TestValidateToken_MultipleProviders (0.01s)1966PASS1967Running hook tests...1968=== RUN TestSendPathsEmpty1969=== PAUSE TestSendPathsEmpty1970=== RUN TestQueueEnqueueAndFetch1971=== PAUSE TestQueueEnqueueAndFetch1972=== RUN TestQueueDeduplication1973=== PAUSE TestQueueDeduplication1974=== RUN TestQueueRemove1975=== PAUSE TestQueueRemove1976=== RUN TestQueueFetchBatchLimit1977=== PAUSE TestQueueFetchBatchLimit1978=== RUN TestQueueFetchRemoveLifecycle1979=== PAUSE TestQueueFetchRemoveLifecycle1980=== RUN TestQueueConcurrentWriters1981=== PAUSE TestQueueConcurrentWriters1982=== RUN TestServerClientIntegration1983=== PAUSE TestServerClientIntegration1984=== RUN TestServerQueueError1985=== PAUSE TestServerQueueError1986=== RUN TestGetListenerSocketActivation1987 server_test.go:210: === RUN TestGetListenerSocketActivation1988 --- PASS: TestGetListenerSocketActivation (0.00s)1989 PASS1990 1991--- PASS: TestGetListenerSocketActivation (0.01s)1992=== RUN TestWorkerUploadsAndRemoves1993=== PAUSE TestWorkerUploadsAndRemoves1994=== RUN TestWorkerSkipsGCdPaths1995=== PAUSE TestWorkerSkipsGCdPaths1996=== RUN TestWorkerPrunesClosureDeps1997=== PAUSE TestWorkerPrunesClosureDeps1998=== CONT TestSendPathsEmpty1999--- PASS: TestSendPathsEmpty (0.00s)2000=== CONT TestQueueFetchRemoveLifecycle2001=== CONT TestQueueConcurrentWriters2002=== CONT TestWorkerUploadsAndRemoves2003=== CONT TestWorkerPrunesClosureDeps2004=== CONT TestWorkerSkipsGCdPaths2005=== CONT TestQueueRemove2006=== CONT TestQueueFetchBatchLimit2007=== CONT TestQueueDeduplication2008=== CONT TestServerQueueError2009=== CONT TestServerClientIntegration20102026/07/19 11:32:32 ERROR Failed to queue paths error="permission denied" count=12011--- PASS: TestServerClientIntegration (0.00s)2012=== CONT TestQueueEnqueueAndFetch2013--- PASS: TestServerQueueError (0.00s)2014--- PASS: TestQueueFetchBatchLimit (0.01s)20152026/07/19 11:32:32 INFO Upload queue status pending=220162026/07/19 11:32:32 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-12522-1347016672/TestWorkerSkipsGCdPaths2655872109/002/nonexistent20172026/07/19 11:32:32 INFO Uploading batch count=12018--- PASS: TestQueueRemove (0.01s)2019--- PASS: TestQueueDeduplication (0.01s)20202026/07/19 11:32:32 INFO Upload queue status pending=220212026/07/19 11:32:32 INFO Uploading batch count=120222026/07/19 11:32:32 INFO Upload queue status pending=220232026/07/19 11:32:32 INFO Uploading batch count=22024--- PASS: TestQueueEnqueueAndFetch (0.01s)2025--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2026--- PASS: TestWorkerSkipsGCdPaths (0.06s)2027--- PASS: TestWorkerUploadsAndRemoves (0.06s)2028--- PASS: TestWorkerPrunesClosureDeps (0.06s)2029--- PASS: TestQueueConcurrentWriters (0.16s)2030PASS