nixbot

builds

succeeded niks3-go-unit-tests checks.aarch64-linux.go-unit-tests · build #155 · raw

1tribuchet: hub connection lost (hub closed event stream without a result); reconnecting2tribuchet: building on eliza3Running client tests...4=== RUN TestDoServerRequestAttachesToken5=== PAUSE TestDoServerRequestAttachesToken6=== RUN TestCaseHackSuffix7=== PAUSE TestCaseHackSuffix8=== RUN TestFilterOversizedClosures9=== PAUSE TestFilterOversizedClosures10=== RUN TestPartSizeForNAR11=== PAUSE TestPartSizeForNAR12=== RUN TestUploadMultipart_SupersededByPeer13=== PAUSE TestUploadMultipart_SupersededByPeer14=== RUN TestDumpPathMatchesNix15=== PAUSE TestDumpPathMatchesNix16=== RUN TestDumpPathSingleFile17=== PAUSE TestDumpPathSingleFile18=== RUN TestDumpPathWriterError19=== PAUSE TestDumpPathWriterError20=== RUN TestEncodeNixBase3221=== PAUSE TestEncodeNixBase3222=== RUN TestEncodeNixBase32WithRealHash23=== PAUSE TestEncodeNixBase32WithRealHash24=== RUN TestConvertHashToNix3225=== PAUSE TestConvertHashToNix3226=== RUN TestGetStorePathHash27=== PAUSE TestGetStorePathHash28=== RUN TestPathInfoHashCompatibility29=== PAUSE TestPathInfoHashCompatibility30=== RUN TestParsePathInfoJSON31=== PAUSE TestParsePathInfoJSON32=== RUN TestParsePathInfoJSONMultiplePaths33=== PAUSE TestParsePathInfoJSONMultiplePaths34=== RUN TestPathInfoCACompatibility35=== PAUSE TestPathInfoCACompatibility36=== RUN TestRateLimiterFeedback37=== PAUSE TestRateLimiterFeedback38=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess39=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess40=== RUN TestResolveStorePath41=== PAUSE TestResolveStorePath42=== RUN TestDoWithRetry_BodyReplayedViaGetBody43=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody44=== RUN TestShellSplit45=== PAUSE TestShellSplit46=== RUN TestShellSplitErrors47=== PAUSE TestShellSplitErrors48=== RUN TestSetClientTLS49=== PAUSE TestSetClientTLS50=== RUN TestSetClientTLSDoesNotMutateDefaultTransport51=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport52=== RUN TestSetClientTLSErrors53=== PAUSE TestSetClientTLSErrors54=== RUN TestStaticToken55=== PAUSE TestStaticToken56=== RUN TestFileTokenReadsAndCaches57=== PAUSE TestFileTokenReadsAndCaches58=== RUN TestFileTokenMissing59=== PAUSE TestFileTokenMissing60=== RUN TestFileTokenEmpty61=== PAUSE TestFileTokenEmpty62=== RUN TestScriptTokenNoExpiryRerunsEveryCall63=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall64=== RUN TestScriptTokenCachesUntilRefresh65=== PAUSE TestScriptTokenCachesUntilRefresh66=== RUN TestScriptTokenEmptyToken67=== PAUSE TestScriptTokenEmptyToken68=== RUN TestScriptTokenBadJSON69=== PAUSE TestScriptTokenBadJSON70=== RUN TestScriptTokenScriptFails71=== PAUSE TestScriptTokenScriptFails72=== RUN TestScriptTokenEmptyCommand73=== PAUSE TestScriptTokenEmptyCommand74=== CONT TestDoServerRequestAttachesToken75=== CONT TestFileTokenMissing76=== CONT TestResolveStorePath77=== CONT TestScriptTokenEmptyToken78=== CONT TestScriptTokenCachesUntilRefresh79=== CONT TestEncodeNixBase32WithRealHash80=== CONT TestScriptTokenEmptyCommand81--- PASS: TestEncodeNixBase32WithRealHash (0.00s)82--- PASS: TestScriptTokenEmptyCommand (0.00s)83=== CONT TestParsePathInfoJSON84--- PASS: TestFileTokenMissing (0.00s)85=== CONT TestShellSplit86=== CONT TestScriptTokenScriptFails87=== CONT TestScriptTokenBadJSON88--- PASS: TestShellSplit (0.00s)89=== CONT TestUploadMultipart_SupersededByPeer90=== RUN TestUploadMultipart_SupersededByPeer/exists91=== CONT TestPartSizeForNAR92--- PASS: TestResolveStorePath (0.00s)93=== PAUSE TestUploadMultipart_SupersededByPeer/exists94=== RUN TestPartSizeForNAR/zero_stays_at_minimum95=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum96=== RUN TestUploadMultipart_SupersededByPeer/missing97=== PAUSE TestUploadMultipart_SupersededByPeer/missing98=== CONT TestStaticToken99--- PASS: TestStaticToken (0.00s)100=== CONT TestFilterOversizedClosures101=== CONT TestGetStorePathHash102=== CONT TestParsePathInfoJSONMultiplePaths103=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess104=== CONT TestRateLimiterFeedback105=== CONT TestPathInfoCACompatibility106=== CONT TestDumpPathMatchesNix107=== CONT TestEncodeNixBase32108=== CONT TestDumpPathWriterError109=== CONT TestDumpPathSingleFile110=== CONT TestShellSplitErrors111=== CONT TestSetClientTLS112=== CONT TestPathInfoHashCompatibility113=== CONT TestFileTokenEmpty114=== RUN TestGetStorePathHash/valid_store_path115=== PAUSE TestGetStorePathHash/valid_store_path116=== RUN TestGetStorePathHash/basename_without_hyphen_should_error117=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error118=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error119=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error120=== RUN TestRateLimiterFeedback/429_enables_limiter121=== PAUSE TestRateLimiterFeedback/429_enables_limiter122=== RUN TestRateLimiterFeedback/503_enables_limiter123=== PAUSE TestRateLimiterFeedback/503_enables_limiter1242026/08/27 10:01:12 WARN Rate limiter enabled after throttle name=server-test rate=5125=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter126=== RUN TestEncodeNixBase32/test_string_hash127=== PAUSE TestEncodeNixBase32/test_string_hash128=== RUN TestEncodeNixBase32/empty_input129=== PAUSE TestEncodeNixBase32/empty_input130=== CONT TestSetClientTLSDoesNotMutateDefaultTransport131=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter132--- PASS: TestShellSplitErrors (0.00s)133=== CONT TestFileTokenReadsAndCaches134=== CONT TestDoWithRetry_BodyReplayedViaGetBody135=== RUN TestPartSizeForNAR/small_stays_at_minimum136=== PAUSE TestPartSizeForNAR/small_stays_at_minimum137=== CONT TestSetClientTLSErrors138=== RUN TestFilterOversizedClosures/no_limit_keeps_everything139=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths140=== RUN TestPathInfoCACompatibility/null_ca_field141=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error142=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)143=== CONT TestConvertHashToNix32144=== RUN TestParsePathInfoJSON/Nix_format145=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter146=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything147=== RUN TestConvertHashToNix32/SRI_format_to_Nix32148=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum149=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error150--- PASS: TestScriptTokenScriptFails (0.00s)151=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped152=== CONT TestCaseHackSuffix153=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter154=== CONT TestScriptTokenNoExpiryRerunsEveryCall155--- PASS: TestFileTokenEmpty (0.00s)156=== CONT TestEncodeNixBase32/test_string_hash157=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths158=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths159=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths160=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32161=== CONT TestEncodeNixBase32/empty_input162=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum163=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts164=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts165=== RUN TestPartSizeForNAR/1_TiB166=== PAUSE TestParsePathInfoJSON/Nix_format167=== CONT TestGetStorePathHash/valid_store_path168=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error169=== CONT TestUploadMultipart_SupersededByPeer/exists170=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped171=== CONT TestGetStorePathHash/basename_without_hyphen_should_error172=== RUN TestConvertHashToNix32/already_Nix32_format173--- PASS: TestDoServerRequestAttachesToken (0.00s)174=== PAUSE TestPathInfoCACompatibility/null_ca_field175=== CONT TestRateLimiterFeedback/429_enables_limiter176=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error177=== RUN TestPathInfoCACompatibility/old_string_format_-_text178=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter179=== RUN TestParsePathInfoJSON/Lix_format180=== PAUSE TestParsePathInfoJSON/Lix_format181=== RUN TestParsePathInfoJSON/empty_input182=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)183=== RUN TestFilterOversizedClosures/all_closures_skipped184=== PAUSE TestConvertHashToNix32/already_Nix32_format185=== CONT TestUploadMultipart_SupersededByPeer/missing186=== PAUSE TestPartSizeForNAR/1_TiB187=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter188=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text189--- PASS: TestEncodeNixBase32 (0.00s)190 --- PASS: TestEncodeNixBase32/empty_input (0.00s)191 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)192=== PAUSE TestParsePathInfoJSON/empty_input193=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon194=== RUN TestConvertHashToNix32/invalid_format1952026/08/27 10:01:12 WARN Rate limiter enabled after throttle name=server-test rate=51962026/08/27 10:01:12 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:34721197=== PAUSE TestFilterOversizedClosures/all_closures_skipped198=== RUN TestPartSizeForNAR/5_TiB_S3_max_object199=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object200=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive201=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive202=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2032026/08/27 10:01:12 WARN Rate limiter backed off name=server-test rate=52042026/08/27 10:01:12 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:347212052026/08/27 10:01:12 WARN Rate limiter enabled after throttle name=server-test rate=5206=== CONT TestFilterOversizedClosures/no_limit_keeps_everything2072026/08/27 10:01:12 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:39497208=== CONT TestFilterOversizedClosures/all_closures_skipped209--- PASS: TestScriptTokenBadJSON (0.01s)2102026/08/27 10:01:12 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=50211=== CONT TestRateLimiterFeedback/503_enables_limiter2122026/08/27 10:01:12 WARN Rate limiter backed off name=server-test rate=5213=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped214=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths2152026/08/27 10:01:12 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=2000216=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon217=== PAUSE TestConvertHashToNix32/invalid_format218=== CONT TestConvertHashToNix32/SRI_format_to_Nix32219=== CONT TestConvertHashToNix32/already_Nix32_format220=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI221=== RUN TestPathInfoCACompatibility/new_structured_format_-_text222=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text223--- PASS: TestGetStorePathHash (0.00s)224 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)225 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)226 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)227 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)2282026/08/27 10:01:12 WARN Rate limiter enabled after throttle name=server-test rate=5229--- PASS: TestFileTokenReadsAndCaches (0.01s)2302026/08/27 10:01:12 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:37329231=== RUN TestParsePathInfoJSON/whitespace_only232=== CONT TestConvertHashToNix32/invalid_format233=== PAUSE TestParsePathInfoJSON/whitespace_only234=== RUN TestPartSizeForNAR/capped_at_5_GiB235=== RUN TestSetClientTLSErrors/missing_cert_file236=== PAUSE TestSetClientTLSErrors/missing_cert_file237=== PAUSE TestPartSizeForNAR/capped_at_5_GiB2382026/08/27 10:01:12 WARN Rate limiter backed off name=server-test rate=5239=== RUN TestSetClientTLSErrors/missing_key_file240=== PAUSE TestSetClientTLSErrors/missing_key_file241=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method242=== RUN TestSetClientTLSErrors/missing_ca_file243=== PAUSE TestSetClientTLSErrors/missing_ca_file244=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method245=== RUN TestParsePathInfoJSON/invalid_JSON246=== PAUSE TestParsePathInfoJSON/invalid_JSON247=== CONT TestParsePathInfoJSON/Nix_format248=== CONT TestParsePathInfoJSON/invalid_JSON249=== CONT TestParsePathInfoJSON/Lix_format250=== CONT TestParsePathInfoJSON/whitespace_only251=== CONT TestPartSizeForNAR/capped_at_5_GiB252=== CONT TestPartSizeForNAR/zero_stays_at_minimum253=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts254=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum255=== CONT TestPartSizeForNAR/5_TiB_S3_max_object256=== CONT TestPartSizeForNAR/small_stays_at_minimum257=== CONT TestPartSizeForNAR/1_TiB258--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)259--- PASS: TestScriptTokenEmptyToken (0.01s)260--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)261=== RUN TestSetClientTLSErrors/invalid_ca_file262=== CONT TestPathInfoCACompatibility/null_ca_field263=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method264=== CONT TestPathInfoCACompatibility/new_structured_format_-_text265=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive266=== CONT TestPathInfoCACompatibility/old_string_format_-_text267=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI268=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512269=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512270=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)271=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512272=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI273--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)274 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)275 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)276=== PAUSE TestSetClientTLSErrors/invalid_ca_file277--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)278 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)279 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)280--- PASS: TestRateLimiterFeedback (0.00s)281 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)282 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)283 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)284 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)285=== CONT TestSetClientTLSErrors/missing_cert_file286--- PASS: TestPartSizeForNAR (0.01s)287 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)288 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)289 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)290 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)291 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)292 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)293 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)294--- PASS: TestConvertHashToNix32 (0.01s)295 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)296 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)297 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)298=== CONT TestParsePathInfoJSON/empty_input299=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon300=== CONT TestSetClientTLSErrors/invalid_ca_file301=== CONT TestSetClientTLSErrors/missing_ca_file302=== CONT TestSetClientTLSErrors/missing_key_file303--- PASS: TestFilterOversizedClosures (0.01s)304 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)305 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)306 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)307=== RUN TestSetClientTLS/rejects_connection_without_client_cert308=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert309=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA310=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA311--- PASS: TestPathInfoCACompatibility (0.01s)312 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)313 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)314 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)315 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)316 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)317=== RUN TestSetClientTLS/preserves_debug_logging_transport318--- PASS: TestParsePathInfoJSON (0.01s)319 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)320 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)321 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)322 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)323 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)324--- PASS: TestPathInfoHashCompatibility (0.01s)325 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)326 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)327 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)328 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)329=== PAUSE TestSetClientTLS/preserves_debug_logging_transport330=== CONT TestSetClientTLS/rejects_connection_without_client_cert331=== CONT TestSetClientTLS/preserves_debug_logging_transport332=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA333--- PASS: TestSetClientTLSErrors (0.01s)334 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)335 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)336 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)337 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)338--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)339--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)3402026/08/27 10:01:12 http: TLS handshake error from 127.0.0.1:46872: remote error: tls: bad certificate341--- PASS: TestSetClientTLS (0.01s)342 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)343 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)344 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)345--- PASS: TestDumpPathSingleFile (0.04s)346--- PASS: TestCaseHackSuffix (0.04s)347--- PASS: TestDumpPathWriterError (0.04s)348--- PASS: TestDumpPathMatchesNix (0.08s)349--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)350PASS351Running server tests...352The files belonging to this database system will be owned by user "nixbld".353This user must also own the server process.354355The database cluster will be initialized with locale "C".356The default database encoding has accordingly been set to "SQL_ASCII".357The default text search configuration will be set to "english".358359Data page checksums are enabled.360361creating directory /build/postgres3475209903/data ... ok362creating subdirectories ... ok363selecting dynamic shared memory implementation ... posix364selecting default "max_connections" ... 100365selecting default "shared_buffers" ... 128MB366selecting default time zone ... UTC367creating configuration files ... ok368running bootstrap script ... ok369performing post-bootstrap initialization ... ok370syncing data to disk ... ok371372initdb: warning: enabling "trust" authentication for local connections373initdb: 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.374375Success. You can now start the database server using:376377 pg_ctl -D /build/postgres3475209903/data -l logfile start378379/build/postgres3475209903:5432 - no response3802026-08-27 10:01:14.494 UTC [112] LOG: starting PostgreSQL 18.4 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit3812026-08-27 10:01:14.494 UTC [112] LOG: listening on Unix socket "/build/postgres3475209903/.s.PGSQL.5432"3822026-08-27 10:01:14.499 UTC [119] LOG: database system was shut down at 2026-08-27 10:01:14 UTC3832026-08-27 10:01:14.502 UTC [112] LOG: database system is ready to accept connections384/build/postgres3475209903:5432 - accepting connections385=== 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-08-27 10:01:16.526 UTC [521] ERROR: relation "goose_db_version" does not exist at character 364132026-08-27 10:01:16.526 UTC [521] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4142026/08/27 10:01:16 OK 20241026095416_initial_model.sql (12.64ms)4152026/08/27 10:01:16 OK 20251210153512_drop_unused_gin_index.sql (2.24ms)4162026/08/27 10:01:16 OK 20251218171726_add_pins.sql (2.85ms)4172026/08/27 10:01:16 OK 20260628120000_add_object_size_and_stats.sql (2.51ms)4182026/08/27 10:01:16 goose: successfully migrated database to version: 202606281200004192026/08/27 10:01:16 OK 1_commit_pending_closure.sql (1.8ms)4202026/08/27 10:01:16 OK 2_object_stats_trigger.sql (700.11µs)4212026/08/27 10:01:16 goose: up to current file version: 2422--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.50s)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 TestReadRedirectNar494=== PAUSE TestReadRedirectNar495=== RUN TestReadRedirectKeepsNarinfoProxied496=== PAUSE TestReadRedirectKeepsNarinfoProxied497=== RUN TestReadProxyRangeRequest498=== PAUSE TestReadProxyRangeRequest499=== RUN TestRedundantMultipartUpload500=== PAUSE TestRedundantMultipartUpload501=== RUN TestCompleteMultipartUpload_ErrorButObjectExists502=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists503=== RUN TestCompletedNarNotReofferedAcrossClosures504=== PAUSE TestCompletedNarNotReofferedAcrossClosures505=== RUN TestPresignedUploadRegisteredBeforeCommit506=== PAUSE TestPresignedUploadRegisteredBeforeCommit507=== RUN TestService_Rustfstest508=== PAUSE TestService_Rustfstest509=== RUN TestParseSize510=== PAUSE TestParseSize511=== RUN TestSkippedUploadsHandler512=== PAUSE TestSkippedUploadsHandler513=== RUN TestSystemdListenerNotActivated514--- PASS: TestSystemdListenerNotActivated (0.00s)515=== RUN TestWatchdogBeatsWhenHealthy516--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)517=== RUN TestWatchdogSkipsWhenUnhealthy5182026/08/27 10:01:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5192026/08/27 10:01:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5202026/08/27 10:01:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5212026/08/27 10:01:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5222026/08/27 10:01:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5232026/08/27 10:01:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5242026/08/27 10:01:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5252026/08/27 10:01:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5262026/08/27 10:01:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5272026/08/27 10:01:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"528--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)529=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle530=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle531=== RUN TestProxyWriteTimeout532=== PAUSE TestProxyWriteTimeout533=== RUN TestIsValidUploadKey534=== PAUSE TestIsValidUploadKey535=== RUN TestUploadHandlersRejectInvalidKeys536=== PAUSE TestUploadHandlersRejectInvalidKeys537=== RUN TestUploadHandlersRejectOversizedBody538=== PAUSE TestUploadHandlersRejectOversizedBody539=== RUN TestService_cleanupPendingClosuresHandler540=== PAUSE TestService_cleanupPendingClosuresHandler541=== RUN TestService_createPendingClosureHandler542=== PAUSE TestService_createPendingClosureHandler543=== RUN TestService_verifyS3Integrity544=== PAUSE TestService_verifyS3Integrity545=== RUN TestCompleteMultipartUnregistered546=== PAUSE TestCompleteMultipartUnregistered547=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT548=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT549=== CONT TestCompleteMultipartUnregistered550=== CONT TestRedundantMultipartUpload551=== CONT TestCacheConfigHandlerMaxNarSize552=== CONT TestGCBugBareHashReferences553=== CONT TestService_verifyS3Integrity554=== CONT TestService_createPendingClosureHandler555=== CONT TestService_cleanupPendingClosuresHandler556--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)557=== CONT TestGCTaskStore_CompletedAllowsNewTask558=== CONT TestUploadHandlersRejectOversizedBody559=== CONT TestUploadHandlersRejectInvalidKeys560=== CONT TestIsValidUploadKey561=== CONT TestProxyWriteTimeout562=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle563=== CONT TestSkippedUploadsHandler564=== CONT TestParseSize565=== CONT TestService_Rustfstest566=== CONT TestPresignedUploadRegisteredBeforeCommit567=== CONT TestCompletedNarNotReofferedAcrossClosures568=== CONT TestCompleteMultipartUpload_ErrorButObjectExists569=== CONT TestGenerateLandingPage570=== CONT TestService_healthCheckHandler571=== CONT TestGracefulShutdownDrainsInflight572=== CONT TestGCTaskStore_Fail573=== CONT TestGCTaskStore_PhaseUpdates574=== CONT TestService_AuthMiddleware575--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)576=== CONT TestReadProxyNarinfo577=== RUN TestIsValidUploadKey/narinfo578=== PAUSE TestIsValidUploadKey/narinfo579=== RUN TestProxyWriteTimeout/narinfo580=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info581--- PASS: TestGCTaskStore_Fail (0.00s)582=== CONT TestGCTaskStore_GetReturnsLatest583--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)584=== CONT TestGCTaskStore_GetEmpty585--- PASS: TestGCTaskStore_GetEmpty (0.00s)586=== CONT TestReadProxyRangeRequest5872026/08/27 10:01:17 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000588--- PASS: TestParseSize (0.00s)589--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)590=== CONT TestGCTaskStore_ConflictDifferentParams591--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)592=== CONT TestGCTaskStore_DeduplicateSameParams593--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)594=== CONT TestReadRedirectNar595=== CONT TestReadRedirectKeepsNarinfoProxied596=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info597=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal598=== PAUSE TestProxyWriteTimeout/narinfo599=== RUN TestIsValidUploadKey/nar_zst600=== RUN TestProxyWriteTimeout/1_GiB_nar601--- PASS: TestGenerateLandingPage (0.01s)602--- PASS: TestSkippedUploadsHandler (0.01s)603=== CONT TestReadProxyDisabled604=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal605=== PAUSE TestProxyWriteTimeout/1_GiB_nar606=== PAUSE TestIsValidUploadKey/nar_zst6072026/08/27 10:01:17 INFO Starting HTTP server address=127.0.0.1:32835608=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key609=== CONT TestGCTaskStore_StartNew610=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key611--- PASS: TestGCTaskStore_StartNew (0.00s)612=== RUN TestProxyWriteTimeout/10_GiB_nar613=== RUN TestIsValidUploadKey/nar_xz614=== PAUSE TestIsValidUploadKey/nar_xz615=== RUN TestIsValidUploadKey/nar_plain616=== CONT TestGCMetrics617=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key618=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key619=== PAUSE TestProxyWriteTimeout/10_GiB_nar6202026/08/27 10:01:17 INFO Shutdown signal received, draining in-flight requests timeout=10s621=== PAUSE TestIsValidUploadKey/nar_plain622=== CONT TestReadProxyRootRedirectsToIndexHTML623=== RUN TestProxyWriteTimeout/unknown_size624=== PAUSE TestProxyWriteTimeout/unknown_size625=== RUN TestIsValidUploadKey/listing626=== CONT TestReadProxyConditionalGet627=== PAUSE TestIsValidUploadKey/listing628=== RUN TestIsValidUploadKey/build_log629=== PAUSE TestIsValidUploadKey/build_log630=== RUN TestIsValidUploadKey/build_log_home-manager_file631=== PAUSE TestIsValidUploadKey/build_log_home-manager_file632=== RUN TestIsValidUploadKey/build_log_plus_in_name633=== PAUSE TestIsValidUploadKey/build_log_plus_in_name634=== RUN TestIsValidUploadKey/build_log_question_mark635=== PAUSE TestIsValidUploadKey/build_log_question_mark636=== RUN TestIsValidUploadKey/build_log_equals637=== PAUSE TestIsValidUploadKey/build_log_equals638=== RUN TestIsValidUploadKey/realisation639=== PAUSE TestIsValidUploadKey/realisation640=== RUN TestIsValidUploadKey/realisation_plus_in_output641=== PAUSE TestIsValidUploadKey/realisation_plus_in_output642=== RUN TestIsValidUploadKey/nix-cache-info643=== PAUSE TestIsValidUploadKey/nix-cache-info644=== RUN TestIsValidUploadKey/index.html645=== PAUSE TestIsValidUploadKey/index.html646=== RUN TestIsValidUploadKey/narinfo_key,_nar_type647=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type648=== RUN TestIsValidUploadKey/nar_key,_narinfo_type649=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type650=== RUN TestIsValidUploadKey/listing_key,_narinfo_type651=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type652=== RUN TestIsValidUploadKey/traversal653=== PAUSE TestIsValidUploadKey/traversal654=== RUN TestIsValidUploadKey/traversal_nar655=== PAUSE TestIsValidUploadKey/traversal_nar656=== RUN TestIsValidUploadKey/absolute657=== PAUSE TestIsValidUploadKey/absolute658=== RUN TestIsValidUploadKey/empty_key659=== PAUSE TestIsValidUploadKey/empty_key660=== RUN TestIsValidUploadKey/unknown_type661=== PAUSE TestIsValidUploadKey/unknown_type662=== CONT TestObjectStatsTrigger6632026-08-27 10:01:17.250 UTC [589] ERROR: relation "goose_db_version" does not exist at character 366642026-08-27 10:01:17.250 UTC [589] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6652026-08-27 10:01:17.285 UTC [590] ERROR: relation "goose_db_version" does not exist at character 366662026-08-27 10:01:17.285 UTC [590] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC667--- PASS: TestGracefulShutdownDrainsInflight (0.13s)668=== CONT TestReadProxyHead669=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure670=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure671=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart672=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart673=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts674=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts675=== CONT TestIsValidCachePath676=== RUN TestIsValidCachePath/narinfo677=== PAUSE TestIsValidCachePath/narinfo678=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars679=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars680=== RUN TestIsValidCachePath/nar_zst681=== PAUSE TestIsValidCachePath/nar_zst682=== RUN TestIsValidCachePath/nar_xz683=== PAUSE TestIsValidCachePath/nar_xz684=== RUN TestIsValidCachePath/nar_bz2685=== PAUSE TestIsValidCachePath/nar_bz2686=== RUN TestIsValidCachePath/nar_uncompressed687=== PAUSE TestIsValidCachePath/nar_uncompressed688=== RUN TestIsValidCachePath/ls689=== PAUSE TestIsValidCachePath/ls690=== RUN TestIsValidCachePath/log691=== PAUSE TestIsValidCachePath/log692=== RUN TestIsValidCachePath/realisation693=== PAUSE TestIsValidCachePath/realisation694=== RUN TestIsValidCachePath/nix-cache-info695=== PAUSE TestIsValidCachePath/nix-cache-info696=== RUN TestIsValidCachePath/index.html697=== PAUSE TestIsValidCachePath/index.html698=== RUN TestIsValidCachePath/traversal_parent699=== PAUSE TestIsValidCachePath/traversal_parent700=== RUN TestIsValidCachePath/traversal_in_middle701=== PAUSE TestIsValidCachePath/traversal_in_middle702=== RUN TestIsValidCachePath/invalid_char_e703=== PAUSE TestIsValidCachePath/invalid_char_e704=== RUN TestIsValidCachePath/invalid_char_u705=== PAUSE TestIsValidCachePath/invalid_char_u706=== RUN TestIsValidCachePath/random_path707=== PAUSE TestIsValidCachePath/random_path708=== RUN TestIsValidCachePath/empty709=== PAUSE TestIsValidCachePath/empty710=== RUN TestIsValidCachePath/leading_slash711=== PAUSE TestIsValidCachePath/leading_slash712=== RUN TestIsValidCachePath/wrong_extension713=== PAUSE TestIsValidCachePath/wrong_extension714=== RUN TestIsValidCachePath/short_hash715=== PAUSE TestIsValidCachePath/short_hash716=== CONT TestReadProxyInvalidPath7172026-08-27 10:01:17.297 UTC [592] ERROR: relation "goose_db_version" does not exist at character 367182026-08-27 10:01:17.297 UTC [592] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7192026-08-27 10:01:17.316 UTC [594] ERROR: relation "goose_db_version" does not exist at character 367202026-08-27 10:01:17.316 UTC [594] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7212026-08-27 10:01:17.316 UTC [596] ERROR: relation "goose_db_version" does not exist at character 367222026-08-27 10:01:17.316 UTC [596] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7232026-08-27 10:01:17.320 UTC [597] ERROR: relation "goose_db_version" does not exist at character 367242026-08-27 10:01:17.320 UTC [597] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7252026/08/27 10:01:17 OK 20241026095416_initial_model.sql (60.7ms)7262026/08/27 10:01:17 OK 20251210153512_drop_unused_gin_index.sql (16.79ms)7272026/08/27 10:01:17 OK 20241026095416_initial_model.sql (46.45ms)7282026-08-27 10:01:17.370 UTC [602] ERROR: relation "goose_db_version" does not exist at character 367292026-08-27 10:01:17.370 UTC [602] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7302026/08/27 10:01:17 OK 20241026095416_initial_model.sql (62.71ms)7312026/08/27 10:01:17 OK 20251210153512_drop_unused_gin_index.sql (11.19ms)7322026/08/27 10:01:17 OK 20241026095416_initial_model.sql (41.45ms)7332026/08/27 10:01:17 OK 20251210153512_drop_unused_gin_index.sql (6.35ms)7342026/08/27 10:01:17 OK 20251210153512_drop_unused_gin_index.sql (4.05ms)7352026/08/27 10:01:17 OK 20251218171726_add_pins.sql (22.02ms)7362026/08/27 10:01:17 OK 20241026095416_initial_model.sql (44.27ms)7372026/08/27 10:01:17 OK 20251218171726_add_pins.sql (17.4ms)7382026-08-27 10:01:17.396 UTC [603] ERROR: relation "goose_db_version" does not exist at character 367392026-08-27 10:01:17.396 UTC [603] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7402026/08/27 10:01:17 OK 20251218171726_add_pins.sql (17.59ms)7412026/08/27 10:01:17 OK 20251218171726_add_pins.sql (14.66ms)7422026/08/27 10:01:17 OK 20251210153512_drop_unused_gin_index.sql (11.21ms)7432026/08/27 10:01:17 OK 20260628120000_add_object_size_and_stats.sql (18.86ms)7442026/08/27 10:01:17 goose: successfully migrated database to version: 202606281200007452026/08/27 10:01:17 OK 20241026095416_initial_model.sql (46.08ms)7462026/08/27 10:01:17 OK 20260628120000_add_object_size_and_stats.sql (10.87ms)7472026/08/27 10:01:17 goose: successfully migrated database to version: 202606281200007482026/08/27 10:01:17 OK 20241026095416_initial_model.sql (24.08ms)7492026/08/27 10:01:17 OK 20260628120000_add_object_size_and_stats.sql (9.74ms)7502026/08/27 10:01:17 goose: successfully migrated database to version: 202606281200007512026/08/27 10:01:17 OK 20260628120000_add_object_size_and_stats.sql (9.62ms)7522026/08/27 10:01:17 goose: successfully migrated database to version: 202606281200007532026/08/27 10:01:17 OK 20251218171726_add_pins.sql (9.31ms)7542026/08/27 10:01:17 OK 20251210153512_drop_unused_gin_index.sql (5.26ms)7552026/08/27 10:01:17 OK 1_commit_pending_closure.sql (5.62ms)7562026/08/27 10:01:17 OK 20251210153512_drop_unused_gin_index.sql (4.42ms)7572026/08/27 10:01:17 OK 1_commit_pending_closure.sql (5.75ms)7582026-08-27 10:01:17.412 UTC [604] ERROR: relation "goose_db_version" does not exist at character 367592026-08-27 10:01:17.412 UTC [604] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7602026-08-27 10:01:17.413 UTC [605] ERROR: relation "goose_db_version" does not exist at character 367612026-08-27 10:01:17.413 UTC [605] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7622026/08/27 10:01:17 OK 1_commit_pending_closure.sql (6.29ms)7632026/08/27 10:01:17 OK 2_object_stats_trigger.sql (4.75ms)7642026/08/27 10:01:17 goose: up to current file version: 27652026/08/27 10:01:17 OK 1_commit_pending_closure.sql (6.24ms)7662026-08-27 10:01:17.414 UTC [606] ERROR: relation "goose_db_version" does not exist at character 367672026-08-27 10:01:17.414 UTC [606] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7682026/08/27 10:01:17 OK 2_object_stats_trigger.sql (3.98ms)7692026/08/27 10:01:17 goose: up to current file version: 27702026/08/27 10:01:17 OK 2_object_stats_trigger.sql (3.3ms)7712026/08/27 10:01:17 goose: up to current file version: 27722026/08/27 10:01:17 OK 20260628120000_add_object_size_and_stats.sql (9.53ms)7732026/08/27 10:01:17 goose: successfully migrated database to version: 202606281200007742026/08/27 10:01:17 OK 20251218171726_add_pins.sql (6.77ms)7752026/08/27 10:01:17 OK 20251218171726_add_pins.sql (8.54ms)7762026/08/27 10:01:17 OK 2_object_stats_trigger.sql (3.06ms)7772026/08/27 10:01:17 goose: up to current file version: 27782026-08-27 10:01:17.418 UTC [607] ERROR: relation "goose_db_version" does not exist at character 367792026-08-27 10:01:17.418 UTC [607] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7802026/08/27 10:01:17 OK 20241026095416_initial_model.sql (15.55ms)7812026/08/27 10:01:17 OK 20260628120000_add_object_size_and_stats.sql (4.92ms)7822026/08/27 10:01:17 goose: successfully migrated database to version: 202606281200007832026/08/27 10:01:17 OK 1_commit_pending_closure.sql (5.18ms)7842026-08-27 10:01:17.423 UTC [608] ERROR: relation "goose_db_version" does not exist at character 367852026-08-27 10:01:17.423 UTC [608] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7862026/08/27 10:01:17 OK 20251210153512_drop_unused_gin_index.sql (4.53ms)7872026/08/27 10:01:17 OK 1_commit_pending_closure.sql (4.64ms)7882026/08/27 10:01:17 OK 2_object_stats_trigger.sql (4.58ms)7892026/08/27 10:01:17 goose: up to current file version: 27902026/08/27 10:01:17 OK 20260628120000_add_object_size_and_stats.sql (9.67ms)7912026/08/27 10:01:17 goose: successfully migrated database to version: 202606281200007922026-08-27 10:01:17.431 UTC [609] ERROR: relation "goose_db_version" does not exist at character 367932026-08-27 10:01:17.431 UTC [609] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7942026/08/27 10:01:17 OK 2_object_stats_trigger.sql (4.89ms)7952026/08/27 10:01:17 goose: up to current file version: 27962026/08/27 10:01:17 OK 20251218171726_add_pins.sql (6.18ms)7972026/08/27 10:01:17 OK 1_commit_pending_closure.sql (4.75ms)7982026-08-27 10:01:17.434 UTC [610] ERROR: relation "goose_db_version" does not exist at character 367992026-08-27 10:01:17.434 UTC [610] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8002026-08-27 10:01:17.437 UTC [611] ERROR: relation "goose_db_version" does not exist at character 368012026-08-27 10:01:17.437 UTC [611] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8022026-08-27 10:01:17.440 UTC [612] ERROR: relation "goose_db_version" does not exist at character 368032026-08-27 10:01:17.440 UTC [612] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8042026-08-27 10:01:17.442 UTC [613] ERROR: relation "goose_db_version" does not exist at character 368052026-08-27 10:01:17.442 UTC [613] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8062026-08-27 10:01:17.443 UTC [614] ERROR: relation "goose_db_version" does not exist at character 368072026-08-27 10:01:17.443 UTC [614] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8082026/08/27 10:01:17 OK 20260628120000_add_object_size_and_stats.sql (11.83ms)8092026/08/27 10:01:17 goose: successfully migrated database to version: 202606281200008102026/08/27 10:01:17 OK 20241026095416_initial_model.sql (18.46ms)8112026/08/27 10:01:17 OK 2_object_stats_trigger.sql (11.71ms)8122026/08/27 10:01:17 goose: up to current file version: 28132026/08/27 10:01:17 OK 20241026095416_initial_model.sql (18.78ms)8142026/08/27 10:01:17 OK 20241026095416_initial_model.sql (19.86ms)8152026/08/27 10:01:17 OK 20241026095416_initial_model.sql (16.17ms)8162026-08-27 10:01:17.446 UTC [615] ERROR: relation "goose_db_version" does not exist at character 368172026-08-27 10:01:17.446 UTC [615] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8182026-08-27 10:01:17.446 UTC [616] ERROR: relation "goose_db_version" does not exist at character 368192026-08-27 10:01:17.446 UTC [616] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8202026/08/27 10:01:17 OK 1_commit_pending_closure.sql (6.06ms)8212026/08/27 10:01:17 OK 20251210153512_drop_unused_gin_index.sql (5.49ms)8222026/08/27 10:01:17 OK 20251210153512_drop_unused_gin_index.sql (5.37ms)8232026/08/27 10:01:17 OK 20251210153512_drop_unused_gin_index.sql (5.76ms)8242026/08/27 10:01:17 OK 20251210153512_drop_unused_gin_index.sql (5.8ms)8252026/08/27 10:01:17 OK 2_object_stats_trigger.sql (3.93ms)8262026/08/27 10:01:17 goose: up to current file version: 28272026/08/27 10:01:17 OK 20251218171726_add_pins.sql (4.92ms)8282026/08/27 10:01:17 OK 20251218171726_add_pins.sql (4.77ms)8292026/08/27 10:01:17 OK 20251218171726_add_pins.sql (6.09ms)8302026-08-27 10:01:17.458 UTC [617] ERROR: relation "goose_db_version" does not exist at character 368312026-08-27 10:01:17.458 UTC [617] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8322026/08/27 10:01:17 OK 20241026095416_initial_model.sql (13.25ms)8332026/08/27 10:01:17 OK 20251218171726_add_pins.sql (7.84ms)8342026/08/27 10:01:17 OK 20241026095416_initial_model.sql (15ms)8352026/08/27 10:01:17 OK 20241026095416_initial_model.sql (14.91ms)8362026/08/27 10:01:17 OK 20260628120000_add_object_size_and_stats.sql (6.58ms)8372026/08/27 10:01:17 goose: successfully migrated database to version: 202606281200008382026/08/27 10:01:17 OK 20260628120000_add_object_size_and_stats.sql (6.65ms)8392026/08/27 10:01:17 goose: successfully migrated database to version: 202606281200008402026/08/27 10:01:17 OK 20241026095416_initial_model.sql (15.44ms)8412026/08/27 10:01:17 OK 20251210153512_drop_unused_gin_index.sql (4.07ms)8422026/08/27 10:01:17 OK 20251210153512_drop_unused_gin_index.sql (4.23ms)8432026/08/27 10:01:17 OK 20260628120000_add_object_size_and_stats.sql (7.13ms)8442026/08/27 10:01:17 goose: successfully migrated database to version: 202606281200008452026/08/27 10:01:17 OK 20251210153512_drop_unused_gin_index.sql (4.06ms)8462026/08/27 10:01:17 OK 20260628120000_add_object_size_and_stats.sql (7.48ms)8472026/08/27 10:01:17 OK 20241026095416_initial_model.sql (16.02ms)8482026/08/27 10:01:17 goose: successfully migrated database to version: 202606281200008492026/08/27 10:01:17 OK 20251210153512_drop_unused_gin_index.sql (3.64ms)8502026/08/27 10:01:17 OK 1_commit_pending_closure.sql (4.97ms)8512026/08/27 10:01:17 OK 1_commit_pending_closure.sql (3.15ms)8522026/08/27 10:01:17 OK 20251218171726_add_pins.sql (4.67ms)8532026/08/27 10:01:17 OK 1_commit_pending_closure.sql (4.87ms)8542026/08/27 10:01:17 OK 20251218171726_add_pins.sql (4.77ms)8552026/08/27 10:01:17 OK 20241026095416_initial_model.sql (11.7ms)8562026/08/27 10:01:17 OK 20241026095416_initial_model.sql (14.43ms)8572026/08/27 10:01:17 OK 20241026095416_initial_model.sql (15.11ms)8582026/08/27 10:01:17 OK 20241026095416_initial_model.sql (16.81ms)8592026/08/27 10:01:17 OK 2_object_stats_trigger.sql (3.27ms)8602026/08/27 10:01:17 goose: up to current file version: 28612026/08/27 10:01:17 OK 2_object_stats_trigger.sql (3.32ms)8622026/08/27 10:01:17 goose: up to current file version: 28632026/08/27 10:01:17 OK 2_object_stats_trigger.sql (3.22ms)8642026/08/27 10:01:17 goose: up to current file version: 28652026/08/27 10:01:17 OK 20251210153512_drop_unused_gin_index.sql (4.93ms)8662026/08/27 10:01:17 OK 20251218171726_add_pins.sql (6.44ms)8672026/08/27 10:01:17 OK 1_commit_pending_closure.sql (4.65ms)8682026/08/27 10:01:17 OK 20251210153512_drop_unused_gin_index.sql (3.41ms)8692026/08/27 10:01:17 OK 20251210153512_drop_unused_gin_index.sql (2.87ms)8702026/08/27 10:01:17 OK 20251218171726_add_pins.sql (6.11ms)8712026/08/27 10:01:17 OK 2_object_stats_trigger.sql (2.72ms)8722026/08/27 10:01:17 goose: up to current file version: 28732026/08/27 10:01:17 OK 20260628120000_add_object_size_and_stats.sql (3.57ms)8742026/08/27 10:01:17 goose: successfully migrated database to version: 202606281200008752026/08/27 10:01:17 OK 20260628120000_add_object_size_and_stats.sql (7.27ms)8762026/08/27 10:01:17 goose: successfully migrated database to version: 202606281200008772026/08/27 10:01:17 OK 20260628120000_add_object_size_and_stats.sql (7.22ms)8782026/08/27 10:01:17 goose: successfully migrated database to version: 202606281200008792026/08/27 10:01:17 OK 20251210153512_drop_unused_gin_index.sql (4.26ms)8802026/08/27 10:01:17 OK 20251210153512_drop_unused_gin_index.sql (4.37ms)8812026-08-27 10:01:17.475 UTC [618] ERROR: relation "goose_db_version" does not exist at character 368822026-08-27 10:01:17.475 UTC [618] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8832026/08/27 10:01:17 OK 20251218171726_add_pins.sql (5.02ms)8842026-08-27 10:01:17.477 UTC [619] ERROR: relation "goose_db_version" does not exist at character 368852026-08-27 10:01:17.477 UTC [619] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8862026/08/27 10:01:17 OK 20260628120000_add_object_size_and_stats.sql (4.76ms)8872026/08/27 10:01:17 goose: successfully migrated database to version: 202606281200008882026/08/27 10:01:17 OK 20251218171726_add_pins.sql (5.18ms)8892026/08/27 10:01:17 OK 20251218171726_add_pins.sql (7.53ms)8902026/08/27 10:01:17 OK 1_commit_pending_closure.sql (3.97ms)8912026/08/27 10:01:17 OK 1_commit_pending_closure.sql (4.04ms)8922026/08/27 10:01:17 OK 1_commit_pending_closure.sql (3.89ms)8932026/08/27 10:01:17 OK 20241026095416_initial_model.sql (13.67ms)8942026/08/27 10:01:17 OK 1_commit_pending_closure.sql (3.53ms)8952026/08/27 10:01:17 OK 20251218171726_add_pins.sql (5.93ms)8962026/08/27 10:01:17 OK 20251218171726_add_pins.sql (6.11ms)8972026/08/27 10:01:17 OK 2_object_stats_trigger.sql (2.15ms)8982026/08/27 10:01:17 goose: up to current file version: 28992026/08/27 10:01:17 OK 2_object_stats_trigger.sql (2.09ms)9002026/08/27 10:01:17 goose: up to current file version: 29012026/08/27 10:01:17 OK 20260628120000_add_object_size_and_stats.sql (4.99ms)9022026/08/27 10:01:17 goose: successfully migrated database to version: 202606281200009032026/08/27 10:01:17 OK 2_object_stats_trigger.sql (2.23ms)9042026/08/27 10:01:17 goose: up to current file version: 29052026/08/27 10:01:17 OK 20260628120000_add_object_size_and_stats.sql (3.88ms)9062026/08/27 10:01:17 goose: successfully migrated database to version: 202606281200009072026/08/27 10:01:17 OK 20251210153512_drop_unused_gin_index.sql (1.68ms)9082026/08/27 10:01:17 OK 2_object_stats_trigger.sql (1.04ms)9092026/08/27 10:01:17 goose: up to current file version: 29102026/08/27 10:01:17 OK 20260628120000_add_object_size_and_stats.sql (4.23ms)9112026/08/27 10:01:17 goose: successfully migrated database to version: 202606281200009122026/08/27 10:01:17 OK 1_commit_pending_closure.sql (2.6ms)9132026/08/27 10:01:17 OK 1_commit_pending_closure.sql (3.8ms)9142026/08/27 10:01:17 OK 2_object_stats_trigger.sql (2.16ms)9152026/08/27 10:01:17 goose: up to current file version: 29162026/08/27 10:01:17 OK 1_commit_pending_closure.sql (3.25ms)9172026/08/27 10:01:17 OK 20251218171726_add_pins.sql (4.33ms)9182026/08/27 10:01:17 OK 20260628120000_add_object_size_and_stats.sql (5.29ms)9192026/08/27 10:01:17 goose: successfully migrated database to version: 202606281200009202026/08/27 10:01:17 OK 20260628120000_add_object_size_and_stats.sql (5.22ms)9212026/08/27 10:01:17 goose: successfully migrated database to version: 202606281200009222026/08/27 10:01:17 OK 2_object_stats_trigger.sql (1.08ms)9232026/08/27 10:01:17 goose: up to current file version: 29242026/08/27 10:01:17 INFO Received uploads request method=POST path=/api/pending_closures9252026/08/27 10:01:17 OK 2_object_stats_trigger.sql (2.23ms)9262026/08/27 10:01:17 goose: up to current file version: 29272026/08/27 10:01:17 OK 1_commit_pending_closure.sql (3.28ms)9282026/08/27 10:01:17 OK 1_commit_pending_closure.sql (3.64ms)9292026/08/27 10:01:17 OK 20260628120000_add_object_size_and_stats.sql (4.85ms)9302026/08/27 10:01:17 goose: successfully migrated database to version: 202606281200009312026/08/27 10:01:17 OK 2_object_stats_trigger.sql (1.55ms)9322026/08/27 10:01:17 goose: up to current file version: 29332026/08/27 10:01:17 OK 20241026095416_initial_model.sql (11.54ms)9342026/08/27 10:01:17 OK 1_commit_pending_closure.sql (1.86ms)9352026/08/27 10:01:17 OK 2_object_stats_trigger.sql (2.6ms)9362026/08/27 10:01:17 OK 20241026095416_initial_model.sql (10.96ms)9372026/08/27 10:01:17 goose: up to current file version: 29382026/08/27 10:01:17 OK 2_object_stats_trigger.sql (938.71µs)9392026/08/27 10:01:17 goose: up to current file version: 29402026/08/27 10:01:17 OK 20251210153512_drop_unused_gin_index.sql (1.84ms)9412026/08/27 10:01:17 OK 20251210153512_drop_unused_gin_index.sql (1.59ms)9422026/08/27 10:01:17 OK 20251218171726_add_pins.sql (3.34ms)9432026/08/27 10:01:17 OK 20251218171726_add_pins.sql (3.6ms)9442026/08/27 10:01:17 OK 20260628120000_add_object_size_and_stats.sql (4.45ms)9452026/08/27 10:01:17 goose: successfully migrated database to version: 202606281200009462026/08/27 10:01:17 OK 20260628120000_add_object_size_and_stats.sql (4.53ms)9472026/08/27 10:01:17 goose: successfully migrated database to version: 202606281200009482026/08/27 10:01:17 OK 1_commit_pending_closure.sql (1.67ms)9492026/08/27 10:01:17 OK 1_commit_pending_closure.sql (1.99ms)9502026/08/27 10:01:17 OK 2_object_stats_trigger.sql (708.61µs)9512026/08/27 10:01:17 goose: up to current file version: 29522026/08/27 10:01:17 OK 2_object_stats_trigger.sql (816.33µs)9532026/08/27 10:01:17 goose: up to current file version: 2954--- PASS: TestService_Rustfstest (0.36s)955=== CONT TestParseSingleRange956=== RUN TestParseSingleRange/none957=== PAUSE TestParseSingleRange/none958=== RUN TestParseSingleRange/unknown_unit959=== PAUSE TestParseSingleRange/unknown_unit960=== RUN TestParseSingleRange/multi-range_ignored961=== PAUSE TestParseSingleRange/multi-range_ignored962=== RUN TestParseSingleRange/malformed_no_dash963=== PAUSE TestParseSingleRange/malformed_no_dash964=== RUN TestParseSingleRange/malformed_both_empty965=== PAUSE TestParseSingleRange/malformed_both_empty966=== RUN TestParseSingleRange/malformed_end_before_start967=== PAUSE TestParseSingleRange/malformed_end_before_start968=== RUN TestParseSingleRange/closed969=== PAUSE TestParseSingleRange/closed970=== RUN TestParseSingleRange/open-ended971=== PAUSE TestParseSingleRange/open-ended972=== RUN TestParseSingleRange/end_clamped_to_size973=== PAUSE TestParseSingleRange/end_clamped_to_size974=== RUN TestParseSingleRange/suffix975=== PAUSE TestParseSingleRange/suffix976=== RUN TestParseSingleRange/suffix_exceeds_size977=== PAUSE TestParseSingleRange/suffix_exceeds_size978=== RUN TestParseSingleRange/single_byte979=== PAUSE TestParseSingleRange/single_byte980=== RUN TestParseSingleRange/start_past_EOF981=== PAUSE TestParseSingleRange/start_past_EOF982=== RUN TestParseSingleRange/start_far_past_EOF983=== PAUSE TestParseSingleRange/start_far_past_EOF984=== CONT TestReadProxy4049852026/08/27 10:01:17 INFO Received uploads request method=POST path=/api/pending_closures9862026/08/27 10:01:17 INFO Received uploads request method=POST path=/api/pending_closures9872026/08/27 10:01:17 INFO Received uploads request method=POST path=/api/pending_closures9882026-08-27 10:01:17.592 UTC [623] ERROR: relation "goose_db_version" does not exist at character 369892026-08-27 10:01:17.592 UTC [623] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9902026/08/27 10:01:17 OK 20241026095416_initial_model.sql (8.51ms)9912026/08/27 10:01:17 OK 20251210153512_drop_unused_gin_index.sql (1.34ms)9922026/08/27 10:01:17 OK 20251218171726_add_pins.sql (3.39ms)9932026/08/27 10:01:17 OK 20260628120000_add_object_size_and_stats.sql (3.14ms)9942026/08/27 10:01:17 goose: successfully migrated database to version: 202606281200009952026/08/27 10:01:17 OK 1_commit_pending_closure.sql (1.97ms)9962026/08/27 10:01:17 OK 2_object_stats_trigger.sql (2.47ms)9972026/08/27 10:01:17 goose: up to current file version: 29982026/08/27 10:01:18 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"999--- PASS: TestService_AuthMiddleware (1.09s)1000=== CONT TestResurrectedObjectNotDeleted10012026/08/27 10:01:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10022026/08/27 10:01:18 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1003--- PASS: TestCompleteMultipartUnregistered (1.11s)1004=== CONT TestReadProxyNarinfoAlreadyDecompressed10052026/08/27 10:01:18 INFO Received uploads request method=POST path=/api/pending_closures10062026-08-27 10:01:18.309 UTC [630] ERROR: relation "goose_db_version" does not exist at character 3610072026-08-27 10:01:18.309 UTC [630] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10082026/08/27 10:01:18 INFO Received uploads request method=POST path=/api/pending_closures1009--- PASS: TestReadRedirectNar (1.15s)1010=== CONT TestOrphanedObjectsGCStressTest10112026/08/27 10:01:18 INFO Received uploads request method=POST path=/api/pending_closures10122026/08/27 10:01:18 OK 20241026095416_initial_model.sql (12.79ms)10132026/08/27 10:01:18 OK 20251210153512_drop_unused_gin_index.sql (3.17ms)10142026/08/27 10:01:18 INFO Received uploads request method=POST path=/api/pending_closures10152026/08/27 10:01:18 OK 20251218171726_add_pins.sql (3.43ms)10162026/08/27 10:01:18 OK 20260628120000_add_object_size_and_stats.sql (5.89ms)10172026/08/27 10:01:18 goose: successfully migrated database to version: 2026062812000010182026-08-27 10:01:18.349 UTC [633] ERROR: relation "goose_db_version" does not exist at character 3610192026-08-27 10:01:18.349 UTC [633] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10202026/08/27 10:01:18 OK 1_commit_pending_closure.sql (6.54ms)10212026/08/27 10:01:18 OK 2_object_stats_trigger.sql (2.71ms)10222026/08/27 10:01:18 goose: up to current file version: 210232026/08/27 10:01:18 OK 20241026095416_initial_model.sql (10.32ms)10242026/08/27 10:01:18 OK 20251210153512_drop_unused_gin_index.sql (2.93ms)10252026/08/27 10:01:18 OK 20251218171726_add_pins.sql (5.6ms)10262026/08/27 10:01:18 OK 20260628120000_add_object_size_and_stats.sql (4.86ms)10272026/08/27 10:01:18 goose: successfully migrated database to version: 2026062812000010282026/08/27 10:01:18 OK 1_commit_pending_closure.sql (2.22ms)10292026/08/27 10:01:18 OK 2_object_stats_trigger.sql (1.01ms)10302026/08/27 10:01:18 goose: up to current file version: 210312026-08-27 10:01:18.393 UTC [634] ERROR: relation "goose_db_version" does not exist at character 3610322026-08-27 10:01:18.393 UTC [634] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10332026/08/27 10:01:18 OK 20241026095416_initial_model.sql (9.55ms)10342026/08/27 10:01:18 OK 20251210153512_drop_unused_gin_index.sql (1.26ms)10352026/08/27 10:01:18 OK 20251218171726_add_pins.sql (3.56ms)10362026/08/27 10:01:18 OK 20260628120000_add_object_size_and_stats.sql (3.33ms)10372026/08/27 10:01:18 goose: successfully migrated database to version: 2026062812000010382026/08/27 10:01:18 OK 1_commit_pending_closure.sql (2.3ms)10392026/08/27 10:01:18 OK 2_object_stats_trigger.sql (744.93µs)10402026/08/27 10:01:18 goose: up to current file version: 21041--- PASS: TestGCBugBareHashReferences (1.35s)1042=== CONT TestService_NativeMTLS10432026-08-27 10:01:18.582 UTC [637] ERROR: relation "goose_db_version" does not exist at character 3610442026-08-27 10:01:18.582 UTC [637] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10452026/08/27 10:01:18 OK 20241026095416_initial_model.sql (11.56ms)10462026/08/27 10:01:18 OK 20251210153512_drop_unused_gin_index.sql (1.66ms)10472026/08/27 10:01:18 OK 20251218171726_add_pins.sql (2.93ms)10482026/08/27 10:01:18 OK 20260628120000_add_object_size_and_stats.sql (3.38ms)10492026/08/27 10:01:18 goose: successfully migrated database to version: 2026062812000010502026/08/27 10:01:18 OK 1_commit_pending_closure.sql (1.85ms)10512026/08/27 10:01:18 OK 2_object_stats_trigger.sql (820.57µs)10522026/08/27 10:01:18 goose: up to current file version: 210532026/08/27 10:01:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10542026/08/27 10:01:19 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZWFiZGI2NGQtNTEwMy00MmZiLWExYjEtZDQzYTUwNWE0YTdjLjNjOGZhMWM4LTkxN2MtNGQzYi05ODI3LTBhNjg3Y2NhYjQ4OXgxNzg3ODI0ODc4Mjk2NjY3Nzc3 parts=121055--- PASS: TestRedundantMultipartUpload (2.01s)1056=== CONT TestOrphanedObjectsGC10572026/08/27 10:01:19 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10582026/08/27 10:01:19 INFO Received uploads request method=POST path=/api/pending_closures1059--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.08s)1060=== CONT TestMultipartCleanup10612026/08/27 10:01:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10622026-08-27 10:01:19.247 UTC [663] ERROR: relation "goose_db_version" does not exist at character 3610632026-08-27 10:01:19.247 UTC [663] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10642026/08/27 10:01:19 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZWFiZGI2NGQtNTEwMy00MmZiLWExYjEtZDQzYTUwNWE0YTdjLmQ0MzgwN2U3LWY2ODYtNDNkNC05YjBjLWNiY2Y4M2JjODUzYngxNzg3ODI0ODc3NTM1NDMyNjcw parts=1010652026/08/27 10:01:19 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1066--- PASS: TestReadProxyNarinfo (2.10s)1067=== CONT TestNARDeduplicationMetadataUploadBug10682026/08/27 10:01:19 INFO Completed upload id=110692026/08/27 10:01:19 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010702026/08/27 10:01:19 INFO Received uploads request method=POST path=/api/pending_closures10712026/08/27 10:01:19 INFO Starting cleanup of old closures method=DELETE path=/api/closures10722026/08/27 10:01:19 OK 20241026095416_initial_model.sql (12.87ms)10732026/08/27 10:01:19 INFO Aborted multipart uploads count=010742026/08/27 10:01:19 OK 20251210153512_drop_unused_gin_index.sql (2.95ms)1075--- PASS: TestReadRedirectKeepsNarinfoProxied (2.11s)1076=== CONT TestServerTLSConfig1077=== RUN TestServerTLSConfig/no_client_CA1078=== PAUSE TestServerTLSConfig/no_client_CA1079=== RUN TestServerTLSConfig/missing_CA_file1080=== PAUSE TestServerTLSConfig/missing_CA_file1081=== RUN TestServerTLSConfig/not_a_PEM_file1082=== PAUSE TestServerTLSConfig/not_a_PEM_file1083=== CONT TestMetricsInventory10842026/08/27 10:01:19 OK 20251218171726_add_pins.sql (6.27ms)1085{"timestamp":"2026-08-27T10:01:19.284292814Z","level":"ERROR","message":"Scanner cycle completed without a durable data usage snapshot","event":"scanner_persist_state","component":"scanner","subsystem":"runtime","cycle":5,"outcome":"Current","state":"usage_not_durable","target":"rustfs::scanner","filename":"crates/scanner/src/scanner.rs","line_number":2844,"threadName":"rustfs-worker","threadId":"ThreadId(370)"}10862026/08/27 10:01:19 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=010872026/08/27 10:01:19 OK 20260628120000_add_object_size_and_stats.sql (8.27ms)10882026/08/27 10:01:19 goose: successfully migrated database to version: 2026062812000010892026/08/27 10:01:19 INFO Vacuumed table table=pending_closures10902026/08/27 10:01:19 OK 1_commit_pending_closure.sql (7.86ms)10912026/08/27 10:01:19 INFO Vacuumed table table=pending_objects1092--- PASS: TestReadProxyRangeRequest (2.14s)1093=== CONT TestCreatePendingClosureRejectsOversizedNAR10942026/08/27 10:01:19 INFO Received uploads request method=POST path=/api/pending_closures1095--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1096=== CONT TestReadProxyNarStreaming10972026/08/27 10:01:19 OK 2_object_stats_trigger.sql (7.91ms)10982026/08/27 10:01:19 goose: up to current file version: 210992026/08/27 10:01:19 INFO Vacuumed table table=multipart_uploads11002026/08/27 10:01:19 INFO Vacuumed table table=closures11012026/08/27 10:01:19 INFO Vacuumed table table=objects11022026/08/27 10:01:19 INFO Received uploads request method=POST path=/api/pending_closures11032026-08-27 10:01:19.325 UTC [672] ERROR: relation "goose_db_version" does not exist at character 3611042026-08-27 10:01:19.325 UTC [672] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11052026-08-27 10:01:19.335 UTC [673] ERROR: relation "goose_db_version" does not exist at character 3611062026-08-27 10:01:19.335 UTC [673] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11072026/08/27 10:01:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11082026/08/27 10:01:19 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000011092026/08/27 10:01:19 OK 20241026095416_initial_model.sql (30.84ms)1110--- PASS: TestService_createPendingClosureHandler (2.21s)1111=== CONT TestService_AuthMiddleware_OIDC11122026/08/27 10:01:19 INFO OIDC provider initialized name=test11132026/08/27 10:01:19 OK 20251210153512_drop_unused_gin_index.sql (10.01ms)11142026/08/27 10:01:19 OK 20251218171726_add_pins.sql (4.06ms)11152026-08-27 10:01:19.383 UTC [675] ERROR: relation "goose_db_version" does not exist at character 3611162026-08-27 10:01:19.383 UTC [675] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11172026/08/27 10:01:19 OK 20260628120000_add_object_size_and_stats.sql (4.94ms)11182026/08/27 10:01:19 goose: successfully migrated database to version: 2026062812000011192026/08/27 10:01:19 OK 20241026095416_initial_model.sql (10.71ms)11202026/08/27 10:01:19 OK 1_commit_pending_closure.sql (2.38ms)11212026-08-27 10:01:19.386 UTC [676] ERROR: relation "goose_db_version" does not exist at character 3611222026-08-27 10:01:19.386 UTC [676] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11232026/08/27 10:01:19 OK 2_object_stats_trigger.sql (873.53µs)11242026/08/27 10:01:19 goose: up to current file version: 211252026/08/27 10:01:19 OK 20251210153512_drop_unused_gin_index.sql (1.48ms)11262026/08/27 10:01:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11272026/08/27 10:01:19 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZWFiZGI2NGQtNTEwMy00MmZiLWExYjEtZDQzYTUwNWE0YTdjLmNjYzA1Yjc3LWJjMTUtNGI3Yy04ZWIyLTg1YWY3NWFkMmU0NHgxNzg3ODI0ODc5MzMyOTY5NTc111282026/08/27 10:01:19 OK 20251218171726_add_pins.sql (6.56ms)11292026/08/27 10:01:19 OK 20241026095416_initial_model.sql (9.39ms)11302026/08/27 10:01:19 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZWFiZGI2NGQtNTEwMy00MmZiLWExYjEtZDQzYTUwNWE0YTdjLmNjYzA1Yjc3LWJjMTUtNGI3Yy04ZWIyLTg1YWY3NWFkMmU0NHgxNzg3ODI0ODc5MzMyOTY5NTc1 parts=11131--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.24s)1132=== CONT TestCacheStatsHandler11332026/08/27 10:01:19 OK 20260628120000_add_object_size_and_stats.sql (6.49ms)11342026/08/27 10:01:19 goose: successfully migrated database to version: 2026062812000011352026/08/27 10:01:19 OK 20251210153512_drop_unused_gin_index.sql (4.1ms)11362026/08/27 10:01:19 OK 20241026095416_initial_model.sql (9.51ms)11372026/08/27 10:01:19 OK 1_commit_pending_closure.sql (3.72ms)11382026/08/27 10:01:19 OK 20251218171726_add_pins.sql (4.38ms)11392026/08/27 10:01:19 OK 20251210153512_drop_unused_gin_index.sql (3.24ms)11402026/08/27 10:01:19 OK 2_object_stats_trigger.sql (2.57ms)11412026/08/27 10:01:19 goose: up to current file version: 211422026/08/27 10:01:19 OK 20251218171726_add_pins.sql (3.52ms)11432026/08/27 10:01:19 OK 20260628120000_add_object_size_and_stats.sql (4.22ms)11442026/08/27 10:01:19 goose: successfully migrated database to version: 2026062812000011452026/08/27 10:01:19 OK 1_commit_pending_closure.sql (3.11ms)11462026/08/27 10:01:19 OK 20260628120000_add_object_size_and_stats.sql (4.56ms)11472026/08/27 10:01:19 goose: successfully migrated database to version: 2026062812000011482026/08/27 10:01:19 OK 2_object_stats_trigger.sql (2.02ms)11492026/08/27 10:01:19 goose: up to current file version: 211502026/08/27 10:01:19 OK 1_commit_pending_closure.sql (2.76ms)11512026/08/27 10:01:19 OK 2_object_stats_trigger.sql (2.23ms)11522026/08/27 10:01:19 goose: up to current file version: 211532026/08/27 10:01:19 INFO Received cleanup request method=DELETE path=/api/pending_closures11542026/08/27 10:01:19 INFO Aborted multipart uploads count=011552026/08/27 10:01:19 INFO Received uploads request method=POST path=/api/pending_closures11562026/08/27 10:01:19 INFO Received cleanup request method=DELETE path=/api/pending_closures11572026/08/27 10:01:19 INFO Aborted multipart uploads count=111582026-08-27 10:01:19.446 UTC [680] ERROR: relation "goose_db_version" does not exist at character 3611592026-08-27 10:01:19.446 UTC [680] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11602026/08/27 10:01:19 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1161--- PASS: TestReadProxyConditionalGet (2.23s)1162=== CONT TestClientCADerivations11632026-08-27 10:01:19.449 UTC [609] ERROR: Closure does not exist: id=111642026-08-27 10:01:19.449 UTC [609] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE11652026-08-27 10:01:19.449 UTC [609] STATEMENT: -- name: CommitPendingClosure :exec1166 SELECT commit_pending_closure($1::bigint)1167 1168--- PASS: TestService_cleanupPendingClosuresHandler (2.29s)1169=== CONT TestService_AuthMiddleware_MTLSBoundSubjects11702026/08/27 10:01:19 OK 20241026095416_initial_model.sql (10.09ms)11712026/08/27 10:01:19 OK 20251210153512_drop_unused_gin_index.sql (2.55ms)1172--- PASS: TestService_healthCheckHandler (2.31s)1173=== CONT TestCacheConfigHandler1174=== RUN TestCacheConfigHandler/full_config,_no_issuer1175=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1176=== RUN TestCacheConfigHandler/no_cache_url_configured1177=== PAUSE TestCacheConfigHandler/no_cache_url_configured1178=== RUN TestCacheConfigHandler/no_signing_keys1179=== PAUSE TestCacheConfigHandler/no_signing_keys1180=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1181=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1182=== CONT TestPinProtectsFromGC11832026/08/27 10:01:19 OK 20251218171726_add_pins.sql (3.52ms)11842026/08/27 10:01:19 OK 20260628120000_add_object_size_and_stats.sql (6.5ms)11852026/08/27 10:01:19 goose: successfully migrated database to version: 2026062812000011862026-08-27 10:01:19.480 UTC [686] ERROR: relation "goose_db_version" does not exist at character 3611872026-08-27 10:01:19.480 UTC [686] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11882026/08/27 10:01:19 OK 1_commit_pending_closure.sql (3.61ms)11892026/08/27 10:01:19 OK 2_object_stats_trigger.sql (3.76ms)11902026/08/27 10:01:19 goose: up to current file version: 21191--- PASS: TestObjectStatsTrigger (2.26s)1192=== CONT TestService_ReadAuthMiddleware11932026/08/27 10:01:19 OK 20241026095416_initial_model.sql (10.95ms)11942026/08/27 10:01:19 OK 20251210153512_drop_unused_gin_index.sql (8.84ms)11952026/08/27 10:01:19 OK 20251218171726_add_pins.sql (5.28ms)11962026/08/27 10:01:19 OK 20260628120000_add_object_size_and_stats.sql (4.54ms)11972026/08/27 10:01:19 goose: successfully migrated database to version: 2026062812000011982026/08/27 10:01:19 OK 1_commit_pending_closure.sql (3.34ms)11992026/08/27 10:01:19 OK 2_object_stats_trigger.sql (2ms)12002026/08/27 10:01:19 goose: up to current file version: 212012026-08-27 10:01:19.541 UTC [690] ERROR: relation "goose_db_version" does not exist at character 3612022026-08-27 10:01:19.541 UTC [690] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12032026-08-27 10:01:19.541 UTC [691] ERROR: relation "goose_db_version" does not exist at character 3612042026-08-27 10:01:19.541 UTC [691] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12052026-08-27 10:01:19.547 UTC [692] ERROR: relation "goose_db_version" does not exist at character 3612062026-08-27 10:01:19.547 UTC [692] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12072026/08/27 10:01:19 OK 20241026095416_initial_model.sql (9.89ms)12082026-08-27 10:01:19.561 UTC [693] ERROR: relation "goose_db_version" does not exist at character 3612092026-08-27 10:01:19.561 UTC [693] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12102026/08/27 10:01:19 OK 20251210153512_drop_unused_gin_index.sql (2.79ms)12112026/08/27 10:01:19 OK 20241026095416_initial_model.sql (12.44ms)12122026/08/27 10:01:19 OK 20241026095416_initial_model.sql (8.5ms)12132026/08/27 10:01:19 OK 20251210153512_drop_unused_gin_index.sql (2.01ms)12142026/08/27 10:01:19 OK 20251218171726_add_pins.sql (3.01ms)12152026/08/27 10:01:19 OK 20251210153512_drop_unused_gin_index.sql (2.45ms)12162026/08/27 10:01:19 OK 20251218171726_add_pins.sql (3.59ms)12172026/08/27 10:01:19 OK 20251218171726_add_pins.sql (4.51ms)12182026/08/27 10:01:19 OK 20260628120000_add_object_size_and_stats.sql (4.45ms)12192026/08/27 10:01:19 goose: successfully migrated database to version: 2026062812000012202026/08/27 10:01:19 OK 20260628120000_add_object_size_and_stats.sql (3.32ms)12212026/08/27 10:01:19 goose: successfully migrated database to version: 2026062812000012222026/08/27 10:01:19 OK 1_commit_pending_closure.sql (2.89ms)12232026/08/27 10:01:19 OK 20260628120000_add_object_size_and_stats.sql (3.3ms)12242026/08/27 10:01:19 goose: successfully migrated database to version: 2026062812000012252026/08/27 10:01:19 OK 2_object_stats_trigger.sql (985.27µs)12262026/08/27 10:01:19 goose: up to current file version: 212272026/08/27 10:01:19 OK 1_commit_pending_closure.sql (1.79ms)12282026/08/27 10:01:19 OK 1_commit_pending_closure.sql (1.77ms)12292026/08/27 10:01:19 OK 2_object_stats_trigger.sql (832.31µs)12302026/08/27 10:01:19 goose: up to current file version: 212312026/08/27 10:01:19 OK 20241026095416_initial_model.sql (8.99ms)12322026/08/27 10:01:19 OK 2_object_stats_trigger.sql (736.19µs)12332026/08/27 10:01:19 goose: up to current file version: 212342026/08/27 10:01:19 OK 20251210153512_drop_unused_gin_index.sql (1.18ms)12352026/08/27 10:01:19 OK 20251218171726_add_pins.sql (3.07ms)12362026/08/27 10:01:19 OK 20260628120000_add_object_size_and_stats.sql (2.54ms)12372026/08/27 10:01:19 goose: successfully migrated database to version: 2026062812000012382026/08/27 10:01:19 OK 1_commit_pending_closure.sql (1.91ms)12392026/08/27 10:01:19 OK 2_object_stats_trigger.sql (797.79µs)12402026/08/27 10:01:19 goose: up to current file version: 21241--- PASS: TestReadProxyDisabled (3.09s)1242=== CONT TestClientWithDependencies1243{"timestamp":"2026-08-27T10:01:20.252041831Z","level":"ERROR","message":"Scanner cycle completed without a durable data usage snapshot","event":"scanner_persist_state","component":"scanner","subsystem":"runtime","cycle":6,"outcome":"Current","state":"usage_not_durable","target":"rustfs::scanner","filename":"crates/scanner/src/scanner.rs","line_number":2844,"threadName":"rustfs-worker","threadId":"ThreadId(366)"}1244--- PASS: TestReadProxyRootRedirectsToIndexHTML (3.05s)1245=== CONT TestService_AuthMiddleware_MTLSProxyHeader12462026/08/27 10:01:20 INFO Received uploads request method=POST path=/api/pending_closures12472026/08/27 10:01:20 INFO Aborted multipart uploads count=012482026/08/27 10:01:20 WARN Force mode enabled - objects will be deleted immediately without grace period12492026/08/27 10:01:20 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=012502026/08/27 10:01:20 INFO Vacuumed table table=pending_closures12512026/08/27 10:01:20 INFO Vacuumed table table=pending_objects1252--- PASS: TestReadProxyInvalidPath (3.01s)1253=== CONT TestClientErrorHandling1254=== RUN TestClientErrorHandling/InvalidStorePath1255=== PAUSE TestClientErrorHandling/InvalidStorePath1256=== RUN TestClientErrorHandling/InvalidAuthToken12572026/08/27 10:01:20 INFO Vacuumed table table=multipart_uploads1258=== PAUSE TestClientErrorHandling/InvalidAuthToken1259=== RUN TestClientErrorHandling/ServerNotAvailable1260=== PAUSE TestClientErrorHandling/ServerNotAvailable1261=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT12622026/08/27 10:01:20 INFO Vacuumed table table=closures12632026/08/27 10:01:20 INFO Vacuumed table table=objects12642026-08-27 10:01:20.315 UTC [699] ERROR: relation "goose_db_version" does not exist at character 3612652026-08-27 10:01:20.315 UTC [699] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1266--- PASS: TestGCMetrics (3.10s)1267=== CONT TestClientMultipleUploads1268--- PASS: TestReadProxyHead (3.05s)1269=== CONT TestClientIntegration12702026/08/27 10:01:20 OK 20241026095416_initial_model.sql (14.39ms)12712026/08/27 10:01:20 OK 20251210153512_drop_unused_gin_index.sql (3.31ms)12722026-08-27 10:01:20.346 UTC [705] ERROR: relation "goose_db_version" does not exist at character 3612732026-08-27 10:01:20.346 UTC [705] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1274--- PASS: TestReadProxy404 (2.83s)1275=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info12762026/08/27 10:01:20 INFO Received uploads request method=POST path=/1277=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key12782026/08/27 10:01:20 OK 20251218171726_add_pins.sql (5.14ms)12792026/08/27 10:01:20 INFO Received request for more parts method=POST path=/1280=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key12812026/08/27 10:01:20 INFO Received complete multipart upload request method=POST path=/1282=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal12832026/08/27 10:01:20 INFO Received uploads request method=POST path=/1284--- PASS: TestUploadHandlersRejectInvalidKeys (0.06s)1285 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1286 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1287 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1288 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1289=== CONT TestProxyWriteTimeout/narinfo1290=== CONT TestProxyWriteTimeout/unknown_size1291=== CONT TestProxyWriteTimeout/10_GiB_nar1292=== CONT TestProxyWriteTimeout/1_GiB_nar1293=== CONT TestIsValidUploadKey/narinfo1294=== CONT TestIsValidUploadKey/empty_key1295=== CONT TestIsValidUploadKey/absolute1296=== CONT TestIsValidUploadKey/unknown_type1297--- PASS: TestProxyWriteTimeout (0.06s)1298 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1299 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1300 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1301 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1302=== CONT TestIsValidUploadKey/traversal_nar1303=== CONT TestIsValidUploadKey/traversal1304=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1305=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1306=== CONT TestIsValidUploadKey/build_log_plus_in_name1307=== CONT TestIsValidUploadKey/build_log_home-manager_file1308=== CONT TestIsValidUploadKey/build_log1309=== CONT TestIsValidUploadKey/listing1310=== CONT TestIsValidUploadKey/nar_plain1311=== CONT TestIsValidUploadKey/build_log_question_mark1312=== CONT TestIsValidUploadKey/nar_xz1313=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1314=== CONT TestIsValidUploadKey/nar_zst1315=== CONT TestIsValidUploadKey/index.html1316=== CONT TestIsValidUploadKey/nix-cache-info1317=== CONT TestIsValidUploadKey/realisation1318=== CONT TestIsValidUploadKey/build_log_equals1319=== CONT TestIsValidUploadKey/realisation_plus_in_output1320--- PASS: TestIsValidUploadKey (0.06s)1321 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1322 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1323 --- PASS: TestIsValidUploadKey/absolute (0.00s)1324 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1325 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1326 --- PASS: TestIsValidUploadKey/traversal (0.00s)1327 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1328 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1329 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1330 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1331 --- PASS: TestIsValidUploadKey/build_log (0.00s)1332 --- PASS: TestIsValidUploadKey/listing (0.00s)1333 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1334 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1335 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1336 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1337 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1338 --- PASS: TestIsValidUploadKey/index.html (0.00s)1339 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1340 --- PASS: TestIsValidUploadKey/realisation (0.00s)1341 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1342 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1343=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure13442026/08/27 10:01:20 INFO Received uploads request method=POST path=/13452026/08/27 10:01:20 OK 20260628120000_add_object_size_and_stats.sql (5.94ms)13462026/08/27 10:01:20 goose: successfully migrated database to version: 2026062812000013472026/08/27 10:01:20 OK 1_commit_pending_closure.sql (4.73ms)13482026/08/27 10:01:20 OK 2_object_stats_trigger.sql (4.79ms)13492026/08/27 10:01:20 goose: up to current file version: 213502026/08/27 10:01:20 OK 20241026095416_initial_model.sql (12.79ms)13512026/08/27 10:01:20 OK 20251210153512_drop_unused_gin_index.sql (3.15ms)13522026/08/27 10:01:20 OK 20251218171726_add_pins.sql (4.91ms)13532026/08/27 10:01:20 OK 20260628120000_add_object_size_and_stats.sql (4.76ms)13542026/08/27 10:01:20 goose: successfully migrated database to version: 2026062812000013552026/08/27 10:01:20 OK 1_commit_pending_closure.sql (2.98ms)1356--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.13s)1357=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts13582026/08/27 10:01:20 INFO Received request for more parts method=POST path=/13592026-08-27 10:01:20.388 UTC [707] ERROR: relation "goose_db_version" does not exist at character 3613602026-08-27 10:01:20.388 UTC [707] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13612026/08/27 10:01:20 OK 2_object_stats_trigger.sql (10.3ms)13622026/08/27 10:01:20 goose: up to current file version: 213632026-08-27 10:01:20.403 UTC [708] ERROR: relation "goose_db_version" does not exist at character 3613642026-08-27 10:01:20.403 UTC [708] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13652026/08/27 10:01:20 OK 20241026095416_initial_model.sql (14.19ms)13662026/08/27 10:01:20 OK 20251210153512_drop_unused_gin_index.sql (2.08ms)13672026/08/27 10:01:20 OK 20251218171726_add_pins.sql (4.34ms)13682026/08/27 10:01:20 OK 20241026095416_initial_model.sql (8.82ms)13692026-08-27 10:01:20.423 UTC [709] ERROR: relation "goose_db_version" does not exist at character 3613702026-08-27 10:01:20.423 UTC [709] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13712026/08/27 10:01:20 OK 20260628120000_add_object_size_and_stats.sql (4.13ms)13722026/08/27 10:01:20 goose: successfully migrated database to version: 2026062812000013732026/08/27 10:01:20 OK 20251210153512_drop_unused_gin_index.sql (2.5ms)13742026/08/27 10:01:20 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13752026/08/27 10:01:20 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1376--- PASS: TestService_NativeMTLS (1.91s)1377=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart13782026/08/27 10:01:20 INFO Received complete multipart upload request method=POST path=/13792026/08/27 10:01:20 OK 1_commit_pending_closure.sql (3.13ms)13802026/08/27 10:01:20 OK 2_object_stats_trigger.sql (1.55ms)13812026/08/27 10:01:20 goose: up to current file version: 213822026/08/27 10:01:20 OK 20251218171726_add_pins.sql (3.91ms)13832026/08/27 10:01:20 OK 20260628120000_add_object_size_and_stats.sql (4.57ms)13842026/08/27 10:01:20 goose: successfully migrated database to version: 202606281200001385--- PASS: TestResurrectedObjectNotDeleted (2.19s)1386=== CONT TestIsValidCachePath/narinfo1387=== CONT TestIsValidCachePath/index.html1388=== CONT TestIsValidCachePath/short_hash1389=== CONT TestIsValidCachePath/wrong_extension13902026/08/27 10:01:20 OK 1_commit_pending_closure.sql (3.25ms)1391=== CONT TestIsValidCachePath/leading_slash1392=== CONT TestIsValidCachePath/empty1393=== CONT TestIsValidCachePath/random_path1394=== CONT TestIsValidCachePath/invalid_char_u1395=== CONT TestIsValidCachePath/invalid_char_e1396=== CONT TestIsValidCachePath/traversal_in_middle1397=== CONT TestIsValidCachePath/nar_uncompressed1398=== CONT TestIsValidCachePath/traversal_parent1399=== CONT TestIsValidCachePath/nix-cache-info1400=== CONT TestIsValidCachePath/log1401=== CONT TestIsValidCachePath/ls1402=== CONT TestIsValidCachePath/realisation1403=== CONT TestIsValidCachePath/nar_xz1404=== CONT TestIsValidCachePath/nar_zst1405=== CONT TestIsValidCachePath/nar_bz21406=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1407--- PASS: TestIsValidCachePath (0.00s)1408 --- PASS: TestIsValidCachePath/narinfo (0.00s)1409 --- PASS: TestIsValidCachePath/index.html (0.00s)1410 --- PASS: TestIsValidCachePath/short_hash (0.00s)1411 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1412 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1413 --- PASS: TestIsValidCachePath/empty (0.00s)1414 --- PASS: TestIsValidCachePath/random_path (0.00s)1415 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1416 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1417 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1418 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1419 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1420 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1421 --- PASS: TestIsValidCachePath/log (0.00s)1422 --- PASS: TestIsValidCachePath/ls (0.00s)1423 --- PASS: TestIsValidCachePath/realisation (0.00s)1424 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1425 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1426 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1427 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1428=== CONT TestParseSingleRange/none1429=== CONT TestParseSingleRange/single_byte1430=== CONT TestParseSingleRange/suffix_exceeds_size1431=== CONT TestParseSingleRange/suffix1432=== CONT TestParseSingleRange/end_clamped_to_size1433=== CONT TestParseSingleRange/open-ended1434=== CONT TestParseSingleRange/closed1435=== CONT TestParseSingleRange/malformed_end_before_start1436=== CONT TestParseSingleRange/start_past_EOF1437=== CONT TestParseSingleRange/malformed_both_empty1438=== CONT TestParseSingleRange/malformed_no_dash1439=== CONT TestParseSingleRange/multi-range_ignored1440=== CONT TestParseSingleRange/unknown_unit1441=== CONT TestParseSingleRange/start_far_past_EOF1442--- PASS: TestParseSingleRange (0.00s)1443 --- PASS: TestParseSingleRange/none (0.00s)1444 --- PASS: TestParseSingleRange/single_byte (0.00s)1445 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1446 --- PASS: TestParseSingleRange/suffix (0.00s)1447 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1448 --- PASS: TestParseSingleRange/open-ended (0.00s)1449 --- PASS: TestParseSingleRange/closed (0.00s)1450 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1451 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1452 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1453 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1454 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1455 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1456 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1457=== CONT TestServerTLSConfig/no_client_CA1458=== CONT TestServerTLSConfig/not_a_PEM_file14592026/08/27 10:01:20 OK 2_object_stats_trigger.sql (1.27ms)14602026/08/27 10:01:20 goose: up to current file version: 21461=== CONT TestServerTLSConfig/missing_CA_file1462--- PASS: TestServerTLSConfig (0.00s)1463 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1464 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1465 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1466=== CONT TestCacheConfigHandler/full_config,_no_issuer1467=== CONT TestCacheConfigHandler/no_signing_keys1468=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1469=== CONT TestCacheConfigHandler/no_cache_url_configured1470=== CONT TestClientErrorHandling/InvalidStorePath1471--- PASS: TestCacheConfigHandler (0.00s)1472 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1473 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1474 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1475 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)14762026/08/27 10:01:20 OK 20241026095416_initial_model.sql (12.23ms)14772026/08/27 10:01:20 OK 20251210153512_drop_unused_gin_index.sql (2.31ms)14782026/08/27 10:01:20 OK 20251218171726_add_pins.sql (2.78ms)14792026/08/27 10:01:20 OK 20260628120000_add_object_size_and_stats.sql (3.64ms)14802026/08/27 10:01:20 goose: successfully migrated database to version: 2026062812000014812026/08/27 10:01:20 OK 1_commit_pending_closure.sql (2.38ms)14822026/08/27 10:01:20 OK 2_object_stats_trigger.sql (820.19µs)14832026/08/27 10:01:20 goose: up to current file version: 214842026/08/27 10:01:20 INFO Received uploads request method=POST path=/api/pending_closures1485=== CONT TestClientErrorHandling/InvalidAuthToken1486=== CONT TestClientErrorHandling/ServerNotAvailable14872026-08-27 10:01:20.525 UTC [716] ERROR: relation "goose_db_version" does not exist at character 3614882026-08-27 10:01:20.525 UTC [716] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1489--- PASS: TestMetricsInventory (1.26s)1490=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1491=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1492=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1493=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1494=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1495=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1496=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1497=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1498=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1499=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1500=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected15012026/08/27 10:01:20 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]1502=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected15032026/08/27 10:01:20 WARN Authentication failed token_preview=eyJhbGciOi...dl8GNHPKCA 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]15042026/08/27 10:01:20 INFO OIDC auth successful provider=test1505=== NAME TestNARDeduplicationMetadataUploadBug1506 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1404843166/001/store/k8l3x873ds7m1j0p1f706qzfn849lgcg-file1.txt1507--- PASS: TestService_AuthMiddleware_OIDC (1.17s)1508 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1509 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1510 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)1511 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)15122026/08/27 10:01:20 OK 20241026095416_initial_model.sql (15.09ms)15132026/08/27 10:01:20 OK 20251210153512_drop_unused_gin_index.sql (3.59ms)15142026/08/27 10:01:20 OK 20251218171726_add_pins.sql (8.7ms)1515--- PASS: TestReadProxyNarStreaming (1.26s)15162026/08/27 10:01:20 OK 20260628120000_add_object_size_and_stats.sql (4.61ms)15172026/08/27 10:01:20 goose: successfully migrated database to version: 202606281200001518--- PASS: TestCacheStatsHandler (1.17s)15192026/08/27 10:01:20 OK 1_commit_pending_closure.sql (2.39ms)15202026/08/27 10:01:20 OK 2_object_stats_trigger.sql (1.42ms)15212026/08/27 10:01:20 goose: up to current file version: 215222026/08/27 10:01:20 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15232026/08/27 10:01:20 WARN mTLS auth: bound subjects configured but subject DN unavailable15242026/08/27 10:01:20 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1525--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.12s)15262026/08/27 10:01:20 INFO Received cleanup request method=DELETE path=/api/pending_closures15272026-08-27 10:01:20.578 UTC [751] ERROR: relation "goose_db_version" does not exist at character 3615282026-08-27 10:01:20.578 UTC [751] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15292026/08/27 10:01:20 INFO Aborted multipart uploads count=11530--- PASS: TestMultipartCleanup (1.35s)15312026/08/27 10:01:20 OK 20241026095416_initial_model.sql (11.92ms)15322026/08/27 10:01:20 OK 20251210153512_drop_unused_gin_index.sql (1.44ms)15332026/08/27 10:01:20 OK 20251218171726_add_pins.sql (3.78ms)15342026/08/27 10:01:20 OK 20260628120000_add_object_size_and_stats.sql (2.86ms)15352026/08/27 10:01:20 goose: successfully migrated database to version: 2026062812000015362026/08/27 10:01:20 OK 1_commit_pending_closure.sql (1.79ms)15372026/08/27 10:01:20 OK 2_object_stats_trigger.sql (888.55µs)15382026/08/27 10:01:20 goose: up to current file version: 215392026/08/27 10:01:20 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1540--- PASS: TestService_ReadAuthMiddleware (1.13s)15412026/08/27 10:01:20 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15422026/08/27 10:01:20 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-config1543--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.38s)15442026/08/27 10:01:20 INFO Received uploads request method=POST path=/api/pending_closures15452026/08/27 10:01:20 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15462026/08/27 10:01:20 INFO Uploading k8l3x873ds7m1j0p1f706qzfn849lgcg-file1.txt (160B)1547=== NAME TestPinProtectsFromGC1548 client_integration_test.go:646: Pinned store path: /build/TestPinProtectsFromGC1888749677/001/store/80qhqs5d4kib99mhxp53ddznp115g0rf-pinned-file.txt1549 client_integration_test.go:647: Unpinned store path: /build/TestPinProtectsFromGC1888749677/001/store/d2py178a28zdhmh4yrg00aciyywx44sb-unpinned-file.txt15502026/08/27 10:01:20 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"15512026/08/27 10:01:20 INFO Received uploads request method=POST path=/api/pending_closures15522026/08/27 10:01:20 WARN Failed to register uploaded object key=k8l3x873ds7m1j0p1f706qzfn849lgcg.ls error="server returned 404: 404 page not found\n"15532026/08/27 10:01:20 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15542026/08/27 10:01:20 INFO Signed narinfos id=1 count=115552026/08/27 10:01:20 INFO Uploading 1 narinfos15562026/08/27 10:01:20 WARN Failed to register uploaded object key=k8l3x873ds7m1j0p1f706qzfn849lgcg.narinfo error="server returned 404: 404 page not found\n"15572026/08/27 10:01:20 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1558--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.38s)1559=== NAME TestClientCADerivations1560 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3835220385/001/store/cp781syrvzmal184g1xxp1nddi44b8iz-ca-test15612026/08/27 10:01:20 INFO Completed upload id=115622026/08/27 10:01:20 INFO Upload complete. (106ms)1563=== NAME TestNARDeduplicationMetadataUploadBug1564 metadata_upload_test.go:54: Retrieved narinfo from S3:1565 StorePath: /build/TestNARDeduplicationMetadataUploadBug1404843166/001/store/k8l3x873ds7m1j0p1f706qzfn849lgcg-file1.txt1566 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1567 Compression: zstd1568 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1569 NarSize: 1601570 References: 1571 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1572 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1573 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1574 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1575=== NAME TestClientMultipleUploads1576 client_integration_test.go:338: Created store path 0: /build/TestClientMultipleUploads889264985/001/store/sh8i82x2ap7ilxs0h9ynw5a71m09rd85-test-file-0.txt1577=== NAME TestClientWithDependencies1578 client_integration_test.go:593: Built derivation: /build/TestClientWithDependencies4221329864/001/store/hz9kwngypmvg59ax6b18gbf7c6gk2f99-test-script1579=== NAME TestClientCADerivations1580 client_ca_test.go:139: Found 1 dependencies (including self)1581=== NAME TestNARDeduplicationMetadataUploadBug1582 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1404843166/001/store/mz0rcihp5bl9w8gjf3mj7c5l35417kc3-file2.txt15832026/08/27 10:01:20 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1584=== NAME TestClientIntegration1585 client_integration_test.go:276: Created store path: /build/TestClientIntegration1531670951/002/store/jxxhjlk39s7vygrks3qcbrjma1hy0r3y-test-file.txt1586=== NAME TestClientWithDependencies1587 client_integration_test.go:595: Found 1 dependencies (including self)1588=== NAME TestClientMultipleUploads1589 client_integration_test.go:338: Created store path 1: /build/TestClientMultipleUploads889264985/001/store/bdfqa53gkv60x4glvzrmd8is6n0vlb36-test-file-1.txt15902026/08/27 10:01:20 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=201.733038ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1591=== NAME TestOrphanedObjectsGC1592 orphaned_objects_gc_test.go:290: GC Test Summary:1593 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1594 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1595 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1596 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1597 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1598--- PASS: TestOrphanedObjectsGC (1.58s)15992026/08/27 10:01:20 INFO Received uploads request method=POST path=/api/pending_closures1600=== NAME TestClientMultipleUploads1601 client_integration_test.go:338: Created store path 2: /build/TestClientMultipleUploads889264985/001/store/5d7qk1ka6fhlsjbrlig05phr65l6dbhi-test-file-2.txt16022026/08/27 10:01:20 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16032026/08/27 10:01:20 INFO Uploading 80qhqs5d4kib99mhxp53ddznp115g0rf-pinned-file.txt (128B)16042026/08/27 10:01:20 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16052026/08/27 10:01:20 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16062026/08/27 10:01:20 INFO Received uploads request method=POST path=/api/pending_closures16072026/08/27 10:01:20 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16082026/08/27 10:01:20 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16092026/08/27 10:01:20 INFO Uploading hz9kwngypmvg59ax6b18gbf7c6gk2f99-test-script (136B)16102026/08/27 10:01:20 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16112026/08/27 10:01:20 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16122026/08/27 10:01:20 INFO Received uploads request method=POST path=/api/pending_closures16132026/08/27 10:01:20 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16142026/08/27 10:01:20 INFO Uploading cp781syrvzmal184g1xxp1nddi44b8iz-ca-test (144B)16152026/08/27 10:01:20 INFO Received uploads request method=POST path=/api/pending_closures16162026/08/27 10:01:20 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16172026/08/27 10:01:20 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"16182026/08/27 10:01:20 INFO Received uploads request method=POST path=/api/pending_closures16192026/08/27 10:01:20 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16202026/08/27 10:01:20 INFO Uploading jxxhjlk39s7vygrks3qcbrjma1hy0r3y-test-file.txt (152B)16212026/08/27 10:01:20 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16222026/08/27 10:01:20 INFO Received uploads request method=POST path=/api/pending_closures16232026/08/27 10:01:20 INFO Received uploads request method=POST path=/api/pending_closures16242026/08/27 10:01:20 INFO Received uploads request method=POST path=/api/pending_closures16252026/08/27 10:01:20 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)16262026/08/27 10:01:20 INFO Uploading 5d7qk1ka6fhlsjbrlig05phr65l6dbhi-test-file-2.txt (160B)16272026/08/27 10:01:20 INFO Uploading bdfqa53gkv60x4glvzrmd8is6n0vlb36-test-file-1.txt (160B)16282026/08/27 10:01:20 INFO Uploading sh8i82x2ap7ilxs0h9ynw5a71m09rd85-test-file-0.txt (160B)16292026/08/27 10:01:20 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=395.212053ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config16302026/08/27 10:01:21 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=754.351025ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1631--- PASS: TestUploadHandlersRejectOversizedBody (0.14s)1632 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.09s)1633 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.09s)1634 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.48s)16352026/08/27 10:01:21 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"16362026/08/27 10:01:21 WARN Failed to register uploaded object key=80qhqs5d4kib99mhxp53ddznp115g0rf.ls error="server returned 404: 404 page not found\n"16372026/08/27 10:01:21 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16382026/08/27 10:01:21 INFO Signed narinfos id=1 count=116392026/08/27 10:01:21 INFO Uploading 1 narinfos16402026/08/27 10:01:21 WARN Failed to register uploaded object key=80qhqs5d4kib99mhxp53ddznp115g0rf.narinfo error="server returned 404: 404 page not found\n"16412026/08/27 10:01:21 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16422026/08/27 10:01:22 INFO Completed upload id=116432026/08/27 10:01:22 INFO Upload complete. (1.304s)16442026/08/27 10:01:22 WARN Failed to register uploaded object key=log/ssdfwin6r4p1f2m1c1h3ziim824ak8fd-ca-test.drv error="server returned 404: 404 page not found\n"16452026/08/27 10:01:22 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"16462026/08/27 10:01:22 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"16472026/08/27 10:01:22 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"16482026/08/27 10:01:22 WARN Failed to register uploaded object key=log/p8fx06gw04bjl2apicmh51l1vijdfn1z-test-script.drv error="server returned 404: 404 page not found\n"16492026/08/27 10:01:22 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16502026/08/27 10:01:22 WARN Failed to register uploaded object key=mz0rcihp5bl9w8gjf3mj7c5l35417kc3.ls error="server returned 404: 404 page not found\n"16512026/08/27 10:01:22 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"16522026/08/27 10:01:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16532026/08/27 10:01:22 INFO Signed narinfos id=2 count=116542026/08/27 10:01:22 INFO Uploading 1 narinfos16552026/08/27 10:01:22 WARN Failed to register uploaded object key=sh8i82x2ap7ilxs0h9ynw5a71m09rd85.ls error="server returned 404: 404 page not found\n"16562026/08/27 10:01:22 WARN Failed to register uploaded object key=bdfqa53gkv60x4glvzrmd8is6n0vlb36.ls error="server returned 404: 404 page not found\n"16572026/08/27 10:01:22 WARN Failed to register uploaded object key=5d7qk1ka6fhlsjbrlig05phr65l6dbhi.ls error="server returned 404: 404 page not found\n"16582026/08/27 10:01:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign16592026/08/27 10:01:22 INFO Signed narinfos id=3 count=116602026/08/27 10:01:22 WARN Failed to register uploaded object key=hz9kwngypmvg59ax6b18gbf7c6gk2f99.ls error="server returned 404: 404 page not found\n"16612026/08/27 10:01:22 WARN Failed to register uploaded object key=cp781syrvzmal184g1xxp1nddi44b8iz.ls error="server returned 404: 404 page not found\n"16622026/08/27 10:01:22 WARN Failed to register uploaded object key=mz0rcihp5bl9w8gjf3mj7c5l35417kc3.narinfo error="server returned 404: 404 page not found\n"16632026/08/27 10:01:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16642026/08/27 10:01:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16652026/08/27 10:01:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16662026/08/27 10:01:22 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16672026/08/27 10:01:22 INFO Signed narinfos id=1 count=116682026/08/27 10:01:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16692026/08/27 10:01:22 INFO Signed narinfos id=1 count=116702026/08/27 10:01:22 INFO Signed narinfos id=1 count=116712026/08/27 10:01:22 INFO Signed narinfos id=2 count=116722026/08/27 10:01:22 INFO Uploading 1 narinfos16732026/08/27 10:01:22 INFO Uploading 3 narinfos16742026/08/27 10:01:22 INFO Uploading 1 narinfos16752026/08/27 10:01:22 INFO Completed upload id=216762026/08/27 10:01:22 INFO Upload complete. (1.264s)1677=== NAME TestNARDeduplicationMetadataUploadBug1678 metadata_upload_test.go:76: Retrieved narinfo from S3:1679 StorePath: /build/TestNARDeduplicationMetadataUploadBug1404843166/001/store/mz0rcihp5bl9w8gjf3mj7c5l35417kc3-file2.txt1680 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1681 Compression: zstd1682 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1683 NarSize: 1601684 References: 1685 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf16862026/08/27 10:01:22 WARN Failed to register uploaded object key=hz9kwngypmvg59ax6b18gbf7c6gk2f99.narinfo error="server returned 404: 404 page not found\n"1687 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1688 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1689 {"version":1,"root":{"type":"regular","size":44}}16902026/08/27 10:01:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16912026/08/27 10:01:22 WARN Failed to register uploaded object key=bdfqa53gkv60x4glvzrmd8is6n0vlb36.narinfo error="server returned 404: 404 page not found\n"16922026/08/27 10:01:22 WARN Failed to register uploaded object key=sh8i82x2ap7ilxs0h9ynw5a71m09rd85.narinfo error="server returned 404: 404 page not found\n"16932026/08/27 10:01:22 WARN Failed to register uploaded object key=cp781syrvzmal184g1xxp1nddi44b8iz.narinfo error="server returned 404: 404 page not found\n"16942026/08/27 10:01:22 WARN Failed to register uploaded object key=5d7qk1ka6fhlsjbrlig05phr65l6dbhi.narinfo error="server returned 404: 404 page not found\n"16952026/08/27 10:01:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16962026/08/27 10:01:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1697--- PASS: TestNARDeduplicationMetadataUploadBug (2.79s)16982026/08/27 10:01:22 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"16992026/08/27 10:01:22 WARN Failed to register uploaded object key=jxxhjlk39s7vygrks3qcbrjma1hy0r3y.ls error="server returned 404: 404 page not found\n"17002026/08/27 10:01:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17012026/08/27 10:01:22 INFO Signed narinfos id=1 count=117022026/08/27 10:01:22 INFO Completed upload id=117032026/08/27 10:01:22 INFO Uploading 1 narinfos17042026/08/27 10:01:22 INFO Upload complete. (1.285s)17052026/08/27 10:01:22 INFO Completed upload id=117062026/08/27 10:01:22 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17072026/08/27 10:01:22 INFO Completed upload id=117082026/08/27 10:01:22 INFO Upload complete. (1.298s)17092026/08/27 10:01:22 INFO Completed upload id=217102026/08/27 10:01:22 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete17112026/08/27 10:01:22 INFO Completed upload id=317122026/08/27 10:01:22 INFO Upload complete. (1.251s)1713=== NAME TestClientMultipleUploads1714 client_integration_test.go:349: Uploaded 3 paths in 1.288694961s17152026/08/27 10:01:22 WARN Failed to register uploaded object key=jxxhjlk39s7vygrks3qcbrjma1hy0r3y.narinfo error="server returned 404: 404 page not found\n"17162026/08/27 10:01:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1717=== NAME TestClientWithDependencies1718 client_integration_test.go:597: Skipping nix copy test - isolated store (/build/TestClientWithDependencies4221329864/001/store) requires matching store prefix1719=== NAME TestClientCADerivations1720 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3835220385/001/store/cp781syrvzmal184g1xxp1nddi44b8iz-ca-test1721 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1722 Compression: zstd1723 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1724 NarSize: 1441725 References: 1726 Deriver: /build/TestClientCADerivations3835220385/001/store/ssdfwin6r4p1f2m1c1h3ziim824ak8fd-ca-test.drv1727 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1728 client_ca_test.go:185: Checking for realisation files in S3...17292026/08/27 10:01:22 INFO Completed upload id=117302026/08/27 10:01:22 INFO Upload complete. (1.296s)1731 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1732 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1733=== NAME TestClientIntegration1734 client_integration_test.go:292: Retrieved narinfo from S3:1735 StorePath: /build/TestClientIntegration1531670951/002/store/jxxhjlk39s7vygrks3qcbrjma1hy0r3y-test-file.txt1736 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1737 Compression: zstd1738 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11739 NarSize: 1521740 References: 1741 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11742--- PASS: TestClientWithDependencies (1.81s)1743=== NAME TestClientIntegration1744 client_integration_test.go:293: Retrieved .ls file from S3 (compressed size: 77 bytes)1745 client_integration_test.go:293: Decompressed .ls content (64 bytes):1746 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1747 client_integration_test.go:296: Testing garbage collection...1748--- PASS: TestClientMultipleUploads (1.75s)17492026/08/27 10:01:22 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17502026/08/27 10:01:22 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.62237528s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config17512026/08/27 10:01:22 INFO Starting cleanup of old closures method=DELETE path=/api/closures17522026/08/27 10:01:22 INFO Garbage collection started17532026/08/27 10:01:22 INFO Aborted multipart uploads count=017542026/08/27 10:01:22 INFO Received uploads request method=POST path=/api/pending_closures17552026/08/27 10:01:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17562026/08/27 10:01:22 INFO Uploading d2py178a28zdhmh4yrg00aciyywx44sb-unpinned-file.txt (128B)17572026/08/27 10:01:22 WARN Force mode enabled - objects will be deleted immediately without grace period1758=== NAME TestClientCADerivations1759 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1760 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1761 error: binary cache 's3://bucket39?endpoint=http://localhost:34427&region=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3835220385/001/store'1762 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11763--- PASS: TestClientCADerivations (2.77s)17642026/08/27 10:01:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17652026/08/27 10:01:22 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZWFiZGI2NGQtNTEwMy00MmZiLWExYjEtZDQzYTUwNWE0YTdjLmRjMDFlYjNhLTczY2ItNDg0ZS1iZmMwLWJhNzQxZmQ3YTAyMngxNzg3ODI0ODc3NDk5NTA1NDA0 parts=1017662026/08/27 10:01:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17672026/08/27 10:01:22 INFO Completed upload id=117682026/08/27 10:01:22 INFO Received uploads request method=POST path=/api/pending_closures17692026/08/27 10:01:22 INFO Received uploads request method=POST path=/api/pending_closures17702026/08/27 10:01:22 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo17712026/08/27 10:01:22 WARN Found objects in DB but missing from S3, will re-upload count=11772--- PASS: TestService_verifyS3Integrity (5.11s)17732026/08/27 10:01:22 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"17742026/08/27 10:01:22 WARN Failed to register uploaded object key=d2py178a28zdhmh4yrg00aciyywx44sb.ls error="server returned 404: 404 page not found\n"17752026/08/27 10:01:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17762026/08/27 10:01:22 INFO Signed narinfos id=2 count=117772026/08/27 10:01:22 INFO Uploading 1 narinfos17782026/08/27 10:01:22 WARN Failed to register uploaded object key=d2py178a28zdhmh4yrg00aciyywx44sb.narinfo error="server returned 404: 404 page not found\n"17792026/08/27 10:01:22 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17802026/08/27 10:01:22 INFO Completed upload id=217812026/08/27 10:01:22 INFO Upload complete. (556ms)17822026/08/27 10:01:22 INFO Received create pin request method=POST path=/api/pins/myapp17832026/08/27 10:01:22 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1888749677/001/store/80qhqs5d4kib99mhxp53ddznp115g0rf-pinned-file.txt narinfo_key=80qhqs5d4kib99mhxp53ddznp115g0rf.narinfo17842026/08/27 10:01:22 INFO Starting cleanup of old closures method=DELETE path=/api/closures17852026/08/27 10:01:22 INFO Garbage collection started17862026/08/27 10:01:22 INFO Aborted multipart uploads count=017872026/08/27 10:01:22 WARN Force mode enabled - objects will be deleted immediately without grace period17882026/08/27 10:01:22 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=017892026/08/27 10:01:22 INFO Vacuumed table table=pending_closures17902026/08/27 10:01:22 INFO Vacuumed table table=pending_objects17912026/08/27 10:01:22 INFO Vacuumed table table=multipart_uploads17922026/08/27 10:01:22 INFO Vacuumed table table=closures17932026/08/27 10:01:22 INFO Vacuumed table table=objects17942026/08/27 10:01:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17952026/08/27 10:01:23 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZWFiZGI2NGQtNTEwMy00MmZiLWExYjEtZDQzYTUwNWE0YTdjLjc0YjAwNTUxLWVjN2EtNDc4Zi1hOGFlLWExMjRkODg4MWRmMngxNzg3ODI0ODgwMjk1OTc3NDY4 parts=1217962026/08/27 10:01:23 INFO Received uploads request method=POST path=/api/pending_closures1797--- PASS: TestCompletedNarNotReofferedAcrossClosures (5.86s)17982026/08/27 10:01: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=017992026/08/27 10:01:23 INFO Vacuumed table table=pending_closures18002026/08/27 10:01:23 INFO Vacuumed table table=pending_objects18012026/08/27 10:01:23 INFO Vacuumed table table=multipart_uploads18022026/08/27 10:01:23 INFO Vacuumed table table=closures18032026/08/27 10:01:23 INFO Vacuumed table table=objects1804=== NAME TestOrphanedObjectsGCStressTest1805 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1806 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1807 orphaned_objects_gc_test.go:509: Stress test completed successfully:1808 orphaned_objects_gc_test.go:510: - Active objects preserved: 201809 orphaned_objects_gc_test.go:511: - Objects deleted: 2101810 orphaned_objects_gc_test.go:512: - Total GC'd: 2101811--- PASS: TestOrphanedObjectsGCStressTest (5.23s)18122026/08/27 10:01:23 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"18132026/08/27 10:01:23 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_closures18142026/08/27 10:01:23 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=181.837069ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures18152026/08/27 10:01:23 WARN Rate limiter enabled after throttle name=s3-test rate=518162026/08/27 10:01:23 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1817=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1818 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101819 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001820--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.78s)18212026/08/27 10:01:24 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=381.050942ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures18222026/08/27 10:01:24 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01823=== NAME TestClientIntegration1824 client_integration_test.go:303: Objects in database after GC:1825 client_integration_test.go:303: Successfully deleted all objects with GC --force1826--- PASS: TestClientIntegration (3.77s)18272026/08/27 10:01:24 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=805.369903ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures18282026/08/27 10:01:24 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01829=== NAME TestPinProtectsFromGC1830 client_integration_test.go:709: Pin successfully protected closure from garbage collection1831--- PASS: TestPinProtectsFromGC (5.18s)18322026/08/27 10:01:25 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.718723393s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1833--- PASS: TestClientErrorHandling (0.00s)1834 --- PASS: TestClientErrorHandling/InvalidStorePath (0.30s)1835 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.38s)1836 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.44s)1837PASS1838{"timestamp":"2026-08-27T10:01:26.952870665Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:51040","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":1836,"threadName":"rustfs-worker","threadId":"ThreadId(384)"}18392026-08-27 10:01:27.269 UTC [112] LOG: received smart shutdown request18402026-08-27 10:01:27.275 UTC [112] LOG: background worker "logical replication launcher" (PID 122) exited with exit code 118412026-08-27 10:01:27.284 UTC [117] LOG: shutting down18422026-08-27 10:01:27.285 UTC [117] LOG: checkpoint starting: shutdown immediate18432026-08-27 10:01:28.422 UTC [117] LOG: checkpoint complete: wrote 11864 buffers (72.4%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 13 recycled; write=0.228 s, sync=0.900 s, total=1.138 s; sync files=15825, longest=0.002 s, average=0.001 s; distance=217977 kB, estimate=217977 kB; lsn=0/EC42478, redo lsn=0/EC4247818442026-08-27 10:01:28.522 UTC [112] LOG: database system is shut down1845Running OIDC tests...1846=== RUN TestGlobMatch1847=== PAUSE TestGlobMatch1848=== RUN TestAudienceForIssuer1849=== PAUSE TestAudienceForIssuer1850=== RUN TestValidateToken_ValidToken1851=== PAUSE TestValidateToken_ValidToken1852=== RUN TestValidateToken_WrongAudience1853=== PAUSE TestValidateToken_WrongAudience1854=== RUN TestValidateToken_Expired1855=== PAUSE TestValidateToken_Expired1856=== RUN TestValidateToken_BoundClaimsMismatch1857=== PAUSE TestValidateToken_BoundClaimsMismatch1858=== RUN TestValidateToken_BoundSubjectMismatch1859=== PAUSE TestValidateToken_BoundSubjectMismatch1860=== RUN TestValidateToken_MultipleProviders1861=== PAUSE TestValidateToken_MultipleProviders1862=== RUN TestValidateToken_NoMatchingProvider1863=== PAUSE TestValidateToken_NoMatchingProvider1864=== CONT TestGlobMatch1865=== CONT TestValidateToken_MultipleProviders1866=== CONT TestValidateToken_BoundClaimsMismatch1867=== CONT TestValidateToken_WrongAudience1868=== RUN TestGlobMatch/foo_foo1869=== PAUSE TestGlobMatch/foo_foo1870=== CONT TestValidateToken_ValidToken1871=== CONT TestAudienceForIssuer1872--- PASS: TestAudienceForIssuer (0.00s)1873=== CONT TestValidateToken_BoundSubjectMismatch1874=== CONT TestValidateToken_NoMatchingProvider1875=== CONT TestValidateToken_Expired1876=== RUN TestGlobMatch/foo_bar1877=== PAUSE TestGlobMatch/foo_bar1878=== RUN TestGlobMatch/*_1879=== PAUSE TestGlobMatch/*_1880=== RUN TestGlobMatch/*_anything1881=== PAUSE TestGlobMatch/*_anything1882=== RUN TestGlobMatch/foo*_foo1883=== PAUSE TestGlobMatch/foo*_foo1884=== RUN TestGlobMatch/foo*_foobar1885=== PAUSE TestGlobMatch/foo*_foobar1886=== RUN TestGlobMatch/foo*_bar1887=== PAUSE TestGlobMatch/foo*_bar1888=== RUN TestGlobMatch/*bar_bar1889=== PAUSE TestGlobMatch/*bar_bar1890=== RUN TestGlobMatch/*bar_foobar1891=== PAUSE TestGlobMatch/*bar_foobar1892=== RUN TestGlobMatch/*bar_foo1893=== PAUSE TestGlobMatch/*bar_foo1894=== RUN TestGlobMatch/foo*bar_foobar1895=== PAUSE TestGlobMatch/foo*bar_foobar1896=== RUN TestGlobMatch/foo*bar_foo123bar1897=== PAUSE TestGlobMatch/foo*bar_foo123bar1898=== RUN TestGlobMatch/foo*bar_foobarbaz1899=== PAUSE TestGlobMatch/foo*bar_foobarbaz1900=== RUN TestGlobMatch/*/*_foo/bar1901=== PAUSE TestGlobMatch/*/*_foo/bar1902=== RUN TestGlobMatch/*/*_foo1903=== PAUSE TestGlobMatch/*/*_foo1904=== RUN TestGlobMatch/refs/heads/*_refs/heads/main1905=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main1906=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.01907=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.01908=== RUN TestGlobMatch/refs/*/main_refs/heads/main1909=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main1910=== RUN TestGlobMatch/fo?_foo1911=== PAUSE TestGlobMatch/fo?_foo1912=== RUN TestGlobMatch/fo?_fo1913=== PAUSE TestGlobMatch/fo?_fo1914=== RUN TestGlobMatch/fo?_fooo1915=== PAUSE TestGlobMatch/fo?_fooo1916=== RUN TestGlobMatch/?oo_foo1917=== PAUSE TestGlobMatch/?oo_foo1918=== RUN TestGlobMatch/?oo_boo1919=== PAUSE TestGlobMatch/?oo_boo1920=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1921=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1922=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1923=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1924=== CONT TestGlobMatch/foo_foo1925=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1926=== CONT TestGlobMatch/foo*bar_foo123bar1927=== CONT TestGlobMatch/foo*bar_foobar1928=== CONT TestGlobMatch/*bar_foobar1929=== CONT TestGlobMatch/foo*bar_foobarbaz1930=== CONT TestGlobMatch/*_1931=== CONT TestGlobMatch/foo_bar1932=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1933=== CONT TestGlobMatch/?oo_boo1934=== CONT TestGlobMatch/?oo_foo1935=== CONT TestGlobMatch/fo?_fooo1936=== CONT TestGlobMatch/fo?_fo1937=== CONT TestGlobMatch/fo?_foo1938=== CONT TestGlobMatch/refs/*/main_refs/heads/main1939=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.01940=== CONT TestGlobMatch/refs/heads/*_refs/heads/main1941=== CONT TestGlobMatch/*/*_foo1942=== CONT TestGlobMatch/*/*_foo/bar1943=== CONT TestGlobMatch/*_anything1944=== CONT TestGlobMatch/foo*_bar1945=== CONT TestGlobMatch/foo*_foo1946=== CONT TestGlobMatch/*bar_foo1947=== CONT TestGlobMatch/*bar_bar1948=== CONT TestGlobMatch/foo*_foobar1949--- PASS: TestGlobMatch (0.00s)1950 --- PASS: TestGlobMatch/foo_foo (0.00s)1951 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)1952 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)1953 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)1954 --- PASS: TestGlobMatch/*bar_foobar (0.00s)1955 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)1956 --- PASS: TestGlobMatch/*_ (0.00s)1957 --- PASS: TestGlobMatch/foo_bar (0.00s)1958 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)1959 --- PASS: TestGlobMatch/?oo_boo (0.00s)1960 --- PASS: TestGlobMatch/?oo_foo (0.00s)1961 --- PASS: TestGlobMatch/fo?_fooo (0.00s)1962 --- PASS: TestGlobMatch/fo?_fo (0.00s)1963 --- PASS: TestGlobMatch/fo?_foo (0.00s)1964 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)1965 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)1966 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)1967 --- PASS: TestGlobMatch/*/*_foo (0.00s)1968 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)1969 --- PASS: TestGlobMatch/*_anything (0.00s)1970 --- PASS: TestGlobMatch/foo*_bar (0.00s)1971 --- PASS: TestGlobMatch/foo*_foo (0.00s)1972 --- PASS: TestGlobMatch/*bar_foo (0.00s)1973 --- PASS: TestGlobMatch/*bar_bar (0.00s)1974 --- PASS: TestGlobMatch/foo*_foobar (0.00s)19752026/08/27 10:01:29 INFO OIDC provider initialized name=test19762026/08/27 10:01:29 INFO OIDC provider initialized name=test19772026/08/27 10:01:29 INFO OIDC provider initialized name=test19782026/08/27 10:01:29 INFO OIDC provider initialized name=provider119792026/08/27 10:01:29 INFO OIDC provider initialized name=test19802026/08/27 10:01:29 INFO OIDC provider initialized name=test19812026/08/27 10:01:29 INFO OIDC provider initialized name=provider119822026/08/27 10:01:29 INFO OIDC provider initialized name=provider21983--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)1984--- PASS: TestValidateToken_NoMatchingProvider (0.01s)1985--- PASS: TestValidateToken_WrongAudience (0.01s)1986--- PASS: TestValidateToken_Expired (0.01s)1987--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)1988--- PASS: TestValidateToken_ValidToken (0.01s)1989--- PASS: TestValidateToken_MultipleProviders (0.01s)1990PASS1991Running hook tests...1992=== RUN TestSendPathsEmpty1993=== PAUSE TestSendPathsEmpty1994=== RUN TestQueueEnqueueAndFetch1995=== PAUSE TestQueueEnqueueAndFetch1996=== RUN TestQueueDeduplication1997=== PAUSE TestQueueDeduplication1998=== RUN TestQueueRemove1999=== PAUSE TestQueueRemove2000=== RUN TestQueueFetchBatchLimit2001=== PAUSE TestQueueFetchBatchLimit2002=== RUN TestQueueRetryMovesToBack2003=== PAUSE TestQueueRetryMovesToBack2004=== RUN TestQueueFetchRemoveLifecycle2005=== PAUSE TestQueueFetchRemoveLifecycle2006=== RUN TestQueueConcurrentWriters2007=== PAUSE TestQueueConcurrentWriters2008=== RUN TestQueueRemoveLargeClosure2009=== PAUSE TestQueueRemoveLargeClosure2010=== RUN TestServerClientIntegration2011=== PAUSE TestServerClientIntegration2012=== RUN TestServerQueueError2013=== PAUSE TestServerQueueError2014=== RUN TestGetListenerSocketActivation2015 server_test.go:210: === RUN TestGetListenerSocketActivation2016 --- PASS: TestGetListenerSocketActivation (0.00s)2017 PASS2018 2019--- PASS: TestGetListenerSocketActivation (0.01s)2020=== RUN TestDrainIsolatesPoisonPath2021=== PAUSE TestDrainIsolatesPoisonPath2022=== RUN TestRunNotBlockedByPoisonHead2023=== PAUSE TestRunNotBlockedByPoisonHead2024=== RUN TestDrainGivesUpWhenServerDown2025=== PAUSE TestDrainGivesUpWhenServerDown2026=== RUN TestFailedPathPrunedByLaterClosure2027=== PAUSE TestFailedPathPrunedByLaterClosure2028=== RUN TestWorkerUploadsAndRemoves2029=== PAUSE TestWorkerUploadsAndRemoves2030=== RUN TestWorkerSkipsGCdPaths2031=== PAUSE TestWorkerSkipsGCdPaths2032=== RUN TestWorkerPrunesClosureDeps2033=== PAUSE TestWorkerPrunesClosureDeps2034=== RUN TestDrainTimeoutStopsSlowDrain2035=== PAUSE TestDrainTimeoutStopsSlowDrain2036=== RUN TestDrainWithoutTimeoutRunsToCompletion2037=== PAUSE TestDrainWithoutTimeoutRunsToCompletion2038=== RUN TestDrainTimeoutNotWaitedOutOnSuccess2039=== PAUSE TestDrainTimeoutNotWaitedOutOnSuccess2040=== CONT TestSendPathsEmpty2041=== CONT TestDrainWithoutTimeoutRunsToCompletion2042=== CONT TestDrainTimeoutNotWaitedOutOnSuccess2043=== CONT TestServerQueueError2044=== CONT TestDrainTimeoutStopsSlowDrain2045=== CONT TestWorkerPrunesClosureDeps2046=== CONT TestWorkerSkipsGCdPaths2047=== CONT TestWorkerUploadsAndRemoves2048=== CONT TestFailedPathPrunedByLaterClosure2049=== CONT TestDrainGivesUpWhenServerDown2050=== CONT TestRunNotBlockedByPoisonHead2051=== CONT TestDrainIsolatesPoisonPath2052=== CONT TestQueueRetryMovesToBack20532026/08/27 10:01:29 ERROR Failed to queue paths error="permission denied" count=12054--- PASS: TestSendPathsEmpty (0.00s)2055=== CONT TestServerClientIntegration2056=== CONT TestQueueRemoveLargeClosure2057=== CONT TestQueueFetchBatchLimit2058=== CONT TestQueueConcurrentWriters2059=== CONT TestQueueRemove2060=== CONT TestQueueFetchRemoveLifecycle2061=== CONT TestQueueDeduplication2062=== CONT TestQueueEnqueueAndFetch2063--- PASS: TestServerQueueError (0.00s)2064--- PASS: TestServerClientIntegration (0.00s)20652026/08/27 10:01:29 INFO Uploading batch count=120662026/08/27 10:01:29 INFO Upload queue status pending=220672026/08/27 10:01:29 INFO Uploading batch count=220682026/08/27 10:01:29 INFO Uploading batch count=120692026/08/27 10:01:29 INFO Uploading batch count=120702026/08/27 10:01:29 ERROR Upload failed error="upload failed" count=12071--- PASS: TestQueueFetchBatchLimit (0.02s)2072--- PASS: TestQueueFetchRemoveLifecycle (0.02s)2073--- PASS: TestQueueEnqueueAndFetch (0.02s)20742026/08/27 10:01:29 INFO Uploading batch count=120752026/08/27 10:01:29 INFO Uploading batch count=420762026/08/27 10:01:29 ERROR Upload failed error="upload failed" count=420772026/08/27 10:01:29 INFO Uploading batch count=22078--- PASS: TestQueueDeduplication (0.02s)20792026/08/27 10:01:29 INFO Upload queue status pending=220802026/08/27 10:01:29 INFO Upload queue status pending=320812026/08/27 10:01:29 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath892335971/002/bbb20822026/08/27 10:01:29 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1719350381/002/nonexistent2083--- PASS: TestQueueRemove (0.02s)20842026/08/27 10:01:29 INFO Uploading batch count=120852026/08/27 10:01:29 INFO Upload queue status pending=220862026/08/27 10:01:29 INFO Uploading batch count=120872026/08/27 10:01:29 ERROR Upload failed error="upload failed" count=120882026/08/27 10:01:29 INFO Uploading batch count=220892026/08/27 10:01:29 ERROR Upload failed error="upload failed" count=220902026/08/27 10:01:29 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3188960975/002/a20912026/08/27 10:01:29 INFO Uploading batch count=220922026/08/27 10:01:29 INFO Uploading batch count=22093--- PASS: TestQueueRetryMovesToBack (0.02s)20942026/08/27 10:01:29 INFO Uploading batch count=120952026/08/27 10:01:29 INFO Uploading batch count=120962026/08/27 10:01:29 ERROR Upload failed error="upload failed" count=120972026/08/27 10:01:29 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3188960975/002/b20982026/08/27 10:01:29 INFO Uploading batch count=120992026/08/27 10:01:29 ERROR Upload failed error="upload failed" count=121002026/08/27 10:01:29 INFO Uploading batch count=221012026/08/27 10:01:29 ERROR Upload failed error="upload failed" count=221022026/08/27 10:01:29 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3188960975/002/c21032026/08/27 10:01:29 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3188960975/002/d2104--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)21052026/08/27 10:01:29 INFO Uploading batch count=121062026/08/27 10:01:29 ERROR Upload failed error="upload failed" count=121072026/08/27 10:01:29 INFO Uploading batch count=22108--- PASS: TestDrainTimeoutNotWaitedOutOnSuccess (0.02s)21092026/08/27 10:01:29 ERROR Upload failed error="upload failed" count=221102026/08/27 10:01:29 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3188960975/002/e21112026/08/27 10:01:29 ERROR Drain finished with paths left in queue remaining=121122026/08/27 10:01:29 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3188960975/002/f21132026/08/27 10:01:29 INFO Uploading batch count=121142026/08/27 10:01:29 ERROR Drain finished with paths left in queue remaining=102115--- PASS: TestDrainIsolatesPoisonPath (0.03s)2116--- PASS: TestDrainGivesUpWhenServerDown (0.03s)21172026/08/27 10:01:29 INFO Uploading batch count=12118--- PASS: TestWorkerPrunesClosureDeps (0.04s)2119--- PASS: TestWorkerSkipsGCdPaths (0.04s)2120--- PASS: TestWorkerUploadsAndRemoves (0.04s)21212026/08/27 10:01:29 INFO Uploading batch count=12122--- PASS: TestDrainWithoutTimeoutRunsToCompletion (0.06s)21232026/08/27 10:01:29 ERROR Upload failed error="context deadline exceeded" count=221242026/08/27 10:01:29 ERROR Upload failed, will retry later error="context deadline exceeded" path=/build/TestDrainTimeoutStopsSlowDrain2849136401/002/a21252026/08/27 10:01:29 ERROR Upload failed, will retry later error="context deadline exceeded" path=/build/TestDrainTimeoutStopsSlowDrain2849136401/002/b21262026/08/27 10:01:29 WARN Drain timed out timeout=200ms21272026/08/27 10:01:29 ERROR Drain finished with paths left in queue remaining=42128--- PASS: TestDrainTimeoutStopsSlowDrain (0.22s)2129--- PASS: TestQueueConcurrentWriters (0.24s)2130--- PASS: TestQueueRemoveLargeClosure (0.34s)21312026/08/27 10:01:30 INFO Uploading batch count=121322026/08/27 10:01:30 INFO Uploading batch count=121332026/08/27 10:01:30 INFO Uploading batch count=121342026/08/27 10:01:30 ERROR Upload failed error="upload failed" count=121352026/08/27 10:01:30 INFO Uploading batch count=121362026/08/27 10:01:30 ERROR Upload failed error="upload failed" count=121372026/08/27 10:01:30 INFO Uploading batch count=121382026/08/27 10:01:30 ERROR Upload failed error="upload failed" count=121392026/08/27 10:01:30 INFO Uploading batch count=121402026/08/27 10:01:30 ERROR Upload failed error="upload failed" count=121412026/08/27 10:01:30 ERROR Drain finished with paths left in queue remaining=12142--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2143PASS